[animations] Adds metrics for jank on selected layer animations

[animations] Adds metrics for jank on selected layer animations

This CL is WIP to add UMA metrics for "smoothness" factor on
selected layer animations. The UI developer would be able to
tag selected animations (sequences or elements) with a "name"
and then have UMA data available for how smooth (how close to
ideal 60 fps) the animation is in the field.

BUG=684115
Review-Url: https://codereview.chromium.org/2631333002
Cr-Commit-Position: refs/heads/master@{#446075}
Committed: https://chromium.googlesource.com/chromium/src/+/62ba671daf03f09c08257fab4559a31259aa09ce

[varkha, 2017-01-17 02:25:44]

Description was changed from

==========
[animations] Adds metrics for jank on selected layer animations

BUG=TBD
==========

to

==========
[animations] Adds metrics for jank on selected layer animations

This CL is WIP to add UMA metrics for "smoothness" factor on
selected layer animations. The UI developer would be able to
tag selected animations (sequences or elements) with a "name"
and then have UMA data available for how smooth (how close to
ideal 60 fps) the animation is in the field.

BUG=TBD
==========

[varkha, 2017-01-18 20:22:43]

varkha@chromium.org changed reviewers:
+ ajuma@chromium.org

[varkha, 2017-01-18 20:22:44]

ajuma@, I wanted to ask you to take a first look at this. I am trying to get
some high-level user-identifiable scenarios log meaningful metrics about
animations frame rate. This CL adds ability to pass a UMA reporter to an
animation element or animation sequence and have the elements log the timing
information when animations complete.
I am quite sure this would be useful to front-end UI developers, we could watch
for regressions on particular hardware in particular scenarios as well as
experiment more while understanding performance implications.

[reveman, 2017-01-18 21:27:52]

reveman@chromium.org changed reviewers:
+ reveman@chromium.org

[reveman, 2017-01-18 21:27:53]

Drive-by: would it be more useful to have perf tests that track these statistics
than UMA stats? Perf tests would be much easier to act on. They can be used
locally when working on performance improvements and we'd be able to detect
regression earlier and not have to wait until it reaches our users?

[ajuma, 2017-01-18 23:02:51]

Perf tests are definitely more actionable, so adding those if possible would be
great. I think there's also value to UMA here though, even as a sanity check to
make sure our perf tests aren't missing real regressions.

https://codereview.chromium.org/2631333002/diff/40001/ui/compositor/composito...
File ui/compositor/compositor.cc (right):

https://codereview.chromium.org/2631333002/diff/40001/ui/compositor/composito...
ui/compositor/compositor.cc:549: return host_->SourceFrameNumber();
This number won't get incremented for frames that are impl-side only in cc. Even
though we don't have a compositor thread for ui, we're still able to tick
"composited" animations without going through the "main-thread" side code, so if
the animation is only for transform or opacity the SourceFrameNumber might only
get incremented at the beginning and end.

Instead, adding a count to calls to Compositor::DidSubmitCompositorFrame (either
directly or by adding a CompositorObserver) would work.

https://codereview.chromium.org/2631333002/diff/40001/ui/compositor/layer_ani...
File ui/compositor/layer_animation_element.cc (right):

https://codereview.chromium.org/2631333002/diff/40001/ui/compositor/layer_ani...
ui/compositor/layer_animation_element.cc:554: (60.f *
duration_.InMillisecondsF()))));
Looking at how this can get called, it seems possible this gets called when
we're ending the animation early because of it being pre-empted. If that's
possible then the duration wouldn't be the right one to use.

[varkha, 2017-01-20 00:16:11]

Patchset #2 (id:20001) has been deleted

[varkha, 2017-01-20 00:16:47]

https://codereview.chromium.org/2631333002/diff/40001/ui/compositor/composito...
File ui/compositor/compositor.cc (right):

https://codereview.chromium.org/2631333002/diff/40001/ui/compositor/composito...
ui/compositor/compositor.cc:549: return host_->SourceFrameNumber();
On 2017/01/18 23:02:51, ajuma wrote:
> This number won't get incremented for frames that are impl-side only in cc.
Even
> though we don't have a compositor thread for ui, we're still able to tick
> "composited" animations without going through the "main-thread" side code, so
if
> the animation is only for transform or opacity the SourceFrameNumber might
only
> get incremented at the beginning and end.
> 
> Instead, adding a count to calls to Compositor::DidSubmitCompositorFrame
(either
> directly or by adding a CompositorObserver) would work.

Done.

https://codereview.chromium.org/2631333002/diff/40001/ui/compositor/layer_ani...
File ui/compositor/layer_animation_element.cc (right):

https://codereview.chromium.org/2631333002/diff/40001/ui/compositor/layer_ani...
ui/compositor/layer_animation_element.cc:554: (60.f *
duration_.InMillisecondsF()))));
On 2017/01/18 23:02:51, ajuma wrote:
> Looking at how this can get called, it seems possible this gets called when
> we're ending the animation early because of it being pre-empted. If that's
> possible then the duration wouldn't be the right one to use.

Is something like that too naive? Looking at the ways ProgressToEnd gets called
it is not easy to distinguish and as long as we only use this timing for metrics
it should not change statistics significantly (and should not affect anything
else).

