Chromium Code Reviews
|
|
Chromium Code Reviews
Issue
1426673009:
Log UMA for navigation start timestamp skew for browser-initiated loads (Closed)
|
Created:
5 years, 1 month ago by Charlie Harrison Modified:
5 years, 1 month ago CC:
asvitkine+watch_chromium.org, Bryan McQuade, chromium-reviews, clamy, creis+watch_chromium.org, darin-cc_chromium.org, jam, mkwst+moarreviews-renderer_chromium.org, mlamouri+watch-content_chromium.org, nasko+codewatch_chromium.org Base URL:
https://chromium.googlesource.com/chromium/src.git@navigation_start_renderer Target Ref:
refs/pending/heads/master Project:
chromium Visibility:
Public. |
DescriptionLog UMA for navigation start timestamp skew for browser-initiated loads
We sanitize the navigation start timestamp by taking
std::min(browser_navigation_start, renderer_navigation_start)
This change logs the difference between the two timestamps. This
difference should ideally reflect the IPC time from browser to renderer,
plus any extra time the navigation was suspended in the RenderFrameHost.
BUG=394757
Committed: https://crrev.com/a813debae1ce75223a04d0c6044edd7d47822e21
Cr-Commit-Position: refs/heads/master@{#360230}
Patch Set 1 #
Total comments: 5
Patch Set 2 : use UMA_HISTOGRAM_TIMES #
Depends on Patchset: Messages
Total messages: 17 (4 generated)
csharrison@chromium.org changed reviewers: + asvitkine@chromium.org, jochen@chromium.org
PTAL. It seems this issue has caused a lot of grief over the years. This should hopefully illuminate how big an issue it is. Thanks!
cc clamy@
lgtm
clamy@chromium.org changed reviewers: + clamy@chromium.org
https://codereview.chromium.org/1426673009/diff/1/tools/metrics/histograms/hi... File tools/metrics/histograms/histograms.xml (right): https://codereview.chromium.org/1426673009/diff/1/tools/metrics/histograms/hi... tools/metrics/histograms/histograms.xml:20787: + should ideally only reflect the IPC time between the browser process and On transfer navigations, this difference covers more than just the IPC time (same with PlzNavigate btw). Should we exclude these cases from the metric?
https://codereview.chromium.org/1426673009/diff/1/tools/metrics/histograms/hi... File tools/metrics/histograms/histograms.xml (right): https://codereview.chromium.org/1426673009/diff/1/tools/metrics/histograms/hi... tools/metrics/histograms/histograms.xml:20787: + should ideally only reflect the IPC time between the browser process and On 2015/11/06 10:58:51, clamy wrote: > On transfer navigations, this difference covers more than just the IPC time > (same with PlzNavigate btw). Should we exclude these cases from the metric? Huh, I could have sworn that this comment included something about transfers / suspensions. Tbh I'm not totally sure what the right move is. Is there an easy way to test renderer-side that this was a transfer? transferred_request_request_id != -1? I'd also be willing to increase the timing window and just observe two humps on the histogram by logging everything. Could be a somewhat useful metric in its own right. WDYT?
https://codereview.chromium.org/1426673009/diff/1/tools/metrics/histograms/hi... File tools/metrics/histograms/histograms.xml (right): https://codereview.chromium.org/1426673009/diff/1/tools/metrics/histograms/hi... tools/metrics/histograms/histograms.xml:20787: + should ideally only reflect the IPC time between the browser process and On 2015/11/06 13:35:19, csharrison wrote: > On 2015/11/06 10:58:51, clamy wrote: > > On transfer navigations, this difference covers more than just the IPC time > > (same with PlzNavigate btw). Should we exclude these cases from the metric? > > Huh, I could have sworn that this comment included something about transfers / > suspensions. Tbh I'm not totally sure what the right move is. Is there an easy > way to test renderer-side that this was a transfer? > transferred_request_request_id != -1? I'd also be willing to increase the timing > window and just observe two humps on the histogram by logging everything. Could > be a somewhat useful metric in its own right. WDYT? transferred_request_request_id != -1 identifies a transferred request. The risk with increasing the window is that you will have less fine grained results for smaller values, which I think we care more about. My recommendation would be to live the window as is, with the possibility of excluding transfer navigations if there are too many of them (I don't think it's the case). Suspended navigations are not an issue: a navigation is only suspended when it is cross site and we are waiting for the current renderer to execute its BeforeUnload event. Since we update the navigation start at the moment when the user clicks on proceed, we should not see a big discrepancy between the browser navigation start and the renderer navigation start.
https://codereview.chromium.org/1426673009/diff/1/tools/metrics/histograms/hi... File tools/metrics/histograms/histograms.xml (right): https://codereview.chromium.org/1426673009/diff/1/tools/metrics/histograms/hi... tools/metrics/histograms/histograms.xml:20787: + should ideally only reflect the IPC time between the browser process and On 2015/11/06 14:07:02, clamy wrote: > On 2015/11/06 13:35:19, csharrison wrote: > > On 2015/11/06 10:58:51, clamy wrote: > > > On transfer navigations, this difference covers more than just the IPC time > > > (same with PlzNavigate btw). Should we exclude these cases from the metric? > > > > Huh, I could have sworn that this comment included something about transfers / > > suspensions. Tbh I'm not totally sure what the right move is. Is there an easy > > way to test renderer-side that this was a transfer? > > transferred_request_request_id != -1? I'd also be willing to increase the > timing > > window and just observe two humps on the histogram by logging everything. > Could > > be a somewhat useful metric in its own right. WDYT? > > transferred_request_request_id != -1 identifies a transferred request. The risk > with increasing the window is that you will have less fine grained results for > smaller values, which I think we care more about. My recommendation would be to > live the window as is, with the possibility of excluding transfer navigations if > there are too many of them (I don't think it's the case). > > Suspended navigations are not an issue: a navigation is only suspended when it > is cross site and we are waiting for the current renderer to execute its > BeforeUnload event. Since we update the navigation start at the moment when the > user clicks on proceed, we should not see a big discrepancy between the browser > navigation start and the renderer navigation start. Ah okay thanks for the clarification, I was conflating the two. Transfers happen for cross site redirects? I'm fine with keeping the window and changing it up if we want to see a longer tail / remove the longer tail. We can always change the positive window and keep the negative window tiny.
https://codereview.chromium.org/1426673009/diff/1/content/renderer/render_fra... File content/renderer/render_frame_impl.cc (right): https://codereview.chromium.org/1426673009/diff/1/content/renderer/render_fra... content/renderer/render_frame_impl.cc:483: base::TimeDelta::FromMilliseconds(1), base::TimeDelta::FromSeconds(5), Suggest using UMA_HISTOGRAM_TIMES(). It gives you a range from 1ms to 10s, which is very similar to your params here. Given that the distribution is exponential, you'll still get lots of resolution at the lower buckets.
On 2015/11/06 16:53:18, Alexei Svitkine (slow) wrote: > https://codereview.chromium.org/1426673009/diff/1/content/renderer/render_fra... > File content/renderer/render_frame_impl.cc (right): > > https://codereview.chromium.org/1426673009/diff/1/content/renderer/render_fra... > content/renderer/render_frame_impl.cc:483: base::TimeDelta::FromMilliseconds(1), > base::TimeDelta::FromSeconds(5), > Suggest using UMA_HISTOGRAM_TIMES(). > > It gives you a range from 1ms to 10s, which is very similar to your params here. > Given that the distribution is exponential, you'll still get lots of resolution > at the lower buckets. SGTM. Looking at a few histograms with 1ms -> 10s, seems good enough on the low end while probably giving us more wiggle room for longer tail. Thanks!
lgtm
The CQ bit was checked by csharrison@chromium.org
The patchset sent to the CQ was uploaded after l-g-t-m from jochen@chromium.org Link to the patchset: https://codereview.chromium.org/1426673009/#ps20001 (title: "use UMA_HISTOGRAM_TIMES")
CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/patch-status/1426673009/20001 View timeline at https://chromium-cq-status.appspot.com/patch-timeline/1426673009/20001
Message was sent while issue was closed.
Committed patchset #2 (id:20001)
Message was sent while issue was closed.
Patchset 2 (id:??) landed as https://crrev.com/a813debae1ce75223a04d0c6044edd7d47822e21 Cr-Commit-Position: refs/heads/master@{#360230} |
|||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
