[Android] Add animation frame time histogram class.

[Android] Add animation frame time histogram UMA facility.

We didn't have any metric for measuring Android UI animation jankiness
before, and recently it came to our attention that animations are very
janky on some low-end devices. It will be useful to know how the
animations are doing on various user devices.

This class can be used to record animation frame times histogram,
for example:

AnimationFrameTimeHistogram histogram =
        new AnimationFrameTimeHistogram(HISTOGRAM_NAME);
histogram.startRecording();
// An animation to measure
histogram.endRecording();

or

animator.addListener(AnimationFrameTimeHistogram.getAnimatorRecorder(
        HISTOGRAM_NAME);

To my knowledge, the closest thing we have is measuring each task
runtime using TaskStopwatch class, but that doesn't suit for us since
Android animation frame tasks are managed by Android, and even if we
can use, it will require a JNI call for each frame.

BUG=461066
Committed: https://crrev.com/30c682a7b93f8cac1c99c1c61316f7539de86c85
Cr-Commit-Position: refs/heads/master@{#318533}

[Kibeom Kim (inactive), 2015-02-21 06:19:47]

kkimlabs@chromium.org changed reviewers:
+ aurimas@chromium.org, dtrainor@chromium.org, tedchoc@chromium.org

[aurimas (slooooooooow), 2015-02-23 18:03:59]

https://codereview.chromium.org/949613002/diff/110001/chrome/android/java/src...
File chrome/android/java/src/org/chromium/chrome/browser/appmenu/AppMenu.java
(right):

https://codereview.chromium.org/949613002/diff/110001/chrome/android/java/src...
chrome/android/java/src/org/chromium/chrome/browser/appmenu/AppMenu.java:343:
new AnimationFrameTimeHistogram("WrenchMenu.OpeningAnimationFrameTimes");
Android strongly suggests against new object creation during draw/animation.
This would be violating that, right?

https://codereview.chromium.org/949613002/diff/110001/chrome/android/java/src...
chrome/android/java/src/org/chromium/chrome/browser/appmenu/AppMenu.java:347:
mAnimationFrameTimeHistogram.startRecording();
How cheap is this call?

[David Trainor- moved to gerrit, 2015-02-23 18:20:35]

lgtm with nits:

- Re: Aurimas' suggestion: Can we cache the listener?
- Maybe use the Adapter version so you don't need onAnimationRepeat?
- On that note, if we plan on using this in more places it might be good to have
a listener class that takes a histogram name and does all of this
automatically...

https://chromiumcodereview.appspot.com/949613002/diff/110001/chrome/android/j...
File chrome/android/java/src/org/chromium/chrome/browser/appmenu/AppMenu.java
(right):

https://chromiumcodereview.appspot.com/949613002/diff/110001/chrome/android/j...
chrome/android/java/src/org/chromium/chrome/browser/appmenu/AppMenu.java:341:
animation.addListener(new AnimatorListener() {
AnimatorListenerAdapter then don't include onAnimationRepeat?

https://chromiumcodereview.appspot.com/949613002/diff/110001/chrome/android/j...
chrome/android/java/src/org/chromium/chrome/browser/appmenu/AppMenu.java:343:
new AnimationFrameTimeHistogram("WrenchMenu.OpeningAnimationFrameTimes");
On 2015/02/23 18:03:59, aurimas wrote:
> Android strongly suggests against new object creation during draw/animation.
> This would be violating that, right?

You're right, but I think they're more concerned with creating objects in the
draw/animation path that runs every frame.  This will be created at the same
time we create the AnimatorSet() above and roughly at the same time we create
all the other sub-animations, so we'll be doing a lot of allocations here anyway
that we have to do.

That said, I'm all for caching this listener if possible!

[Kibeom Kim (inactive), 2015-02-23 18:27:24]

https://codereview.chromium.org/949613002/diff/110001/chrome/android/java/src...
File chrome/android/java/src/org/chromium/chrome/browser/appmenu/AppMenu.java
(right):

https://codereview.chromium.org/949613002/diff/110001/chrome/android/java/src...
chrome/android/java/src/org/chromium/chrome/browser/appmenu/AppMenu.java:347:
mAnimationFrameTimeHistogram.startRecording();
On 2015/02/23 18:03:59, aurimas wrote:
> How cheap is this call?

I just measured 3 times, release build:

1st run:
onAnimationStart : 0.366245 ms
onAnimationEnd : 0.213642 ms

2nd run:
onAnimationStart : 0.03052 ms
onAnimationEnd : 0.122082 ms

3rd run:
onAnimationStart : 0.03052 ms
onAnimationEnd : 0.091561 ms

Also measured AnimationFrameTimeHistogram#Recorder#doFrame(...) but that's like
0, as expected.

[aurimas (slooooooooow), 2015-02-23 18:59:38]

On 2015/02/23 at 18:27:24, kkimlabs wrote:
>
https://codereview.chromium.org/949613002/diff/110001/chrome/android/java/src...
> File chrome/android/java/src/org/chromium/chrome/browser/appmenu/AppMenu.java
(right):
> 
>
https://codereview.chromium.org/949613002/diff/110001/chrome/android/java/src...
> chrome/android/java/src/org/chromium/chrome/browser/appmenu/AppMenu.java:347:
mAnimationFrameTimeHistogram.startRecording();
> On 2015/02/23 18:03:59, aurimas wrote:
> > How cheap is this call?
> 
> I just measured 3 times, release build:
> 
> 1st run:
> onAnimationStart : 0.366245 ms
> onAnimationEnd : 0.213642 ms
> 
> 2nd run:
> onAnimationStart : 0.03052 ms
> onAnimationEnd : 0.122082 ms
> 
> 3rd run:
> onAnimationStart : 0.03052 ms
> onAnimationEnd : 0.091561 ms
> 
> Also measured AnimationFrameTimeHistogram#Recorder#doFrame(...) but that's
like 0, as expected.

What device did you record this on? First run of 0.5ms is pretty bad as it will
be 1-2% of the full menu animation. We do not want to make it slower than it
already is :/

[Kibeom Kim (inactive), 2015-02-23 19:05:01]

On 2015/02/23 18:59:38, aurimas wrote:
> On 2015/02/23 at 18:27:24, kkimlabs wrote:
> >
>
https://codereview.chromium.org/949613002/diff/110001/chrome/android/java/src...
> > File
chrome/android/java/src/org/chromium/chrome/browser/appmenu/AppMenu.java
> (right):
> > 
> >
>
https://codereview.chromium.org/949613002/diff/110001/chrome/android/java/src...
> >
chrome/android/java/src/org/chromium/chrome/browser/appmenu/AppMenu.java:347:
> mAnimationFrameTimeHistogram.startRecording();
> > On 2015/02/23 18:03:59, aurimas wrote:
> > > How cheap is this call?
> > 
> > I just measured 3 times, release build:
> > 
> > 1st run:
> > onAnimationStart : 0.366245 ms
> > onAnimationEnd : 0.213642 ms
> > 
> > 2nd run:
> > onAnimationStart : 0.03052 ms
> > onAnimationEnd : 0.122082 ms
> > 
> > 3rd run:
> > onAnimationStart : 0.03052 ms
> > onAnimationEnd : 0.091561 ms
> > 
> > Also measured AnimationFrameTimeHistogram#Recorder#doFrame(...) but that's
> like 0, as expected.
> 
> What device did you record this on? First run of 0.5ms is pretty bad as it
will
> be 1-2% of the full menu animation. We do not want to make it slower than it
> already is :/

It was on Nexus 4 lollipop userdbg.

[David Trainor- moved to gerrit, 2015-02-23 19:10:58]

On 2015/02/23 19:05:01, Kibeom Kim wrote:
> On 2015/02/23 18:59:38, aurimas wrote:
> > On 2015/02/23 at 18:27:24, kkimlabs wrote:
> > >
> >
>
https://codereview.chromium.org/949613002/diff/110001/chrome/android/java/src...
> > > File
> chrome/android/java/src/org/chromium/chrome/browser/appmenu/AppMenu.java
> > (right):
> > > 
> > >
> >
>
https://codereview.chromium.org/949613002/diff/110001/chrome/android/java/src...
> > >
> chrome/android/java/src/org/chromium/chrome/browser/appmenu/AppMenu.java:347:
> > mAnimationFrameTimeHistogram.startRecording();
> > > On 2015/02/23 18:03:59, aurimas wrote:
> > > > How cheap is this call?
> > > 
> > > I just measured 3 times, release build:
> > > 
> > > 1st run:
> > > onAnimationStart : 0.366245 ms
> > > onAnimationEnd : 0.213642 ms
> > > 
> > > 2nd run:
> > > onAnimationStart : 0.03052 ms
> > > onAnimationEnd : 0.122082 ms
> > > 
> > > 3rd run:
> > > onAnimationStart : 0.03052 ms
> > > onAnimationEnd : 0.091561 ms
> > > 
> > > Also measured AnimationFrameTimeHistogram#Recorder#doFrame(...) but that's
> > like 0, as expected.
> > 
> > What device did you record this on? First run of 0.5ms is pretty bad as it
> will
> > be 1-2% of the full menu animation. We do not want to make it slower than it
> > already is :/
> 
> It was on Nexus 4 lollipop userdbg.

Just for some context on current enter animation duration:
- The window component of the animation is 200ms.
- The item animation is 350 ms + 80 ms delay for first item and 30 ms after that
for extra items.

[aurimas (slooooooooow), 2015-02-23 19:12:21]

On 2015/02/23 at 19:10:58, dtrainor wrote:
> On 2015/02/23 19:05:01, Kibeom Kim wrote:
> > On 2015/02/23 18:59:38, aurimas wrote:
> > > On 2015/02/23 at 18:27:24, kkimlabs wrote:
> > > >
> > >
> >
https://codereview.chromium.org/949613002/diff/110001/chrome/android/java/src...
> > > > File
> > chrome/android/java/src/org/chromium/chrome/browser/appmenu/AppMenu.java
> > > (right):
> > > > 
> > > >
> > >
> >
https://codereview.chromium.org/949613002/diff/110001/chrome/android/java/src...
> > > >
> >
chrome/android/java/src/org/chromium/chrome/browser/appmenu/AppMenu.java:347:
> > > mAnimationFrameTimeHistogram.startRecording();
> > > > On 2015/02/23 18:03:59, aurimas wrote:
> > > > > How cheap is this call?
> > > > 
> > > > I just measured 3 times, release build:
> > > > 
> > > > 1st run:
> > > > onAnimationStart : 0.366245 ms
> > > > onAnimationEnd : 0.213642 ms
> > > > 
> > > > 2nd run:
> > > > onAnimationStart : 0.03052 ms
> > > > onAnimationEnd : 0.122082 ms
> > > > 
> > > > 3rd run:
> > > > onAnimationStart : 0.03052 ms
> > > > onAnimationEnd : 0.091561 ms
> > > > 
> > > > Also measured AnimationFrameTimeHistogram#Recorder#doFrame(...) but
that's
> > > like 0, as expected.
> > > 
> > > What device did you record this on? First run of 0.5ms is pretty bad as it
> > will
> > > be 1-2% of the full menu animation. We do not want to make it slower than
it
> > > already is :/
> > 
> > It was on Nexus 4 lollipop userdbg.
> 
> Just for some context on current enter animation duration:
> - The window component of the animation is 200ms.
> - The item animation is 350 ms + 80 ms delay for first item and 30 ms after
that for extra items.

Oh. I did not realize it takes that long already. Nevermind then. We are good to
add this then. LGTM

[Kibeom Kim (inactive), 2015-02-23 22:17:29]

ptal.

https://codereview.chromium.org/949613002/diff/110001/chrome/android/java/src...
File chrome/android/java/src/org/chromium/chrome/browser/appmenu/AppMenu.java
(right):

https://codereview.chromium.org/949613002/diff/110001/chrome/android/java/src...
chrome/android/java/src/org/chromium/chrome/browser/appmenu/AppMenu.java:341:
animation.addListener(new AnimatorListener() {
On 2015/02/23 18:20:35, David Trainor wrote:
> AnimatorListenerAdapter then don't include onAnimationRepeat?

Done.

https://codereview.chromium.org/949613002/diff/110001/chrome/android/java/src...
chrome/android/java/src/org/chromium/chrome/browser/appmenu/AppMenu.java:343:
new AnimationFrameTimeHistogram("WrenchMenu.OpeningAnimationFrameTimes");
On 2015/02/23 18:20:35, David Trainor wrote:
> On 2015/02/23 18:03:59, aurimas wrote:
> > Android strongly suggests against new object creation during draw/animation.
> > This would be violating that, right?
> 
> You're right, but I think they're more concerned with creating objects in the
> draw/animation path that runs every frame.  This will be created at the same
> time we create the AnimatorSet() above and roughly at the same time we create
> all the other sub-animations, so we'll be doing a lot of allocations here
anyway
> that we have to do.
> 
> That said, I'm all for caching this listener if possible!

Done.

[Kibeom Kim (inactive), 2015-02-23 23:40:51]

kkimlabs@chromium.org changed reviewers:
+ danakj@chromium.org, isherman@chromium.org, nyquist@chromium.org

[Kibeom Kim (inactive), 2015-02-23 23:40:51]

+OWNERS ptal

nyquist:
  base/android/animation_frame_time_histogram.cc
  base/android/animation_frame_time_histogram.h
  base/android/base_jni_registrar.cc
  base/android/java/src/org/chromium/base/AnimationFrameTimeHistogram.java

danakj:
  base/BUILD.gn
  base/base.gyp
  base/base.gypi
  base/time/time.h
  base/time/time_unittest.cc

isherman:
  tools/metrics/histograms/histograms.xml

[Ilya Sherman, 2015-02-24 05:28:51]

https://codereview.chromium.org/949613002/diff/130001/tools/metrics/histogram...
File tools/metrics/histograms/histograms.xml (right):

https://codereview.chromium.org/949613002/diff/130001/tools/metrics/histogram...
tools/metrics/histograms/histograms.xml:43460: +  <summary>Frame times of
Android wrench menu opening animation.</summary>
This description is not very clear.  Could you please clarify what exactly this
is measuring?  What are the start and end times in this metric?  Are there
multiple different start+end time combinations being measured?

[Kibeom Kim (inactive), 2015-02-24 18:25:54]

https://codereview.chromium.org/949613002/diff/130001/tools/metrics/histogram...
File tools/metrics/histograms/histograms.xml (right):

https://codereview.chromium.org/949613002/diff/130001/tools/metrics/histogram...
tools/metrics/histograms/histograms.xml:43460: +  <summary>Frame times of
Android wrench menu opening animation.</summary>
On 2015/02/24 05:28:51, Ilya Sherman wrote:
> This description is not very clear.  Could you please clarify what exactly
this
> is measuring?  What are the start and end times in this metric?  Are there
> multiple different start+end time combinations being measured?

Done.

[Ilya Sherman, 2015-02-24 18:53:11]

LGTM, thanks.

[nyquist, 2015-02-24 23:26:56]

https://codereview.chromium.org/949613002/diff/150001/base/android/java/src/o...
File base/android/java/src/org/chromium/base/AnimationFrameTimeHistogram.java
(right):

https://codereview.chromium.org/949613002/diff/150001/base/android/java/src/o...
base/android/java/src/org/chromium/base/AnimationFrameTimeHistogram.java:48:
mAnimationFrameTimeHistogram.endRecording();
If this gets called often, would that skew the stats? Or are you assuming that
for those cases the mFrameTimesCount hasn't hit the max for those cases?

https://codereview.chromium.org/949613002/diff/150001/base/android/java/src/o...
base/android/java/src/org/chromium/base/AnimationFrameTimeHistogram.java:57:
public AnimationFrameTimeHistogram(final String histogramName) {
Nit: unneccessary final

https://codereview.chromium.org/949613002/diff/150001/base/android/java/src/o...
base/android/java/src/org/chromium/base/AnimationFrameTimeHistogram.java:83:
private static class Recorder implements FrameCallback {
Is FrameCallback available on API level 14? I thought that was from 16? Same for
Choreographer.

[Kibeom Kim (inactive), 2015-02-25 00:17:47]

https://codereview.chromium.org/949613002/diff/150001/base/android/java/src/o...
File base/android/java/src/org/chromium/base/AnimationFrameTimeHistogram.java
(right):

https://codereview.chromium.org/949613002/diff/150001/base/android/java/src/o...
base/android/java/src/org/chromium/base/AnimationFrameTimeHistogram.java:48:
mAnimationFrameTimeHistogram.endRecording();
On 2015/02/24 23:26:56, nyquist wrote:
> If this gets called often, would that skew the stats? Or are you assuming that
> for those cases the mFrameTimesCount hasn't hit the max for those cases?

If mAnimationFrameTimeHistogram.endRecording() is called multiple times in a
row, then subsequent calls shouldn't do anything. since #102 will return false.
So the code block #72-#77 won't do anything other than mRecorder.cleanUp(),
which has no harm.

https://codereview.chromium.org/949613002/diff/150001/base/android/java/src/o...
base/android/java/src/org/chromium/base/AnimationFrameTimeHistogram.java:57:
public AnimationFrameTimeHistogram(final String histogramName) {
On 2015/02/24 23:26:56, nyquist wrote:
> Nit: unneccessary final

Done.

https://codereview.chromium.org/949613002/diff/150001/base/android/java/src/o...
base/android/java/src/org/chromium/base/AnimationFrameTimeHistogram.java:83:
private static class Recorder implements FrameCallback {
On 2015/02/24 23:26:56, nyquist wrote:
> Is FrameCallback available on API level 14? I thought that was from 16? Same
for
> Choreographer.

(will discuss offline)

[Kibeom Kim (inactive), 2015-02-25 19:17:09]

nyquist@ : ptal, changed to TimeAnimator. It's also API 16 but we decided that
it's ok to use for ICS.

[Kibeom Kim (inactive), 2015-02-25 19:25:20]

On 2015/02/25 19:17:09, Kibeom Kim wrote:
> nyquist@ : ptal, changed to TimeAnimator. It's also API 16 but we decided that
> it's ok to use for ICS.

TimeAnimator bug:  http://crbug.com/323632

[nyquist, 2015-02-27 04:02:19]

The CL description is incredibly short. Care to expand a bit? Maybe answer
questions in it like:
Why is this class needed? What did we do before this class was available? How do
you integrate with the class?

otherwise lgtm

https://codereview.chromium.org/949613002/diff/190001/base/android/animation_...
File base/android/animation_frame_time_histogram.cc (right):

https://codereview.chromium.org/949613002/diff/190001/base/android/animation_...
base/android/animation_frame_time_histogram.cc:21: for (int i = 0; i < j_count;
++i) {
size_t?

https://codereview.chromium.org/949613002/diff/190001/base/android/java/src/o...
File base/android/java/src/org/chromium/base/AnimationFrameTimeHistogram.java
(right):

https://codereview.chromium.org/949613002/diff/190001/base/android/java/src/o...
base/android/java/src/org/chromium/base/AnimationFrameTimeHistogram.java:132:
Log.w(TAG, "Animation frame time recording reached the maximum number. It's
either"
Is this intentionally a warning? I am just afraid that this might swarm the log
for poor-performance devices going forward, when this class is heavily in use.

[Kibeom Kim (inactive), 2015-02-27 19:56:39]

kkimlabs@chromium.org changed reviewers:
+ thakis@chromium.org

[Kibeom Kim (inactive), 2015-02-27 19:56:40]

ptal danakj@ or thakis@ (trivial file adding changes):

base/BUILD.gn
base/base.gyp
base/base.gypi


Excluded AppMenu.java usage from this CL, I'll make it a seperate CL.

https://codereview.chromium.org/949613002/diff/190001/base/android/animation_...
File base/android/animation_frame_time_histogram.cc (right):

https://codereview.chromium.org/949613002/diff/190001/base/android/animation_...
base/android/animation_frame_time_histogram.cc:21: for (int i = 0; i < j_count;
++i) {
On 2015/02/27 04:02:19, nyquist wrote:
> size_t?

Currently j_count is jint type so I'm getting "comparison between signed and
unsigned integer expressions [-Werror=sign-compare]" for using size_t here. Do
you think it's better to change j_count to unsigned also?

https://codereview.chromium.org/949613002/diff/190001/base/android/java/src/o...
File base/android/java/src/org/chromium/base/AnimationFrameTimeHistogram.java
(right):

https://codereview.chromium.org/949613002/diff/190001/base/android/java/src/o...
base/android/java/src/org/chromium/base/AnimationFrameTimeHistogram.java:132:
Log.w(TAG, "Animation frame time recording reached the maximum number. It's
either"
On 2015/02/27 04:02:19, nyquist wrote:
> Is this intentionally a warning? I am just afraid that this might swarm the
log
> for poor-performance devices going forward, when this class is heavily in use.

I think spamming log will be unlikely to happen, since it's only when 1.
Animation recording is started and 2. The animation exceeds 600 frames. If an
animation is janky on a device, it will have less number of frames. So this log
shouldn't be seen in normal circumstances even on a very slow device.

Actually I was more concerned about mistakes, e,g, forgot to call
endRecording(). I think that type of mistakes can remain undetected, so I wanted
to have some form of alert. I thought about recording this in UMA but ended up
just putting a log message. I didn't consider infinite recording or crashing as
options.

[nyquist, 2015-02-27 21:20:28]

lgtm

[Nico, 2015-02-27 21:21:47]

lgtm

[Kibeom Kim (inactive), 2015-02-27 21:26:35]

The CQ bit was checked by kkimlabs@chromium.org

[Kibeom Kim (inactive), 2015-02-27 21:26:36]

The patchset sent to the CQ was uploaded after l-g-t-m from
dtrainor@chromium.org, aurimas@chromium.org, isherman@chromium.org
Link to the patchset: https://codereview.chromium.org/949613002/#ps210001
(title: "ns -> ms renaming, excluded AppMenu")

[commit-bot: I haz the power, 2015-02-27 21:27:17]

CQ is trying da patch. Follow status at
 https://chromium-cq-status.appspot.com/patch-status/949613002/210001

[commit-bot: I haz the power, 2015-02-27 22:37:16]

Committed patchset #12 (id:210001)

[commit-bot: I haz the power, 2015-02-27 22:37:51]

Patchset 12 (id:??) landed as
https://crrev.com/30c682a7b93f8cac1c99c1c61316f7539de86c85
Cr-Commit-Position: refs/heads/master@{#318533}