[ajuma, 2017-01-20 14:31:58]

https://codereview.chromium.org/2631333002/diff/40001/ui/compositor/layer_ani...
File ui/compositor/layer_animation_element.cc (right):

https://codereview.chromium.org/2631333002/diff/40001/ui/compositor/layer_ani...
ui/compositor/layer_animation_element.cc:554: (60.f *
duration_.InMillisecondsF()))));
On 2017/01/20 00:16:47, varkha wrote:
> On 2017/01/18 23:02:51, ajuma wrote:
> > Looking at how this can get called, it seems possible this gets called when
> > we're ending the animation early because of it being pre-empted. If that's
> > possible then the duration wouldn't be the right one to use.
> 
> Is something like that too naive? Looking at the ways ProgressToEnd gets
called
> it is not easy to distinguish and as long as we only use this timing for
metrics
> it should not change statistics significantly (and should not affect anything
> else).

My only worry is that the statistics might be misleading (that is, we'll think
frame rate is poor when it's not; or something that increases/decreases how
often animations end early will look like a regression/progression in
smoothness). 

One thing we could do to filter out animations that ended early is to check
whether effective_start_time_ + duration_ >= now (or, alternatively, we could
use now - effective_start_time_ instead of using duration_).

Either way, would it be possible to unit test this?

[varkha, 2017-01-20 17:07:58]

https://codereview.chromium.org/2631333002/diff/40001/ui/compositor/layer_ani...
File ui/compositor/layer_animation_element.cc (right):

https://codereview.chromium.org/2631333002/diff/40001/ui/compositor/layer_ani...
ui/compositor/layer_animation_element.cc:554: (60.f *
duration_.InMillisecondsF()))));
On 2017/01/20 14:31:58, ajuma wrote:
> On 2017/01/20 00:16:47, varkha wrote:
> > On 2017/01/18 23:02:51, ajuma wrote:
> > > Looking at how this can get called, it seems possible this gets called
when
> > > we're ending the animation early because of it being pre-empted. If that's
> > > possible then the duration wouldn't be the right one to use.
> > 
> > Is something like that too naive? Looking at the ways ProgressToEnd gets
> called
> > it is not easy to distinguish and as long as we only use this timing for
> metrics
> > it should not change statistics significantly (and should not affect
anything
> > else).
> 
> My only worry is that the statistics might be misleading (that is, we'll think
> frame rate is poor when it's not; or something that increases/decreases how
> often animations end early will look like a regression/progression in
> smoothness). 
> 
> One thing we could do to filter out animations that ended early is to check
> whether effective_start_time_ + duration_ >= now (or, alternatively, we could
> use now - effective_start_time_ instead of using duration_).
> 
> Either way, would it be possible to unit test this?

> check whether effective_start_time_ + duration_ >= now
Isn't that exactly what I am doing here?

[sadrul, 2017-01-20 17:29:42]

sadrul@chromium.org changed reviewers:
+ sadrul@chromium.org

[sadrul, 2017-01-20 17:29:43]

drive-by: I have questions about things are wired up right now. My understanding
of how things are right in the CL:
 . User creates an AnimationMetricsReporter, which is eventually attached to
LayerAnimationElement. Either user directly sets it on the
LayerAnimationSequence, which then attaches it to the LayerAnimationElement, or
user sets it on the LayerAnimator, which then sets on the
LayerAnimationSequence(s) it creates, and those get attached to
LayerAnimationElements. These AnimationMetricsReporter objects are leaked.

 . LayerAnimationElement track the 'frame number' of the compositor.

 . LayerAnimationElement does not report if the animation ends early (e.g.
aborted, or preempted by some other animation).

What if:

 . Instead of tracking the 'frame number', LayerAnimationElement tracks the
number of 'Progress()' steps between start and stop, and simply returns a
'progress-steps per second' metric to Report()?

 . Can we have LayerAnimator (or Sequence?) own the Reporter object, so that it
is not leaked? Although maybe that gets complicated when you consider adding a
reporter from a ScopedLayerAnimationSettings.

 . Can we just create a concrete Reporter object that takes in the name of the
UMA metric? Or just do 'LayerAnimator::StartReportingMetric(name);' and
LayerAnimator::StopReportingMetric(name);' (and a corresponding
'ScopedLayerAnimationSettings::ReportMetric(name);'), and the reporter itself is
created/destroyed internally by the animation code.

https://codereview.chromium.org/2631333002/diff/60001/ui/compositor/layer_ani...
File ui/compositor/layer_animator.cc (right):

https://codereview.chromium.org/2631333002/diff/60001/ui/compositor/layer_ani...
ui/compositor/layer_animator.cc:104: StartAnimation(sequence);                  
                        \
Does this cover all the cases? e.g. what if LayerAnimator::StartTogether() is
called to trigger some animation?

[ajuma, 2017-01-20 18:02:52]

