Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

core(network): align headers end time with send when no data received #16044

Merged
merged 2 commits into from
Jun 5, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
6 changes: 5 additions & 1 deletion core/lib/lantern/types/lantern.d.ts
Original file line number Diff line number Diff line change
Expand Up @@ -60,7 +60,11 @@ export class NetworkRequest<T = any> {
* HTTP cache or going to the network for DNS/connection setup, in milliseconds.
*/
networkRequestTime: number;
/** When the last byte of the response headers is received, in milliseconds. */
/**
* When the last byte of the response headers is received, in milliseconds.
* Equal to networkRequestTime if no data is recieved over the
* network (ex: cached requests or data urls).
*/
responseHeadersEndTime: number;
/** When the last byte of the response body is received, in milliseconds. */
networkEndTime: number;
Expand Down
20 changes: 12 additions & 8 deletions core/lib/network-request.js
Original file line number Diff line number Diff line change
Expand Up @@ -129,7 +129,11 @@ class NetworkRequest {
* HTTP cache or going to the network for DNS/connection setup, in milliseconds.
*/
this.networkRequestTime = -1;
/** When the last byte of the response headers is received, in milliseconds. */
/**
* When the last byte of the response headers is received, in milliseconds.
* Equal to networkRequestTime if no data is recieved over the
* network (ex: cached requests or data urls).
*/
this.responseHeadersEndTime = -1;
/** When the last byte of the response body is received, in milliseconds. */
this.networkEndTime = -1;
Expand Down Expand Up @@ -222,8 +226,9 @@ class NetworkRequest {
this.isSecure = UrlUtils.isSecureScheme(this.parsedURL.scheme);

this.rendererStartTime = data.timestamp * 1000;
// Expected to be overridden with better value in `_recomputeTimesWithResourceTiming`.
// These are expected to be overridden with better value in `_recomputeTimesWithResourceTiming`.
this.networkRequestTime = this.rendererStartTime;
this.responseHeadersEndTime = this.rendererStartTime;

this.requestMethod = data.request.method;

Expand Down Expand Up @@ -350,8 +355,7 @@ class NetworkRequest {

if (response.protocol) this.protocol = response.protocol;

// This is updated in _recomputeTimesWithResourceTiming, if timings are present.
this.responseHeadersEndTime = timestamp * 1000;
this.responseTimestamp = timestamp * 1000;

this.transferSize = response.encodedDataLength;
this.responseHeadersTransferSize = response.encodedDataLength;
Expand Down Expand Up @@ -381,7 +385,7 @@ class NetworkRequest {
_recomputeTimesWithResourceTiming(timing) {
// Don't recompute times if the data is invalid. RequestTime should always be a thread timestamp.
// If we don't have receiveHeadersEnd, we really don't have more accurate data.
if (timing.requestTime === 0 || timing.receiveHeadersEnd === -1) return;
if (timing.requestTime === -1 || timing.receiveHeadersEnd === -1) return;
Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

checking against 0 is a mistake given we have test records that start at 0. this caused roundtrip to fail.


// Take networkRequestTime and responseHeadersEndTime from timing data for better accuracy.
// Before this, networkRequestTime and responseHeadersEndTime were set to bogus values based on
Expand All @@ -392,15 +396,15 @@ class NetworkRequest {
// See https://raw.githubusercontent.com/GoogleChrome/lighthouse/main/docs/Network-Timings.svg
this.networkRequestTime = timing.requestTime * 1000;
const headersReceivedTime = this.networkRequestTime + timing.receiveHeadersEnd;
// This was set in `_onResponse` as that event's timestamp.
const responseTimestamp = this.responseHeadersEndTime;

// Update this.responseHeadersEndTime. All timing values from the netstack (timing) are well-ordered, and
// so are the timestamps from CDP (which this.responseHeadersEndTime belongs to). It shouldn't be possible
// that this timing from the netstack is greater than the onResponse timestamp, but just to ensure proper order
// is maintained we bound the new timing by the network request time and the response timestamp.
this.responseHeadersEndTime = headersReceivedTime;
this.responseHeadersEndTime = Math.min(this.responseHeadersEndTime, responseTimestamp);
if (this.responseTimestamp !== undefined) {
this.responseHeadersEndTime = Math.min(this.responseHeadersEndTime, this.responseTimestamp);
}
this.responseHeadersEndTime = Math.max(this.responseHeadersEndTime, this.networkRequestTime);

// We're only at responseReceived (_onResponse) at this point.
Expand Down
2 changes: 1 addition & 1 deletion core/test/lib/network-recorder-test.js
Original file line number Diff line number Diff line change
Expand Up @@ -587,7 +587,7 @@ describe('network recorder', function() {
localizedFailDescription: 'net::ERR_ABORTED',
rendererStartTime: 500,
networkRequestTime: 500,
responseHeadersEndTime: -1,
responseHeadersEndTime: 500,
networkEndTime: 501,
Copy link
Collaborator Author

@connorjclark connorjclark Jun 5, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

this value being -1 when rendererStartTime/networkRequestTime is set is no longer a valid state.

transferSize: 0,
resourceSize: 0,
Expand Down
7 changes: 6 additions & 1 deletion core/test/network-records-to-devtools-log.js
Original file line number Diff line number Diff line change
Expand Up @@ -96,6 +96,7 @@ function extractPartialTiming(networkRecord) {
responseHeadersEndTime,
networkEndTime,
redirectResponseTimestamp, // Generated timestamp added in addRedirectResponseIfNeeded; only used as backup start time.
responseTimestamp, // Time of response event from CDP, not from the netstack.
} = networkRecord;

const requestTime = timeDefined(requestTimeS) ? requestTimeS * 1000 : undefined;
Expand Down Expand Up @@ -130,6 +131,7 @@ function extractPartialTiming(networkRecord) {

return {
redirectResponseTimestamp,
responseTimestamp,
rendererStartTime,
networkRequestTime,
requestTime,
Expand Down Expand Up @@ -199,11 +201,14 @@ function getNormalizedRequestTiming(networkRecord) {
const networkEndTime = extractedTimes.networkEndTime ??
(responseHeadersEndTime + defaultTimingOffset);

const responseTimestamp = extractedTimes.responseTimestamp ?? requestTime + receiveHeadersEnd;

return {
rendererStartTime,
networkRequestTime,
responseHeadersEndTime,
networkEndTime,
responseTimestamp,
timing: {
// TODO: other `timing` properties could have default values.
...networkRecord.timing,
Expand Down Expand Up @@ -277,7 +282,7 @@ function getResponseReceivedEvent(networkRecord, index, normalizedTiming) {
method: 'Network.responseReceived',
params: {
requestId: getBaseRequestId(networkRecord) || `${idBase}.${index}`,
timestamp: normalizedTiming.responseHeadersEndTime / 1000,
timestamp: normalizedTiming.responseTimestamp / 1000,
type: networkRecord.resourceType || undefined,
response: {
url: networkRecord.url || exampleUrl,
Expand Down
Loading