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.

Sign up for GitHub

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

Jump to bottom

misc: document where network timings come from #14227

Merged
merged 11 commits into from
Aug 20, 2022
Merged

misc: document where network timings come from #14227

Changes from 5 commits
Commits
Show all changes
11 commits
Select commit Hold shift + click to select a range
0b2e77b
misc: document where network timings come from
connorjclark Jul 20, 2022
7b912a5
update
connorjclark Jul 20, 2022
057d1da
update
connorjclark Jul 20, 2022
0a33be4
update
connorjclark Jul 20, 2022
02aae47
update
connorjclark Jul 20, 2022
6f7bee2
pr
connorjclark Aug 19, 2022
9bf0683
update
connorjclark Aug 19, 2022
0227595
Merge remote-tracking branch 'origin/master' into request-notes-cdp
connorjclark Aug 19, 2022
3077f90
typo
connorjclark Aug 19, 2022
d83d201
this ck is fn raw!!
connorjclark Aug 19, 2022
00b0985
Merge remote-tracking branch 'origin/master' into request-notes-cdp
connorjclark Aug 20, 2022
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
26 changes: 26 additions & 0 deletions lighthouse-core/lib/network-request.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,31 @@
* @fileoverview Fills most of the role of NetworkManager and NetworkRequest classes from DevTools.
* @see https://cs.chromium.org/chromium/src/third_party/blink/renderer/devtools/front_end/sdk/NetworkRequest.js
* @see https://cs.chromium.org/chromium/src/third_party/blink/renderer/devtools/front_end/sdk/NetworkManager.js

DevTools box-whisker
Copy link
Member

Choose a reason for hiding this comment

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

Between this documentation effort and my other goal of adding tests to chromium to assert resourcetiming & cdp & trace events all agree with eachother.... I really needed to determine and document the network timing dealio.

I went real overkill, but ... at least i almost covered everything I was hoping to..

Network-Timings


|-------[xxxxxXXXXXX]-|
(1) (2) (3) (4)

(1) Queuing (delta between renderer knowing about request and network manager knowing about it),
connorjclark marked this conversation as resolved.
Show resolved Hide resolved
DNS, SSL, connection setup cost

CDP: left whisker edge is Network.requestWillBeSent timestamp

(2) light shaded region. browser network manager has initiated the request, hasn't recieved any bytes back yet
Note: even with early-hint response, only the "real" response is considered here

CDP: Network.responseRecieved timings.requestStart + timing.sendStart

(3) dark shaded region. browser network manager has recieved the very first header byte

CDP: Network.responseRecieved timings.requestStart + timing.recievedHeadersEnd
CDP: (right edge of box) Network.finished/Network.failed timestamp

(4) Trailing whisker: marks time when render process has used the resource.

Trace: ResourceFinished trace event finishedTime. Currently don't care about this. Could be
long if main thread is busy.
Copy link
Member

Choose a reason for hiding this comment

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

Suggested change
DevTools box-whisker
|-------[xxxxxXXXXXX]-|
(1) (2) (3) (4)
(1) Queuing (delta between renderer knowing about request and network manager knowing about it),
DNS, SSL, connection setup cost
CDP: left whisker edge is Network.requestWillBeSent timestamp
(2) light shaded region. browser network manager has initiated the request, hasn't recieved any bytes back yet
Note: even with early-hint response, only the "real" response is considered here
CDP: Network.responseRecieved timings.requestStart + timing.sendStart
(3) dark shaded region. browser network manager has recieved the very first header byte
CDP: Network.responseRecieved timings.requestStart + timing.recievedHeadersEnd
CDP: (right edge of box) Network.finished/Network.failed timestamp
(4) Trailing whisker: marks time when render process has used the resource.
Trace: ResourceFinished trace event finishedTime. Currently don't care about this. Could be
long if main thread is busy.
Details for network timing instrumentation in CDP and trace events:
https://nettimings.surge.sh/Network-Timings.svg (Aug 2022)
Also, see _updateTimingsForLightrider() for LR specifics.

Sorry to mess up your sweet ascii art, but i'd suggest we just invest in this one canonical document. sgty?

thanks for your help in working through all this. it's a real pita.

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

surge links are liable to bit-rot so we shouldn't keep docs there. I'll pull this into the repo.

While there is tons of value in the thing you cooked up, I find myself overwhelmed when looking at it. I feel like a smaller view into the same info (As I have in the comment) is still useful to keep around for reference.

I'll need to double-check it all conforms with what's in your SVG, though.

*/

import URL from './url-shim.js';
Expand Down Expand Up @@ -321,6 +346,7 @@ class NetworkRequest {
if (timing.requestTime === 0 || timing.receiveHeadersEnd === -1) return;
// Take startTime and responseReceivedTime from timing data for better accuracy.
// Timing's requestTime is a baseline in seconds, rest of the numbers there are ticks in millis.
// TODO: This skips the "queuing time" before the netstack has taken over ... is this a mistake?
this.startTime = timing.requestTime;
Copy link
Collaborator Author

Choose a reason for hiding this comment

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

It seems this could be a mistake? startTime is initially set to the Network.requestWillBeSent timestamp AKA the left whisker .... then is reset here to be basically that + however long the "Queuing" time is (Pauls says that timings.requestTime is simply ignoring the time between renderer knowing about request and network manager knowing about request AKA queuing time)

Does this have implications on how we model our network records?

Copy link
Member

@paulirish paulirish Aug 10, 2022 •
edited
Loading

Choose a reason for hiding this comment

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

really good catch.

In short: yeah i think this could be a problem.

After doing the timing exercise id say our NetworkRequest class has too simple of a model.
Right now there's startTime, responseReceivedTime, endTime.

My first second inclination is to instead have mainThreadStartTime, _internalNetServiceRequestTime, requestStartTime, responseHeadersReceivedTime, networkEndTime, and optionally mainThreadEndTime.

back to current state:

  • Lantern slurps up the startTime, but i'm pretty sure the TCP stuff is simulated after that point, which is incorrect with this above assignment.
  • uses-rel-preconnect is looking at network request starts vs timeOrigin, but it should be using the mainThreadStartTime aka requestWillBeSent timestamp instead.
  • tags-blocking-first-paint calculates blocking time so it should def use mainThread- times rather than network-start times.

So yes... It's a mistake. And the fix looks kinda involved. :) But also somewhat clear.

const headersReceivedTime = timing.requestTime + timing.receiveHeadersEnd / 1000;
if (!this.responseReceivedTime || this.responseReceivedTime < 0) {
Expand Down