-
Notifications
You must be signed in to change notification settings - Fork 9.3k
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
misc: document where network timings come from #14227
Conversation
@@ -321,6 +341,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; |
There was a problem hiding this comment.
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?
There was a problem hiding this comment.
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
akarequestWillBeSent
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.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Overall LGTM
todo: could |
@@ -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 |
There was a problem hiding this comment.
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..
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. |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
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.
There was a problem hiding this comment.
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.
@@ -321,6 +341,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; |
There was a problem hiding this comment.
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
akarequestWillBeSent
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.
56b0482
to
d83d201
Compare
Paul and I attempted to document where all these timings come from in our network record model, in relation to the box-whisker model from DevTools performance panel.