On 2017/01/20 17:29:43, sadrul wrote:
> drive-by: I have questions about things are wired up right now. My
understanding
> of how things are right in the CL:
>  . User creates an AnimationMetricsReporter, which is eventually attached to
> LayerAnimationElement. Either user directly sets it on the
> LayerAnimationSequence, which then attaches it to the LayerAnimationElement,
or
> user sets it on the LayerAnimator, which then sets on the
> LayerAnimationSequence(s) it creates, and those get attached to
> LayerAnimationElements. These AnimationMetricsReporter objects are leaked.
> 
>  . LayerAnimationElement track the 'frame number' of the compositor.
> 
>  . LayerAnimationElement does not report if the animation ends early (e.g.
> aborted, or preempted by some other animation).
> 
> What if:
> 
>  . Instead of tracking the 'frame number', LayerAnimationElement tracks the
> number of 'Progress()' steps between start and stop, and simply returns a
> 'progress-steps per second' metric to Report()?

This won't work for animations sent to cc (opacity and transform) since those
can proceed in cc without Progress getting called on the LayerAnimationElement.

[ajuma, 2017-01-20 18:03:05]

https://codereview.chromium.org/2631333002/diff/40001/ui/compositor/layer_ani...
File ui/compositor/layer_animation_element.cc (right):

https://codereview.chromium.org/2631333002/diff/40001/ui/compositor/layer_ani...
ui/compositor/layer_animation_element.cc:554: (60.f *
duration_.InMillisecondsF()))));
On 2017/01/20 17:07:58, varkha wrote:
> On 2017/01/20 14:31:58, ajuma wrote:
> > On 2017/01/20 00:16:47, varkha wrote:
> > > On 2017/01/18 23:02:51, ajuma wrote:
> > > > Looking at how this can get called, it seems possible this gets called
> when
> > > > we're ending the animation early because of it being pre-empted. If
that's
> > > > possible then the duration wouldn't be the right one to use.
> > > 
> > > Is something like that too naive? Looking at the ways ProgressToEnd gets
> > called
> > > it is not easy to distinguish and as long as we only use this timing for
> > metrics
> > > it should not change statistics significantly (and should not affect
> anything
> > > else).
> > 
> > My only worry is that the statistics might be misleading (that is, we'll
think
> > frame rate is poor when it's not; or something that increases/decreases how
> > often animations end early will look like a regression/progression in
> > smoothness). 
> > 
> > One thing we could do to filter out animations that ended early is to check
> > whether effective_start_time_ + duration_ >= now (or, alternatively, we
could
> > use now - effective_start_time_ instead of using duration_).
> > 
> > Either way, would it be possible to unit test this?
> 
> > check whether effective_start_time_ + duration_ >= now
> Isn't that exactly what I am doing here?

Currently, this just uses duration_, which might not be the actual duration if
the animation ends early. e.g. Say the duration_ is 2 seconds, but the animation
is pre-empted after 1 second, I think duration_ will still have value 2 when
this code gets reached.

[varkha, 2017-01-20 20:19:20]

On 2017/01/20 18:03:05, ajuma wrote:
>
https://codereview.chromium.org/2631333002/diff/40001/ui/compositor/layer_ani...
> File ui/compositor/layer_animation_element.cc (right):
> 
>
https://codereview.chromium.org/2631333002/diff/40001/ui/compositor/layer_ani...
> ui/compositor/layer_animation_element.cc:554: (60.f *
> duration_.InMillisecondsF()))));
> On 2017/01/20 17:07:58, varkha wrote:
> > On 2017/01/20 14:31:58, ajuma wrote:
> > > On 2017/01/20 00:16:47, varkha wrote:
> > > > On 2017/01/18 23:02:51, ajuma wrote:
> > > > > Looking at how this can get called, it seems possible this gets called
> > when
> > > > > we're ending the animation early because of it being pre-empted. If
> that's
> > > > > possible then the duration wouldn't be the right one to use.
> > > > 
> > > > Is something like that too naive? Looking at the ways ProgressToEnd gets
> > > called
> > > > it is not easy to distinguish and as long as we only use this timing for
> > > metrics
> > > > it should not change statistics significantly (and should not affect
> > anything
> > > > else).
> > > 
> > > My only worry is that the statistics might be misleading (that is, we'll
> think
> > > frame rate is poor when it's not; or something that increases/decreases
how
> > > often animations end early will look like a regression/progression in
> > > smoothness). 
> > > 
> > > One thing we could do to filter out animations that ended early is to
check
> > > whether effective_start_time_ + duration_ >= now (or, alternatively, we
> could
> > > use now - effective_start_time_ instead of using duration_).
> > > 
> > > Either way, would it be possible to unit test this?
> > 
> > > check whether effective_start_time_ + duration_ >= now
> > Isn't that exactly what I am doing here?
> 
> Currently, this just uses duration_, which might not be the actual duration if
> the animation ends early. e.g. Say the duration_ is 2 seconds, but the
animation
> is pre-empted after 1 second, I think duration_ will still have value 2 when
> this code gets reached.

Yes, but I am checking if (now - effective_start_time) is less than expected
duration_
(meaning animation was pre-empted) and not reporting in this case. Am I still
missing it?

[varkha, 2017-01-20 20:22:45]

Also added a unit test to verify that the chain of events works.

[ajuma, 2017-01-20 21:10:51]

