Chromium Code Reviews
|
|
Chromium Code Reviews
Issue
2911743002:
Add UMA metric of time to start the first render process (Closed)
DescriptionAdd UMA metric of time to start the first renderer process
BUG=728324
TBR=fdoray
Review-Url: https://codereview.chromium.org/2911743002
Cr-Commit-Position: refs/heads/master@{#476049}
Committed: https://chromium.googlesource.com/chromium/src/+/85233645d272d0d71cc23bb73d40ad4a1d4d7d39
Patch Set 1 #Patch Set 2 : fix copy-o #
Total comments: 6
Patch Set 3 : Address comments #Patch Set 4 : rebase #
Total comments: 2
Messages
Total messages: 34 (14 generated)
hans@chromium.org changed reviewers: + fdoray@chromium.org, isherman@chromium.org, rnk@chromium.org, thakis@chromium.org
My Chrome-fu feels pretty weak here, but what I want to measure is the time from when the browser decides to start the first renderer process (I believe this happens in the first RenderProcessHostImpl::Init call) to the time that process is up and running (OnFirstVisuallyNonEmptyPaint seems to be the thing we normally look for, but I'm not entirely sure what that means...) The idea is that we'd like to confirm whether the NewTabPage.LoadTime metric is slower with Clang because of render process start-up time. And it seems like an interesting metric in general too.
isherman@chromium.org changed reviewers: + bmcquade@chromium.org
Metrics LGTM in terms of API use and clarity. Adding Bryan (and cc'ing Tim and Charlie) as folks who might be able to offer some wisdom as to the substance of the metric.
On 2017/05/26 at 22:03:59, isherman wrote: > Metrics LGTM in terms of API use and clarity. Adding Bryan (and cc'ing Tim and Charlie) as folks who might be able to offer some wisdom as to the substance of the metric. Thanks! For paint-related page load metrics, we tend to try to record these in the page_load_metrics codebase, where we have the exact TimeTicks timestamps that these paints happened in the render process, sent to browser process code over IPC. This is more accurate than hooking the OnFirstVisuallyNonEmptyPaint callback and taking a timestamp, which may include delay from IPC/Mojo time etc. That said, given that the existing code here already uses OnFirstVisuallyNonEmptyPaint as its signal, I think it's probably fine to continue doing this here. But it may be beneficial to take an AI to migrate these metrics over to the page load metrics code in the future. Here's a doc with more details on this: https://docs.google.com/document/d/1ApM09ygFdNBHjQogYJ_rUwGyFcCplWZFhcJfsUFkF...
https://codereview.chromium.org/2911743002/diff/20001/chrome/browser/metrics/... File chrome/browser/metrics/first_web_contents_profiler.cc (right): https://codereview.chromium.org/2911743002/diff/20001/chrome/browser/metrics/... chrome/browser/metrics/first_web_contents_profiler.cc:114: ->GetInitTimeForNavigationMetrics()); I notice that the comment for GetInitTimeForNavigationMetrics includes: // Note: Do not use! Will disappear after PlzNavitate is completed. Is there some other timestamp source we could use instead?
tdresser@chromium.org changed reviewers: + tdresser@chromium.org
A few extremely minor nits. Other than Bryan's concern, this LGTM. https://codereview.chromium.org/2911743002/diff/20001/chrome/browser/metrics/... File chrome/browser/metrics/startup_metrics_browsertest.cc (right): https://codereview.chromium.org/2911743002/diff/20001/chrome/browser/metrics/... chrome/browser/metrics/startup_metrics_browsertest.cc:26: "Startup.FirstWebContents.RenderProcessHostInit.To.NonEmptyPaint", Maybe ToNonEmptyPaint instead of To.NonEmptyPaint? https://codereview.chromium.org/2911743002/diff/20001/components/startup_metr... File components/startup_metric_utils/browser/startup_metric_utils.h (right): https://codereview.chromium.org/2911743002/diff/20001/components/startup_metr... components/startup_metric_utils/browser/startup_metric_utils.h:86: // only if the first web contents was unimpended in its attempt to do so. Can we fix unimpended -> unimpeded while we're here?
On 2017/05/26 22:28:32, Bryan McQuade wrote: > On 2017/05/26 at 22:03:59, isherman wrote: > > Metrics LGTM in terms of API use and clarity. Adding Bryan (and cc'ing Tim > and Charlie) as folks who might be able to offer some wisdom as to the substance > of the metric. > > Thanks! > > For paint-related page load metrics, we tend to try to record these in the > page_load_metrics codebase, where we have the exact TimeTicks timestamps that > these paints happened in the render process, sent to browser process code over > IPC. This is more accurate than hooking the OnFirstVisuallyNonEmptyPaint > callback and taking a timestamp, which may include delay from IPC/Mojo time etc. > > That said, given that the existing code here already uses > OnFirstVisuallyNonEmptyPaint as its signal, I think it's probably fine to > continue doing this here. But it may be beneficial to take an AI to migrate > these metrics over to the page load metrics code in the future. Here's a doc > with more details on this: > https://docs.google.com/document/d/1ApM09ygFdNBHjQogYJ_rUwGyFcCplWZFhcJfsUFkF... Yes, since the other code is using OnFirstVisuallyNonEmptyPaint, I figured I'd just go with that too. I don't really care about painting per se; I just want a notification when the renderer is up and running, but the code I found all just this metric? Do you know if there's something better I could use?
On 2017/05/31 at 17:58:00, hans wrote: > On 2017/05/26 22:28:32, Bryan McQuade wrote: > > On 2017/05/26 at 22:03:59, isherman wrote: > > > Metrics LGTM in terms of API use and clarity. Adding Bryan (and cc'ing Tim > > and Charlie) as folks who might be able to offer some wisdom as to the substance > > of the metric. > > > > Thanks! > > > > For paint-related page load metrics, we tend to try to record these in the > > page_load_metrics codebase, where we have the exact TimeTicks timestamps that > > these paints happened in the render process, sent to browser process code over > > IPC. This is more accurate than hooking the OnFirstVisuallyNonEmptyPaint > > callback and taking a timestamp, which may include delay from IPC/Mojo time etc. > > > > That said, given that the existing code here already uses > > OnFirstVisuallyNonEmptyPaint as its signal, I think it's probably fine to > > continue doing this here. But it may be beneficial to take an AI to migrate > > these metrics over to the page load metrics code in the future. Here's a doc > > with more details on this: > > https://docs.google.com/document/d/1ApM09ygFdNBHjQogYJ_rUwGyFcCplWZFhcJfsUFkF... > > Yes, since the other code is using OnFirstVisuallyNonEmptyPaint, I figured I'd just go with that too. > > I don't really care about painting per se; I just want a notification when the renderer is up and running, but the code I found all just this metric? Do you know if there's something better I could use? If you want to know that the render process is up and running you might be able to use RenderFrameCreated on WebContentsObserver. Its comments say: // Called when a RenderFrame for |render_frame_host| is created in the // renderer process. Use |RenderFrameDeleted| to listen for when this // RenderFrame goes away. That said, I have very limited knowledge of how exactly these APIs work, when render frames are created during render process initialization, etc, so it'd be worth asking someone more familiar with these APIs (maybe nasko?) for guidance. That said I think it's totally fine to continue to use OnFirstVisuallyNonEmptyPaint in the meantime. Don't want to block your progress here.
On 2017/05/31 18:19:32, Bryan McQuade wrote: > On 2017/05/31 at 17:58:00, hans wrote: > > On 2017/05/26 22:28:32, Bryan McQuade wrote: > > > On 2017/05/26 at 22:03:59, isherman wrote: > > > > Metrics LGTM in terms of API use and clarity. Adding Bryan (and cc'ing > Tim > > > and Charlie) as folks who might be able to offer some wisdom as to the > substance > > > of the metric. > > > > > > Thanks! > > > > > > For paint-related page load metrics, we tend to try to record these in the > > > page_load_metrics codebase, where we have the exact TimeTicks timestamps > that > > > these paints happened in the render process, sent to browser process code > over > > > IPC. This is more accurate than hooking the OnFirstVisuallyNonEmptyPaint > > > callback and taking a timestamp, which may include delay from IPC/Mojo time > etc. > > > > > > That said, given that the existing code here already uses > > > OnFirstVisuallyNonEmptyPaint as its signal, I think it's probably fine to > > > continue doing this here. But it may be beneficial to take an AI to migrate > > > these metrics over to the page load metrics code in the future. Here's a doc > > > with more details on this: > > > > https://docs.google.com/document/d/1ApM09ygFdNBHjQogYJ_rUwGyFcCplWZFhcJfsUFkF... > > > > Yes, since the other code is using OnFirstVisuallyNonEmptyPaint, I figured I'd > just go with that too. > > > > I don't really care about painting per se; I just want a notification when the > renderer is up and running, but the code I found all just this metric? Do you > know if there's something better I could use? > > If you want to know that the render process is up and running you might be able > to use RenderFrameCreated on WebContentsObserver. Its comments say: > > // Called when a RenderFrame for |render_frame_host| is created in the > // renderer process. Use |RenderFrameDeleted| to listen for when this > // RenderFrame goes away. > > That said, I have very limited knowledge of how exactly these APIs work, when > render frames are created during render process initialization, etc, so it'd be > worth asking someone more familiar with these APIs (maybe nasko?) for guidance. > > That said I think it's totally fine to continue to use > OnFirstVisuallyNonEmptyPaint in the meantime. Don't want to block your progress > here. Thanks, I'll go with this for now.
https://codereview.chromium.org/2911743002/diff/20001/chrome/browser/metrics/... File chrome/browser/metrics/first_web_contents_profiler.cc (right): https://codereview.chromium.org/2911743002/diff/20001/chrome/browser/metrics/... chrome/browser/metrics/first_web_contents_profiler.cc:114: ->GetInitTimeForNavigationMetrics()); On 2017/05/26 22:28:42, Bryan McQuade wrote: > I notice that the comment for GetInitTimeForNavigationMetrics includes: > // Note: Do not use! Will disappear after PlzNavitate is completed. > > Is there some other timestamp source we could use instead? I'm not familiar with PlzNagigate (looks like something added in 2014), and I think this is the timestamp I want. As far as I can tell, this is the one place where we capture the timestamp for starting the render process. (The comment is a little misleading, we set the timestamp after we've created the ChildProcessLauncher, but IIUC, the actual launching happens asynchronously.) https://codereview.chromium.org/2911743002/diff/20001/chrome/browser/metrics/... File chrome/browser/metrics/startup_metrics_browsertest.cc (right): https://codereview.chromium.org/2911743002/diff/20001/chrome/browser/metrics/... chrome/browser/metrics/startup_metrics_browsertest.cc:26: "Startup.FirstWebContents.RenderProcessHostInit.To.NonEmptyPaint", On 2017/05/29 13:38:02, tdresser wrote: > Maybe ToNonEmptyPaint instead of To.NonEmptyPaint? Done. https://codereview.chromium.org/2911743002/diff/20001/components/startup_metr... File components/startup_metric_utils/browser/startup_metric_utils.h (right): https://codereview.chromium.org/2911743002/diff/20001/components/startup_metr... components/startup_metric_utils/browser/startup_metric_utils.h:86: // only if the first web contents was unimpended in its attempt to do so. On 2017/05/29 13:38:02, tdresser wrote: > Can we fix unimpended -> unimpeded while we're here? Done.
The CQ bit was checked by hans@chromium.org
The patchset sent to the CQ was uploaded after l-g-t-m from isherman@chromium.org, tdresser@chromium.org Link to the patchset: https://codereview.chromium.org/2911743002/#ps60001 (title: "rebase")
CQ is trying da patch. Follow status at: https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...
Description was changed from ========== Add UMA metric of time to start the first renderer process BUG=none ========== to ========== Add UMA metric of time to start the first renderer process BUG=728324 ==========
fdoray: Can you take an owner's look for components/startup_metric_utils/browser/ ?
The CQ bit was unchecked by commit-bot@chromium.org
Try jobs failed on following builders: chromium_presubmit on master.tryserver.chromium.linux (JOB_FAILED, http://build.chromium.org/p/tryserver.chromium.linux/builders/chromium_presub...)
hans@chromium.org changed reviewers: + gab@chromium.org
On 2017/05/31 20:15:17, hans wrote: > fdoray: Can you take an owner's look for > components/startup_metric_utils/browser/ ? or gab, if you're around?
Description was changed from ========== Add UMA metric of time to start the first renderer process BUG=728324 ========== to ========== Add UMA metric of time to start the first renderer process BUG=728324 TBR=fdoray ==========
tbr'ing so we can get this into the next dev release
The CQ bit was checked by hans@chromium.org
CQ is trying da patch. Follow status at: https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...
The CQ bit was unchecked by hans@chromium.org
The CQ bit was checked by hans@chromium.org
CQ is trying da patch. Follow status at: https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...
CQ is committing da patch.
Bot data: {"patchset_id": 60001, "attempt_start_ts": 1496267091736370,
"parent_rev": "4f307f2f73c304ee22ac9fb43d3ce4fbf493ae4a", "commit_rev":
"85233645d272d0d71cc23bb73d40ad4a1d4d7d39"}
Message was sent while issue was closed.
Description was changed from ========== Add UMA metric of time to start the first renderer process BUG=728324 TBR=fdoray ========== to ========== Add UMA metric of time to start the first renderer process BUG=728324 TBR=fdoray Review-Url: https://codereview.chromium.org/2911743002 Cr-Commit-Position: refs/heads/master@{#476049} Committed: https://chromium.googlesource.com/chromium/src/+/85233645d272d0d71cc23bb73d40... ==========
Message was sent while issue was closed.
Committed patchset #4 (id:60001) as https://chromium.googlesource.com/chromium/src/+/85233645d272d0d71cc23bb73d40...
Message was sent while issue was closed.
On 2017/05/31 21:43:53, hans wrote: > tbr'ing so we can get this into the next dev release I don't think this is an appropriate use of TBR. Please see the documentation at [ https://chromium.googlesource.com/chromium/src/+/master/docs/code_reviews.md#... ]. Quoting from the docs: "Do not use TBR just because a change is urgent or the reviewer is being slow. Contact the reviewer directly or find somebody."
Message was sent while issue was closed.
https://codereview.chromium.org/2911743002/diff/60001/chrome/browser/metrics/... File chrome/browser/metrics/first_web_contents_profiler.cc (right): https://codereview.chromium.org/2911743002/diff/60001/chrome/browser/metrics/... chrome/browser/metrics/first_web_contents_profiler.cc:114: ->GetInitTimeForNavigationMetrics()); Does the browser get this signal before? startup_metric_utils works by getting individual signals (e.g. process start, message loop start, etc.) and then computing metrics from them. Would be preferable to keep it that way instead of passing two values into RecordNonEmptyPaint() -- e.g. if we wanted RenderedStart->MainNavigationStart we could not with this approach. https://codereview.chromium.org/2911743002/diff/60001/components/startup_metr... File components/startup_metric_utils/browser/startup_metric_utils.cc (right): https://codereview.chromium.org/2911743002/diff/60001/components/startup_metr... components/startup_metric_utils/browser/startup_metric_utils.cc:746: UMA_HISTOGRAM_WITH_TEMPERATURE( UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE so it appears in startup trace events.
Message was sent while issue was closed.
On 2017/06/01 14:56:45, gab wrote: > https://codereview.chromium.org/2911743002/diff/60001/chrome/browser/metrics/... > File chrome/browser/metrics/first_web_contents_profiler.cc (right): > > https://codereview.chromium.org/2911743002/diff/60001/chrome/browser/metrics/... > chrome/browser/metrics/first_web_contents_profiler.cc:114: > ->GetInitTimeForNavigationMetrics()); > Does the browser get this signal before? startup_metric_utils works by getting > individual signals (e.g. process start, message loop start, etc.) and then > computing metrics from them. > > Would be preferable to keep it that way instead of passing two values into > RecordNonEmptyPaint() -- e.g. if we wanted RenderedStart->MainNavigationStart we > could not with this approach. > > https://codereview.chromium.org/2911743002/diff/60001/components/startup_metr... > File components/startup_metric_utils/browser/startup_metric_utils.cc (right): > > https://codereview.chromium.org/2911743002/diff/60001/components/startup_metr... > components/startup_metric_utils/browser/startup_metric_utils.cc:746: > UMA_HISTOGRAM_WITH_TEMPERATURE( > UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE > > so it appears in startup trace events. Thanks for the comments! I started a follow-up patch to address this: https://codereview.chromium.org/2913423003/ |
|||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
