Chromium Code Reviews
|
|
Chromium Code Reviews
Issue
921473003:
Break down end-to-end scroll update latency UMA metrics (Closed)
|
Created:
5 years, 10 months ago by Yufeng Shen (Slow to review) Modified:
5 years, 10 months ago CC:
chromium-reviews, tdresser+watch_chromium.org, jam, darin-cc_chromium.org, asvitkine+watch_chromium.org, cc-bugs_chromium.org, jdduke+watch_chromium.org, tdresser, Rick Byers Base URL:
https://chromium.googlesource.com/chromium/src.git@master Target Ref:
refs/pending/heads/master Project:
chromium Visibility:
Public. |
DescriptionBreak down end-to-end scroll update latency UMA metrics
End-to-end ScrollUpdate latency UMA metric is not so actionable
when there is regression, partly because the latency pipeline
covers too many subsystems so it is hard to locate which subsystem
is contributing to the regression.
This CL breaks down the end-to-end latency so that we have new
metrics covering various subsystem latency along the end-to-end
latency pipeline.
Specifically, we have
1. ScrollUpdateTouchToHandledMain(Impl)
Touch event creation to event handled on main/impl. This covers
the browser to renderer input dispatching stack.
2. ScrollUpdateHandledMain(Impl)ToRendererSwap
Event handled on main/impl to renderer starts to swap. This covers
the renderer scheduling stack.
3. ScrollUpdateRendererSwapToBrowserNotified
Renderer starts to swap to browser receives the swap notification.
This covers the renderer swap stack and IPC latency between renderer
and browser.
4. ScrollUpdateBrowserNotifiedToBeforeGpuSwap
Browser receives the renderer swap notification to browser starts
to swap. This covers the browser scheduling stack (latency mode
between browser and renderer).
5. ScrollUpdateGpuSwap
Browser starts to swap to gpu finishes swap. This covers the
latency mode between browser and gpu, and the gpu swap cost.
BUG=457825
Committed: https://crrev.com/6c07a33540b859ce77c8f9be0a92dc9d743edffe
Cr-Commit-Position: refs/heads/master@{#316861}
Patch Set 1 #
Total comments: 8
Patch Set 2 : address comments #
Total comments: 8
Patch Set 3 : address comments #
Total comments: 2
Patch Set 4 : address comments #
Total comments: 2
Patch Set 5 : optimize UMA metrics range/bucket size #
Total comments: 3
Patch Set 6 : address comments #Patch Set 7 : add a few DCHECK #Patch Set 8 : #
Total comments: 1
Patch Set 9 : revert to patchset #6 and add TODO #Patch Set 10 : pretty-printing histograms.xml #
Messages
Total messages: 35 (8 generated)
miletus@chromium.org changed reviewers: + danakj@chromium.org, jdduke@chromium.org, sadrul@chromium.org
https://codereview.chromium.org/921473003/diff/1/cc/trees/layer_tree_host_imp... File cc/trees/layer_tree_host_impl.cc (right): https://codereview.chromium.org/921473003/diff/1/cc/trees/layer_tree_host_imp... cc/trees/layer_tree_host_impl.cc:1651: if (!latency.FindLatency(ui::INPUT_EVENT_LATENCY_RENDERER_SWAP_COMPONENT, This seems like a common operation (adding a comonent if not found), and I keep seeing it in various places. Maybe as a follow-up we could simplify all of the callsites and add a helper routine? https://codereview.chromium.org/921473003/diff/1/content/browser/renderer_hos... File content/browser/renderer_host/render_widget_host_latency_tracker.cc (right): https://codereview.chromium.org/921473003/diff/1/content/browser/renderer_hos... content/browser/renderer_host/render_widget_host_latency_tracker.cc:179: ComponentPair renderer_swap_component; Do these always go together? If not, can we early out? If so, should we be validating that?
cc LGTM https://codereview.chromium.org/921473003/diff/1/cc/base/latency_info_swap_pr... File cc/base/latency_info_swap_promise_monitor.cc (right): https://codereview.chromium.org/921473003/diff/1/cc/base/latency_info_swap_pr... cc/base/latency_info_swap_promise_monitor.cc:53: if (AddRenderingScheduledComponent(latency_, true)) { use a comment or a temp bool to give this literal a name like ..., true /* on_main */); or bool on_main = true; ... , on_main); https://codereview.chromium.org/921473003/diff/1/cc/base/latency_info_swap_pr... cc/base/latency_info_swap_promise_monitor.cc:60: if (AddRenderingScheduledComponent(latency_, false)) { dittos
New patchsets have been uploaded after l-g-t-m from danakj@chromium.org
miletus@chromium.org changed reviewers: + asvitkine@chromium.org
+Alexei for tools/metrics/histograms/histograms.xml https://codereview.chromium.org/921473003/diff/1/cc/base/latency_info_swap_pr... File cc/base/latency_info_swap_promise_monitor.cc (right): https://codereview.chromium.org/921473003/diff/1/cc/base/latency_info_swap_pr... cc/base/latency_info_swap_promise_monitor.cc:53: if (AddRenderingScheduledComponent(latency_, true)) { On 2015/02/11 23:38:24, danakj wrote: > use a comment or a temp bool to give this literal a name > like > ..., true /* on_main */); > or > bool on_main = true; > ... , on_main); Done. https://codereview.chromium.org/921473003/diff/1/cc/base/latency_info_swap_pr... cc/base/latency_info_swap_promise_monitor.cc:60: if (AddRenderingScheduledComponent(latency_, false)) { On 2015/02/11 23:38:24, danakj wrote: > dittos Done. https://codereview.chromium.org/921473003/diff/1/cc/trees/layer_tree_host_imp... File cc/trees/layer_tree_host_impl.cc (right): https://codereview.chromium.org/921473003/diff/1/cc/trees/layer_tree_host_imp... cc/trees/layer_tree_host_impl.cc:1651: if (!latency.FindLatency(ui::INPUT_EVENT_LATENCY_RENDERER_SWAP_COMPONENT, On 2015/02/11 23:22:02, jdduke wrote: > This seems like a common operation (adding a comonent if not found), and I keep > seeing it in various places. Maybe as a follow-up we could simplify all of the > callsites and add a helper routine? will do a follow up for this. https://codereview.chromium.org/921473003/diff/1/content/browser/renderer_hos... File content/browser/renderer_host/render_widget_host_latency_tracker.cc (right): https://codereview.chromium.org/921473003/diff/1/content/browser/renderer_hos... content/browser/renderer_host/render_widget_host_latency_tracker.cc:179: ComponentPair renderer_swap_component; On 2015/02/11 23:22:02, jdduke wrote: > Do these always go together? If not, can we early out? If so, should we be > validating that? CHECK seems too restrict here. I will just do early return.
https://codereview.chromium.org/921473003/diff/20001/content/browser/renderer... File content/browser/renderer_host/render_widget_host_latency_tracker.cc (right): https://codereview.chromium.org/921473003/diff/20001/content/browser/renderer... content/browser/renderer_host/render_widget_host_latency_tracker.cc:188: rendering_scheduled_on_main ? This is not valid to do. Histogram macros cache the histogram object on first hit, so this ternary will do nothing on the next invocation. https://codereview.chromium.org/921473003/diff/20001/content/browser/renderer... content/browser/renderer_host/render_widget_host_latency_tracker.cc:230: 1, 1000000, 100); If you're using the same ranges for all of these, please make a helper macro instead of duplicating these constants. Along with a comment explaining why those values were chosen. https://codereview.chromium.org/921473003/diff/20001/tools/metrics/histograms... File tools/metrics/histograms/histograms.xml (right): https://codereview.chromium.org/921473003/diff/20001/tools/metrics/histograms... tools/metrics/histograms/histograms.xml:7314: +<histogram name="Event.Latency.ScrollUpdateBrowserNotifiedToBeforeGpuSwap" Nit: I suggest adding another level of namespace to these to give them better grouping on the dashboard, i.e. Event.Latency.ScrollUpdate.BrowserNotifiedToBeforeGpuSwap https://codereview.chromium.org/921473003/diff/20001/tools/metrics/histograms... tools/metrics/histograms/histograms.xml:7331: +<histogram name="Event.Latency.ScrollUpdateHandledImplToRendererSwap" For these pairs of histogram where the name only differs in "Impl" vs. "Main", please use the histogram_suffixes construct to make the definitions more concise. You can find an example in the file. Note: You can specify a custom separator string - so e.g. the empty string or a dot, if you're not a fan of the default _.
https://codereview.chromium.org/921473003/diff/20001/content/browser/renderer... File content/browser/renderer_host/render_widget_host_latency_tracker.cc (right): https://codereview.chromium.org/921473003/diff/20001/content/browser/renderer... content/browser/renderer_host/render_widget_host_latency_tracker.cc:188: rendering_scheduled_on_main ? On 2015/02/12 15:31:32, Alexei Svitkine wrote: > This is not valid to do. > > Histogram macros cache the histogram object on first hit, so this ternary will > do nothing on the next invocation. Thanks for pointing this out. https://codereview.chromium.org/921473003/diff/20001/content/browser/renderer... content/browser/renderer_host/render_widget_host_latency_tracker.cc:230: 1, 1000000, 100); On 2015/02/12 15:31:33, Alexei Svitkine wrote: > If you're using the same ranges for all of these, please make a helper macro > instead of duplicating these constants. Along with a comment explaining why > those values were chosen. Done. https://codereview.chromium.org/921473003/diff/20001/tools/metrics/histograms... File tools/metrics/histograms/histograms.xml (right): https://codereview.chromium.org/921473003/diff/20001/tools/metrics/histograms... tools/metrics/histograms/histograms.xml:7314: +<histogram name="Event.Latency.ScrollUpdateBrowserNotifiedToBeforeGpuSwap" On 2015/02/12 15:31:33, Alexei Svitkine wrote: > Nit: I suggest adding another level of namespace to these to give them better > grouping on the dashboard, i.e. > > Event.Latency.ScrollUpdate.BrowserNotifiedToBeforeGpuSwap Done. https://codereview.chromium.org/921473003/diff/20001/tools/metrics/histograms... tools/metrics/histograms/histograms.xml:7331: +<histogram name="Event.Latency.ScrollUpdateHandledImplToRendererSwap" On 2015/02/12 15:31:33, Alexei Svitkine wrote: > For these pairs of histogram where the name only differs in "Impl" vs. "Main", > please use the histogram_suffixes construct to make the definitions more > concise. You can find an example in the file. Note: You can specify a custom > separator string - so e.g. the empty string or a dot, if you're not a fan of the > default _. Done.
https://codereview.chromium.org/921473003/diff/40001/content/browser/renderer... File content/browser/renderer_host/render_widget_host_latency_tracker.cc (right): https://codereview.chromium.org/921473003/diff/40001/content/browser/renderer... content/browser/renderer_host/render_widget_host_latency_tracker.cc:139: #define UMA_HISTOGRAM_SCROLL_LATENCY(name, end, start) \ The end vs start arg order is a little confusing when reading the code below, if it's not too much trouble could we reverse it?
https://codereview.chromium.org/921473003/diff/40001/content/browser/renderer... File content/browser/renderer_host/render_widget_host_latency_tracker.cc (right): https://codereview.chromium.org/921473003/diff/40001/content/browser/renderer... content/browser/renderer_host/render_widget_host_latency_tracker.cc:139: #define UMA_HISTOGRAM_SCROLL_LATENCY(name, end, start) \ On 2015/02/12 21:44:08, jdduke wrote: > The end vs start arg order is a little confusing when reading the code below, if > it's not too much trouble could we reverse it? Done.
https://codereview.chromium.org/921473003/diff/60001/content/browser/renderer... File content/browser/renderer_host/render_widget_host_latency_tracker.cc (right): https://codereview.chromium.org/921473003/diff/60001/content/browser/renderer... content/browser/renderer_host/render_widget_host_latency_tracker.cc:138: // Scroll latency is mostly under 1000ms. I'm not convinced that these macro params are the best. When I look at an existing histogram using these: https://uma.googleplex.com/histograms/?dayCount=1&endDate=02-12-2015&version=... It looks like most of the interesting data happens around 5ms - 200ms range. At which point, most of the bucket sizes are several ms in size. Which doesn't seem any better than what you get with just a UMA_HISTOGRAM_TIMES() macro, e.g.: https://uma.googleplex.com/histograms/?dayCount=1&endDate=02-12-2015&version=... But you can probably do even better by just customizing UMA_HISTOGRAM_TIMES() and logging in ms. For example, you can set it's max to be 1s like you do here, which will give you smaller bucket sizes. Or increase the number of buckets (default is 50) - although I'm hoping you actually don't need the full 100 buckets. The more buckets there are, the more space is used in logs and bandwidth to transmit - so it should only be increased if there's a real benefit. So the question is, what kind of granularity you're looking for? Perhaps the default UMA_HISTOGRAM_TIMES buckets are sufficient?
https://codereview.chromium.org/921473003/diff/60001/content/browser/renderer... File content/browser/renderer_host/render_widget_host_latency_tracker.cc (right): https://codereview.chromium.org/921473003/diff/60001/content/browser/renderer... content/browser/renderer_host/render_widget_host_latency_tracker.cc:138: // Scroll latency is mostly under 1000ms. On 2015/02/13 16:16:33, Alexei Svitkine wrote: > I'm not convinced that these macro params are the best. > > When I look at an existing histogram using these: > > https://uma.googleplex.com/histograms/?dayCount=1&endDate=02-12-2015&version=... > > It looks like most of the interesting data happens around 5ms - 200ms range. > > At which point, most of the bucket sizes are several ms in size. > > Which doesn't seem any better than what you get with just a > UMA_HISTOGRAM_TIMES() macro, e.g.: > > https://uma.googleplex.com/histograms/?dayCount=1&endDate=02-12-2015&version=... > > But you can probably do even better by just customizing UMA_HISTOGRAM_TIMES() > and logging in ms. > > For example, you can set it's max to be 1s like you do here, which will give you > smaller bucket sizes. Or increase the number of buckets (default is 50) - > although I'm hoping you actually don't need the full 100 buckets. The more > buckets there are, the more space is used in logs and bandwidth to transmit - so > it should only be increased if there's a real benefit. > > So the question is, what kind of granularity you're looking for? Perhaps the > default UMA_HISTOGRAM_TIMES buckets are sufficient? Thanks Alexei for the suggestions. Here is what's in the new patchset: 1) The UMA range/bucket size for the existing metrics remain the same so we don't lose the history data. 2) For the new metrics added, we have some to be collected with the long range that's between under 200ms and 50 buckets. And the others collected with the short range that's under 50ms and 50 buckets. This should improve the granularity and collecting overhead. PTAL, thanks.
https://codereview.chromium.org/921473003/diff/80001/content/browser/renderer... File content/browser/renderer_host/render_widget_host_latency_tracker.cc (right): https://codereview.chromium.org/921473003/diff/80001/content/browser/renderer... content/browser/renderer_host/render_widget_host_latency_tracker.cc:217: UMA_HISTOGRAM_SCROLL_LATENCY_LONG( Will using separate buckets for impl vs main make it hard to compare between the two?
https://codereview.chromium.org/921473003/diff/80001/content/browser/renderer... File content/browser/renderer_host/render_widget_host_latency_tracker.cc (right): https://codereview.chromium.org/921473003/diff/80001/content/browser/renderer... content/browser/renderer_host/render_widget_host_latency_tracker.cc:217: UMA_HISTOGRAM_SCROLL_LATENCY_LONG( Will using separate buckets for impl vs main make it hard to compare between the two?
https://codereview.chromium.org/921473003/diff/80001/content/browser/renderer... File content/browser/renderer_host/render_widget_host_latency_tracker.cc (right): https://codereview.chromium.org/921473003/diff/80001/content/browser/renderer... content/browser/renderer_host/render_widget_host_latency_tracker.cc:217: UMA_HISTOGRAM_SCROLL_LATENCY_LONG( On 2015/02/17 20:40:37, jdduke wrote: > Will using separate buckets for impl vs main make it hard to compare between the > two? I have this concern as well - if you're planning to compare, use the same macro.
https://codereview.chromium.org/921473003/diff/80001/content/browser/renderer... File content/browser/renderer_host/render_widget_host_latency_tracker.cc (right): https://codereview.chromium.org/921473003/diff/80001/content/browser/renderer... content/browser/renderer_host/render_widget_host_latency_tracker.cc:217: UMA_HISTOGRAM_SCROLL_LATENCY_LONG( On 2015/02/17 20:53:02, Alexei Svitkine wrote: > On 2015/02/17 20:40:37, jdduke wrote: > > Will using separate buckets for impl vs main make it hard to compare between > the > > two? > > I have this concern as well - if you're planning to compare, use the same macro. Done.
lgtm
Jared, how does this look to you ? Also is render_widget_host_latency_tracker.cc suitable candidate to live in input/ ? so we have more specific OWNER for it rather than having you to review it and sadrul@ to rubber stamp ?
This looks fine. I'd feel a little better with some sanity DCHECK validation that we get all of the correct components if we ever get the final swap component (or maybe a DCHECK that the components are monotonically non-decreasing in time), but maybe that's overkill. In any case, moving RWHLatencyTracker to input/ also sounds fine.
New patchsets have been uploaded after l-g-t-m from asvitkine@chromium.org
On 2015/02/17 23:16:01, jdduke wrote: > This looks fine. I'd feel a little better with some sanity DCHECK validation > that we get all of the correct components if we ever get the final swap > component (or maybe a DCHECK that the components are monotonically > non-decreasing in time), but maybe that's overkill. done. > > In any case, moving RWHLatencyTracker to input/ also sounds fine.
https://codereview.chromium.org/921473003/diff/140001/content/browser/rendere... File content/browser/renderer_host/render_widget_host_latency_tracker.cc (right): https://codereview.chromium.org/921473003/diff/140001/content/browser/rendere... content/browser/renderer_host/render_widget_host_latency_tracker.cc:248: DCHECK(ret && gpu_swap_component.event_time >= Hmm, these combined DCHECK conditions will be difficult to debug in practice. Maybe let's leave them for a follow-up (back to patchset #6), just add a TODO? Otherwise, I would use a NOTREACHED() + return for the find failure, and perhaps add a DCHECK to the UMA macro. Regardless, let's add the validation in a separate patch.
On 2015/02/18 00:00:16, jdduke wrote: > https://codereview.chromium.org/921473003/diff/140001/content/browser/rendere... > File content/browser/renderer_host/render_widget_host_latency_tracker.cc > (right): > > https://codereview.chromium.org/921473003/diff/140001/content/browser/rendere... > content/browser/renderer_host/render_widget_host_latency_tracker.cc:248: > DCHECK(ret && gpu_swap_component.event_time >= > Hmm, these combined DCHECK conditions will be difficult to debug in practice. > Maybe let's leave them for a follow-up (back to patchset #6), just add a TODO? > done > Otherwise, I would use a NOTREACHED() + return for the find failure, and perhaps > add a DCHECK to the UMA macro. Regardless, let's add the validation in a > separate patch.
On 2015/02/18 02:14:05, Yufeng Shen wrote: > On 2015/02/18 00:00:16, jdduke wrote: > > > https://codereview.chromium.org/921473003/diff/140001/content/browser/rendere... > > File content/browser/renderer_host/render_widget_host_latency_tracker.cc > > (right): > > > > > https://codereview.chromium.org/921473003/diff/140001/content/browser/rendere... > > content/browser/renderer_host/render_widget_host_latency_tracker.cc:248: > > DCHECK(ret && gpu_swap_component.event_time >= > > Hmm, these combined DCHECK conditions will be difficult to debug in practice. > > Maybe let's leave them for a follow-up (back to patchset #6), just add a TODO? > > > > done > > > Otherwise, I would use a NOTREACHED() + return for the find failure, and > perhaps > > add a DCHECK to the UMA macro. Regardless, let's add the validation in a > > separate patch. lgtm, thanks.
lgtm
The CQ bit was checked by miletus@chromium.org
CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/patch-status/921473003/160001
The CQ bit was unchecked by commit-bot@chromium.org
Try jobs failed on following builders: chromium_presubmit on tryserver.chromium.linux (JOB_FAILED, http://build.chromium.org/p/tryserver.chromium.linux/builders/chromium_presub...)
New patchsets have been uploaded after l-g-t-m from jdduke@chromium.org,sadrul@chromium.org
The CQ bit was checked by miletus@chromium.org
CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/patch-status/921473003/180001
Message was sent while issue was closed.
Committed patchset #10 (id:180001)
Message was sent while issue was closed.
Patchset 10 (id:??) landed as https://crrev.com/6c07a33540b859ce77c8f9be0a92dc9d743edffe Cr-Commit-Position: refs/heads/master@{#316861} |
|||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