On 2017/01/20 20:19:20, varkha wrote:
> On 2017/01/20 18:03:05, ajuma wrote:
> >
>
https://codereview.chromium.org/2631333002/diff/40001/ui/compositor/layer_ani...
> > File ui/compositor/layer_animation_element.cc (right):
> > 
> >
>
https://codereview.chromium.org/2631333002/diff/40001/ui/compositor/layer_ani...
> > ui/compositor/layer_animation_element.cc:554: (60.f *
> > duration_.InMillisecondsF()))));
> > On 2017/01/20 17:07:58, varkha wrote:
> > > On 2017/01/20 14:31:58, ajuma wrote:
> > > > On 2017/01/20 00:16:47, varkha wrote:
> > > > > On 2017/01/18 23:02:51, ajuma wrote:
> > > > > > Looking at how this can get called, it seems possible this gets
called
> > > when
> > > > > > we're ending the animation early because of it being pre-empted. If
> > that's
> > > > > > possible then the duration wouldn't be the right one to use.
> > > > > 
> > > > > Is something like that too naive? Looking at the ways ProgressToEnd
gets
> > > > called
> > > > > it is not easy to distinguish and as long as we only use this timing
for
> > > > metrics
> > > > > it should not change statistics significantly (and should not affect
> > > anything
> > > > > else).
> > > > 
> > > > My only worry is that the statistics might be misleading (that is, we'll
> > think
> > > > frame rate is poor when it's not; or something that increases/decreases
> how
> > > > often animations end early will look like a regression/progression in
> > > > smoothness). 
> > > > 
> > > > One thing we could do to filter out animations that ended early is to
> check
> > > > whether effective_start_time_ + duration_ >= now (or, alternatively, we
> > could
> > > > use now - effective_start_time_ instead of using duration_).
> > > > 
> > > > Either way, would it be possible to unit test this?
> > > 
> > > > check whether effective_start_time_ + duration_ >= now
> > > Isn't that exactly what I am doing here?
> > 
> > Currently, this just uses duration_, which might not be the actual duration
if
> > the animation ends early. e.g. Say the duration_ is 2 seconds, but the
> animation
> > is pre-empted after 1 second, I think duration_ will still have value 2 when
> > this code gets reached.
> 
> Yes, but I am checking if (now - effective_start_time) is less than expected
> duration_
> (meaning animation was pre-empted) and not reporting in this case. Am I still
> missing it?

Oh, sorry, I was looking at the wrong patch set :)   The filtering is correct.

[ajuma, 2017-01-20 21:24:07]

https://codereview.chromium.org/2631333002/diff/80001/ui/compositor/layer_uni...
File ui/compositor/layer_unittest.cc (right):

https://codereview.chromium.org/2631333002/diff/80001/ui/compositor/layer_uni...
ui/compositor/layer_unittest.cc:2272: EXPECT_GT(reporter.value(), 90);
Just to make sure I understand, since the animation duration is 100ms and since
we only report non-100 smoothness when there's at least a one frame difference
in duration vs actual_duration, this is equivalent to saying that smoothness is
100?

I guess the use of TimeTicks::Now() in the computation makes it hard to unit
test other scenarios.

[varkha, 2017-01-20 22:05:24]

https://codereview.chromium.org/2631333002/diff/80001/ui/compositor/layer_uni...
File ui/compositor/layer_unittest.cc (right):

https://codereview.chromium.org/2631333002/diff/80001/ui/compositor/layer_uni...
ui/compositor/layer_unittest.cc:2272: EXPECT_GT(reporter.value(), 90);
On 2017/01/20 21:24:07, ajuma wrote:
> Just to make sure I understand, since the animation duration is 100ms and
since
> we only report non-100 smoothness when there's at least a one frame difference
> in duration vs actual_duration, this is equivalent to saying that smoothness
is
> 100?
> 
> I guess the use of TimeTicks::Now() in the computation makes it hard to unit
> test other scenarios.

Yes, you got me here. I saw a value of 100% and thought at first it was not
guaranteed. I think your logic is correct and I tried to put it in a comment.

[varkha, 2017-01-20 22:21:15]

Patchset #5 (id:100001) has been deleted

[varkha, 2017-01-20 22:21:22]

Patchset #5 (id:120001) has been deleted

[ajuma, 2017-01-20 23:02:06]

Thanks, just one more thing and then this lgtm % sadrul

https://codereview.chromium.org/2631333002/diff/60001/ui/compositor/layer_ani...
File ui/compositor/layer_animator.cc (right):

https://codereview.chromium.org/2631333002/diff/60001/ui/compositor/layer_ani...
ui/compositor/layer_animator.cc:104: StartAnimation(sequence);                  
                        \
On 2017/01/20 17:29:43, sadrul wrote:
> Does this cover all the cases? e.g. what if LayerAnimator::StartTogether() is
> called to trigger some animation?

This is a good point, what about moving this logic into StartAnimation (since
that also gets called for StartTogether)?

[varkha, 2017-01-20 23:24:23]

Patchset #6 (id:160001) has been deleted

[varkha, 2017-01-20 23:26:15]

Patchset #6 (id:180001) has been deleted

[varkha, 2017-01-20 23:34:25]

Patchset #6 (id:200001) has been deleted

[varkha, 2017-01-20 23:34:54]

Patchset #6 (id:220001) has been deleted

[varkha, 2017-01-20 23:35:18]

The CQ bit was checked by varkha@chromium.org to run a CQ dry run

[commit-bot: I haz the power, 2017-01-20 23:35:57]

Dry run: CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[commit-bot: I haz the power, 2017-01-21 00:02:42]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2017-01-21 00:02:43]

Dry run: Try jobs failed on following builders:
  chromeos_amd64-generic_chromium_compile_only_ng on
master.tryserver.chromium.linux (JOB_FAILED,
http://build.chromium.org/p/tryserver.chromium.linux/builders/chromeos_amd64-...)

[varkha, 2017-01-21 00:03:31]

varkha@chromium.org changed reviewers:
+ rkaplow@chromium.org

[varkha, 2017-01-21 00:03:32]

+rkaplow@ for OWNERS in tools/metrics/histograms/

[varkha, 2017-01-21 00:07:35]

The CQ bit was checked by varkha@chromium.org to run a CQ dry run

[commit-bot: I haz the power, 2017-01-21 00:07:58]

Dry run: CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[commit-bot: I haz the power, 2017-01-21 00:38:46]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2017-01-21 00:38:47]

Dry run: Try jobs failed on following builders:
  win_chromium_rel_ng on master.tryserver.chromium.win (JOB_FAILED,
http://build.chromium.org/p/tryserver.chromium.win/builders/win_chromium_rel_...)
  win_chromium_x64_rel_ng on master.tryserver.chromium.win (JOB_FAILED,
http://build.chromium.org/p/tryserver.chromium.win/builders/win_chromium_x64_...)

[varkha, 2017-01-21 02:03:26]

The CQ bit was checked by varkha@chromium.org to run a CQ dry run

[commit-bot: I haz the power, 2017-01-21 02:04:01]

Dry run: CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[commit-bot: I haz the power, 2017-01-21 02:49:16]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2017-01-21 02:49:17]

Dry run: Try jobs failed on following builders:
  win_chromium_rel_ng on master.tryserver.chromium.win (JOB_FAILED,
http://build.chromium.org/p/tryserver.chromium.win/builders/win_chromium_rel_...)

[sadrul, 2017-01-21 03:26:38]

+danakj@ for the remaining ui/compositor change as the sole active compositor
owner.

I would still prefer
LayerAnimator/ScopedLayerAnimationSettings::StartReportingMetric(name) (+ a
corresponding stop), but I would be OK with this too.

[sadrul, 2017-01-21 03:26:56]

btw: please update BUG=TBD to point to a real bug :)

[reveman, 2017-01-21 15:27:39]

https://codereview.chromium.org/2631333002/diff/280001/ui/compositor/composit...
File ui/compositor/compositor.cc (right):

https://codereview.chromium.org/2631333002/diff/280001/ui/compositor/composit...
ui/compositor/compositor.cc:528: ++submitted_frame_number_;
This doesn't mean the frame was displayed. If we submit a bad frame (e.g. one
with lots of overdraw) we might still miss vsync and jank. Should these stats be
hooked up to swap acks instead?

https://codereview.chromium.org/2631333002/diff/280001/ui/compositor/layer_an...
File ui/compositor/layer_animation_element.cc (right):

https://codereview.chromium.org/2631333002/diff/280001/ui/compositor/layer_an...
ui/compositor/layer_animation_element.cc:555: const double kFrameInterval =
1000.f / 60.f;
Should we get the actual vsync interval here instead of assuming 60?

https://codereview.chromium.org/2631333002/diff/280001/ui/compositor/layer_an...
ui/compositor/layer_animation_element.cc:559: smoothness = 100 *
(actual_duration / duration_.InMillisecondsF());
Did you consider just reporting dropped frames instead? I'm not sure this type
of smoothness is a good metric for user experience. E.g. one dropped frame can
ruin the user experience but that will be reported as 99% smoothness.

[rkaplow, 2017-01-23 15:47:18]

https://codereview.chromium.org/2631333002/diff/280001/ui/compositor/animatio...
File ui/compositor/animation_metrics_reporter_template.h (right):

https://codereview.chromium.org/2631333002/diff/280001/ui/compositor/animatio...
ui/compositor/animation_metrics_reporter_template.h:15: void Report(int value)
override { UMA_HISTOGRAM_PERCENTAGE(name, value); }
you can't use the macros this way:
https://codesearch.chromium.org/chromium/src/base/metrics/histogram_macros.h?...

If you really want to set up the recording like this, you need to use what the
macros use, i.e. the base::LinearHistogram::FactoryGet. There's samples of this
use within the codebase

[danakj, 2017-01-23 15:48:53]

danakj@chromium.org changed reviewers:
+ danakj@chromium.org

[danakj, 2017-01-23 15:48:53]

ajuma owns the animation stuff and should probably look at this

[danakj, 2017-01-23 15:49:11]

On 2017/01/23 15:48:53, danakj (slow) wrote:
> ajuma owns the animation stuff and should probably look at this

oh i'm very late to the party haha :)

[danakj, 2017-01-23 15:49:51]

rs LGTM for the unit test

[danakj, 2017-01-23 15:52:05]

https://codereview.chromium.org/2631333002/diff/280001/ui/compositor/composit...
File ui/compositor/compositor.cc (right):

https://codereview.chromium.org/2631333002/diff/280001/ui/compositor/composit...
ui/compositor/compositor.cc:528: ++submitted_frame_number_;
On 2017/01/21 15:27:39, reveman wrote:
> This doesn't mean the frame was displayed. If we submit a bad frame (e.g. one
> with lots of overdraw) we might still miss vsync and jank. Should these stats
be
> hooked up to swap acks instead?

Depends if we wanna measure the production of frames from the UI compositor or
the whole stack beyond it.

[varkha, 2017-01-23 22:55:32]

Description was changed from

==========
[animations] Adds metrics for jank on selected layer animations

This CL is WIP to add UMA metrics for "smoothness" factor on
selected layer animations. The UI developer would be able to
tag selected animations (sequences or elements) with a "name"
and then have UMA data available for how smooth (how close to
ideal 60 fps) the animation is in the field.

BUG=TBD
==========

to

==========
[animations] Adds metrics for jank on selected layer animations

This CL is WIP to add UMA metrics for "smoothness" factor on
selected layer animations. The UI developer would be able to
tag selected animations (sequences or elements) with a "name"
and then have UMA data available for how smooth (how close to
ideal 60 fps) the animation is in the field.

BUG=684115
==========

[varkha, 2017-01-24 00:00:56]

Patchset #9 (id:300001) has been deleted

[varkha, 2017-01-24 00:18:57]

https://codereview.chromium.org/2631333002/diff/280001/ui/compositor/animatio...
File ui/compositor/animation_metrics_reporter_template.h (right):

https://codereview.chromium.org/2631333002/diff/280001/ui/compositor/animatio...
ui/compositor/animation_metrics_reporter_template.h:15: void Report(int value)
override { UMA_HISTOGRAM_PERCENTAGE(name, value); }
On 2017/01/23 15:47:18, rkaplow wrote:
> you can't use the macros this way:
>
https://codesearch.chromium.org/chromium/src/base/metrics/histogram_macros.h?...
> 
> If you really want to set up the recording like this, you need to use what the
> macros use, i.e. the base::LinearHistogram::FactoryGet. There's samples of
this
> use within the codebase

The intention here was exactly to make the strings a compile time static to
ensure that every code path that goes through a particular line ends with just
one histogram instance. Unfortunately only some compilers allow string
parameters in compile time templates so I had to go back to subclassing (similar
to
https://cs.chromium.org/chromium/src/cc/scheduler/compositor_timing_history.c...)

https://codereview.chromium.org/2631333002/diff/280001/ui/compositor/composit...
File ui/compositor/compositor.cc (right):

https://codereview.chromium.org/2631333002/diff/280001/ui/compositor/composit...
ui/compositor/compositor.cc:528: ++submitted_frame_number_;
On 2017/01/23 15:52:05, danakj (slow) wrote:
> On 2017/01/21 15:27:39, reveman wrote:
> > This doesn't mean the frame was displayed. If we submit a bad frame (e.g.
one
> > with lots of overdraw) we might still miss vsync and jank. Should these
stats
> be
> > hooked up to swap acks instead?
> 
> Depends if we wanna measure the production of frames from the UI compositor or
> the whole stack beyond it.

Looking at how WaitForSwap() is implemented I think wiring it to
DidReceiveCompositorFrameAck is the right thing to do if we want to measure what
a user actually sees ("whole stack").

https://codereview.chromium.org/2631333002/diff/280001/ui/compositor/layer_an...
File ui/compositor/layer_animation_element.cc (right):

https://codereview.chromium.org/2631333002/diff/280001/ui/compositor/layer_an...
ui/compositor/layer_animation_element.cc:555: const double kFrameInterval =
1000.f / 60.f;
On 2017/01/21 15:27:39, reveman wrote:
> Should we get the actual vsync interval here instead of assuming 60?

Is there an easy place to get it from in compositor? I can see it seems to be
hardcoded as kDefaultRefreshRate=60.0 in compositor.cc but I am not sure if
there are significant deviations from this in practice.

https://codereview.chromium.org/2631333002/diff/280001/ui/compositor/layer_an...
ui/compositor/layer_animation_element.cc:559: smoothness = 100 *
(actual_duration / duration_.InMillisecondsF());
On 2017/01/21 15:27:39, reveman wrote:
> Did you consider just reporting dropped frames instead? I'm not sure this type
> of smoothness is a good metric for user experience. E.g. one dropped frame can
> ruin the user experience but that will be reported as 99% smoothness.

one dropped frame could indeed ruin user experience but then to still show 99%
here we would need an animation that is 100 frames or 1.6 seconds long and drop
just a single frame - most likely not a concern.

Animation can be still smooth with some frames dropped, I tried to take
animation expected duration into account. I admit in a long animation it
probably matters whether one in every 10 frames is lost (barely noticeable) or
when a whole 10 frames block in a 100 frame sequence is lost (very visible).

[varkha, 2017-01-24 00:40:09]

The CQ bit was checked by varkha@chromium.org to run a CQ dry run

[commit-bot: I haz the power, 2017-01-24 00:41:08]

Dry run: CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[varkha, 2017-01-24 00:54:34]

varkha@chromium.org changed reviewers:
+ bruthig@chromium.org

[varkha, 2017-01-24 00:54:35]

+bruthig@ for ui/views/animation/*ink*.cc OWNERS.

[commit-bot: I haz the power, 2017-01-24 01:58:27]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2017-01-24 01:58:29]

Dry run: This issue passed the CQ dry run.

[bruthig, 2017-01-24 15:56:30]

https://codereview.chromium.org/2631333002/diff/320001/ui/views/animation/flo...
File ui/views/animation/flood_fill_ink_drop_ripple.cc (right):

https://codereview.chromium.org/2631333002/diff/320001/ui/views/animation/flo...
ui/views/animation/flood_fill_ink_drop_ripple.cc:120:
UMA_HISTOGRAM_PERCENTAGE("Views.AnimationSmoothness.FloodFillRipple",
I'm not sure how helpful it will be to get an aggregate of all flood fill
animations across all surfaces.  It would be much much better if they could be
named with the surface that they are on, e.g. AppListFloodFill.  IIUC it should
be possible, you just have to expand the histogram macros manually.

https://codereview.chromium.org/2631333002/diff/320001/ui/views/animation/flo...
ui/views/animation/flood_fill_ink_drop_ripple.cc:124:
base::LazyInstance<FloodRippleMetricsReporter>::Leaky g_reporter =
Do these really need to be global state?  Would any of the following work?

. Make FloodFillInkDropRipple inherit ui::AnimationMetricsReporter
. Use scoped_refptr's instead
. Use normal instances and pass them by copy

FloodRippleMetricsReporter may be a small class but if this is the de facto
standard than I imagine others will be adding a lot of global state to track
animations.  I don't think eating up that RAM is worthy for something that is
only useful for a small portion of the time.

[reveman, 2017-01-24 17:21:45]

https://codereview.chromium.org/2631333002/diff/280001/ui/compositor/layer_an...
File ui/compositor/layer_animation_element.cc (right):

https://codereview.chromium.org/2631333002/diff/280001/ui/compositor/layer_an...
ui/compositor/layer_animation_element.cc:555: const double kFrameInterval =
1000.f / 60.f;
On 2017/01/24 at 00:18:57, varkha wrote:
> On 2017/01/21 15:27:39, reveman wrote:
> > Should we get the actual vsync interval here instead of assuming 60?
> 
> Is there an easy place to get it from in compositor? I can see it seems to be
hardcoded as kDefaultRefreshRate=60.0 in compositor.cc but I am not sure if
there are significant deviations from this in practice.

VSync manager observer interface provides this:
https://cs.chromium.org/chromium/src/ui/compositor/compositor_vsync_manager.h...

We should at least have a TODO and comment here to indicate that this will need
to be updated to produce correct data on devices with lower/higher refresh rate.

[varkha, 2017-01-24 20:18:29]

https://codereview.chromium.org/2631333002/diff/280001/ui/compositor/layer_an...
File ui/compositor/layer_animation_element.cc (right):

https://codereview.chromium.org/2631333002/diff/280001/ui/compositor/layer_an...
ui/compositor/layer_animation_element.cc:555: const double kFrameInterval =
1000.f / 60.f;
On 2017/01/24 17:21:45, reveman wrote:
> On 2017/01/24 at 00:18:57, varkha wrote:
> > On 2017/01/21 15:27:39, reveman wrote:
> > > Should we get the actual vsync interval here instead of assuming 60?
> > 
> > Is there an easy place to get it from in compositor? I can see it seems to
be
> hardcoded as kDefaultRefreshRate=60.0 in compositor.cc but I am not sure if
> there are significant deviations from this in practice.
> 
> VSync manager observer interface provides this:
>
https://cs.chromium.org/chromium/src/ui/compositor/compositor_vsync_manager.h...
> 
> We should at least have a TODO and comment here to indicate that this will
need
> to be updated to produce correct data on devices with lower/higher refresh
rate.

Looks like it is the Compositor that always sets this interval in a
CompositorVSyncManager. Would it be OK to cache it in Compositor and then here
simply to ask Compositor for the up to date value?

[varkha, 2017-01-24 20:23:25]

https://codereview.chromium.org/2631333002/diff/320001/ui/views/animation/flo...
File ui/views/animation/flood_fill_ink_drop_ripple.cc (right):

https://codereview.chromium.org/2631333002/diff/320001/ui/views/animation/flo...
ui/views/animation/flood_fill_ink_drop_ripple.cc:120:
UMA_HISTOGRAM_PERCENTAGE("Views.AnimationSmoothness.FloodFillRipple",
On 2017/01/24 15:56:30, bruthig wrote:
> I'm not sure how helpful it will be to get an aggregate of all flood fill
> animations across all surfaces.  It would be much much better if they could be
> named with the surface that they are on, e.g. AppListFloodFill.  IIUC it
should
> be possible, you just have to expand the histogram macros manually.

I thought of those more as examples to use the new metrics. I agree that
aggregating across all ripples is not the use case I had in mind; it would be
better to have more specific (and more problematic) surfaces: notification tray
ripple, app-list ripple and maybe one example in top chrome (chrome kebob menu
button or bookmarks). I will leave the ripple metrics instantiations out of this
CL.

https://codereview.chromium.org/2631333002/diff/320001/ui/views/animation/flo...
ui/views/animation/flood_fill_ink_drop_ripple.cc:124:
base::LazyInstance<FloodRippleMetricsReporter>::Leaky g_reporter =
On 2017/01/24 15:56:30, bruthig wrote:
> Do these really need to be global state?  Would any of the following work?
> 
> . Make FloodFillInkDropRipple inherit ui::AnimationMetricsReporter
> . Use scoped_refptr's instead
> . Use normal instances and pass them by copy
> 
> FloodRippleMetricsReporter may be a small class but if this is the de facto
> standard than I imagine others will be adding a lot of global state to track
> animations.  I don't think eating up that RAM is worthy for something that is
> only useful for a small portion of the time.

Chatted offline about it. I think so far with a very few actual histograms added
simplicity would win (and avoid some non-trivial instantiation and
reconstitution costs for the histogram objects). I will leave the ripple metrics
out of this CL for now.

[varkha, 2017-01-24 23:55:28]

The CQ bit was checked by varkha@chromium.org to run a CQ dry run

[varkha, 2017-01-24 23:56:20]

https://codereview.chromium.org/2631333002/diff/280001/ui/compositor/layer_an...
File ui/compositor/layer_animation_element.cc (right):

https://codereview.chromium.org/2631333002/diff/280001/ui/compositor/layer_an...
ui/compositor/layer_animation_element.cc:555: const double kFrameInterval =
1000.f / 60.f;
On 2017/01/24 20:18:29, varkha wrote:
> On 2017/01/24 17:21:45, reveman wrote:
> > On 2017/01/24 at 00:18:57, varkha wrote:
> > > On 2017/01/21 15:27:39, reveman wrote:
> > > > Should we get the actual vsync interval here instead of assuming 60?
> > > 
> > > Is there an easy place to get it from in compositor? I can see it seems to
> be
> > hardcoded as kDefaultRefreshRate=60.0 in compositor.cc but I am not sure if
> > there are significant deviations from this in practice.
> > 
> > VSync manager observer interface provides this:
> >
>
https://cs.chromium.org/chromium/src/ui/compositor/compositor_vsync_manager.h...
> > 
> > We should at least have a TODO and comment here to indicate that this will
> need
> > to be updated to produce correct data on devices with lower/higher refresh
> rate.
> 
> Looks like it is the Compositor that always sets this interval in a
> CompositorVSyncManager. Would it be OK to cache it in Compositor and then here
> simply to ask Compositor for the up to date value?

Please see if this works.

[commit-bot: I haz the power, 2017-01-24 23:56:24]

Dry run: CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[commit-bot: I haz the power, 2017-01-25 01:45:39]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2017-01-25 01:45:40]

Dry run: This issue passed the CQ dry run.

[rkaplow, 2017-01-25 15:31:13]

lgtm

[varkha, 2017-01-25 19:01:07]

The CQ bit was checked by varkha@chromium.org

[varkha, 2017-01-25 19:01:07]

The patchset sent to the CQ was uploaded after l-g-t-m from ajuma@chromium.org,
danakj@chromium.org
Link to the patchset: https://codereview.chromium.org/2631333002/#ps340001
(title: "Adds UMA reporting for ripples and overview mode (query refresh rate)")

[commit-bot: I haz the power, 2017-01-25 19:01:38]

CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[commit-bot: I haz the power, 2017-01-25 19:09:55]

CQ is committing da patch.

Bot data: {"patchset_id": 340001, "attempt_start_ts": 1485370867259930,
"parent_rev": "54aad911b25fd13622a400c73fc8b3bd0026ebda", "commit_rev":
"62ba671daf03f09c08257fab4559a31259aa09ce"}

[commit-bot: I haz the power, 2017-01-25 19:10:26]

Description was changed from

==========
[animations] Adds metrics for jank on selected layer animations

This CL is WIP to add UMA metrics for "smoothness" factor on
selected layer animations. The UI developer would be able to
tag selected animations (sequences or elements) with a "name"
and then have UMA data available for how smooth (how close to
ideal 60 fps) the animation is in the field.

BUG=684115
==========

to

==========
[animations] Adds metrics for jank on selected layer animations

This CL is WIP to add UMA metrics for "smoothness" factor on
selected layer animations. The UI developer would be able to
tag selected animations (sequences or elements) with a "name"
and then have UMA data available for how smooth (how close to
ideal 60 fps) the animation is in the field.

BUG=684115

Review-Url: https://codereview.chromium.org/2631333002
Cr-Commit-Position: refs/heads/master@{#446075}
Committed:
https://chromium.googlesource.com/chromium/src/+/62ba671daf03f09c08257fab4559...
==========

[commit-bot: I haz the power, 2017-01-25 19:10:28]

Committed patchset #10 (id:340001) as
https://chromium.googlesource.com/chromium/src/+/62ba671daf03f09c08257fab4559...