Merge "Fix animation start jank due to expensive layout operations."
diff --git a/core/java/android/animation/TimeAnimator.java b/core/java/android/animation/TimeAnimator.java
index 1738ade..1ba68df 100644
--- a/core/java/android/animation/TimeAnimator.java
+++ b/core/java/android/animation/TimeAnimator.java
@@ -51,6 +51,7 @@
public void setCurrentPlayTime(long playTime) {
long currentTime = AnimationUtils.currentAnimationTimeMillis();
mStartTime = Math.max(mStartTime, currentTime - playTime);
+ mStartTimeCommitted = true; // do not allow start time to be compensated for jank
animationFrame(currentTime);
}
diff --git a/core/java/android/animation/ValueAnimator.java b/core/java/android/animation/ValueAnimator.java
index 85dc832..2386007 100644
--- a/core/java/android/animation/ValueAnimator.java
+++ b/core/java/android/animation/ValueAnimator.java
@@ -20,6 +20,7 @@
import android.os.Looper;
import android.os.Trace;
import android.util.AndroidRuntimeException;
+import android.util.Log;
import android.view.Choreographer;
import android.view.animation.AccelerateDecelerateInterpolator;
import android.view.animation.AnimationUtils;
@@ -64,6 +65,8 @@
*/
@SuppressWarnings("unchecked")
public class ValueAnimator extends Animator {
+ private static final String TAG = "ValueAnimator";
+ private static final boolean DEBUG = false;
/**
* Internal constants
@@ -85,12 +88,30 @@
* to clone() to make deep copies of them.
*/
- // The first time that the animation's animateFrame() method is called. This time is used to
- // determine elapsed time (and therefore the elapsed fraction) in subsequent calls
- // to animateFrame()
+ /**
+ * The first time that the animation's animateFrame() method is called. This time is used to
+ * determine elapsed time (and therefore the elapsed fraction) in subsequent calls
+ * to animateFrame().
+ *
+ * Whenever mStartTime is set, you must also update mStartTimeCommitted.
+ */
long mStartTime;
/**
+ * When true, the start time has been firmly committed as a chosen reference point in
+ * time by which the progress of the animation will be evaluated. When false, the
+ * start time may be updated when the first animation frame is committed so as
+ * to compensate for jank that may have occurred between when the start time was
+ * initialized and when the frame was actually drawn.
+ *
+ * This flag is generally set to false during the first frame of the animation
+ * when the animation playing state transitions from STOPPED to RUNNING or
+ * resumes after having been paused. This flag is set to true when the start time
+ * is firmly committed and should not be further compensated for jank.
+ */
+ boolean mStartTimeCommitted;
+
+ /**
* Set when setCurrentPlayTime() is called. If negative, animation is not currently seeked
* to a value.
*/
@@ -528,6 +549,7 @@
* value makes it easier to compose statements together that construct and then set the
* duration, as in <code>ValueAnimator.ofInt(0, 10).setDuration(500).start()</code>.
*/
+ @Override
public ValueAnimator setDuration(long duration) {
if (duration < 0) {
throw new IllegalArgumentException("Animators cannot have negative duration: " +
@@ -547,6 +569,7 @@
*
* @return The length of the animation, in milliseconds.
*/
+ @Override
public long getDuration() {
return mUnscaledDuration;
}
@@ -608,6 +631,7 @@
long seekTime = (long) (mDuration * fraction);
long currentTime = AnimationUtils.currentAnimationTimeMillis();
mStartTime = currentTime - seekTime;
+ mStartTimeCommitted = true; // do not allow start time to be compensated for jank
if (mPlayingState != RUNNING) {
mSeekFraction = fraction;
mPlayingState = SEEKED;
@@ -644,7 +668,7 @@
* @hide
*/
@SuppressWarnings("unchecked")
- protected static class AnimationHandler implements Runnable {
+ protected static class AnimationHandler {
// The per-thread list of all active animations
/** @hide */
protected final ArrayList<ValueAnimator> mAnimations = new ArrayList<ValueAnimator>();
@@ -667,6 +691,7 @@
private final Choreographer mChoreographer;
private boolean mAnimationScheduled;
+ private long mLastFrameTime;
private AnimationHandler() {
mChoreographer = Choreographer.getInstance();
@@ -679,7 +704,9 @@
scheduleAnimation();
}
- private void doAnimationFrame(long frameTime) {
+ void doAnimationFrame(long frameTime) {
+ mLastFrameTime = frameTime;
+
// mPendingAnimations holds any animations that have requested to be started
// We're going to clear mPendingAnimations, but starting animation may
// cause more to be added to the pending list (for example, if one animation
@@ -700,6 +727,7 @@
}
}
}
+
// Next, process animations currently sitting on the delayed queue, adding
// them to the active animations if they are ready
int numDelayedAnims = mDelayedAnims.size();
@@ -740,6 +768,9 @@
mEndingAnims.clear();
}
+ // Schedule final commit for the frame.
+ mChoreographer.postCallback(Choreographer.CALLBACK_COMMIT, mCommit, null);
+
// If there are still active or delayed animations, schedule a future call to
// onAnimate to process the next frame of the animations.
if (!mAnimations.isEmpty() || !mDelayedAnims.isEmpty()) {
@@ -747,19 +778,37 @@
}
}
- // Called by the Choreographer.
- @Override
- public void run() {
- mAnimationScheduled = false;
- doAnimationFrame(mChoreographer.getFrameTime());
+ void commitAnimationFrame(long frameTime) {
+ final long adjustment = frameTime - mLastFrameTime;
+ final int numAnims = mAnimations.size();
+ for (int i = 0; i < numAnims; ++i) {
+ mAnimations.get(i).commitAnimationFrame(adjustment);
+ }
}
private void scheduleAnimation() {
if (!mAnimationScheduled) {
- mChoreographer.postCallback(Choreographer.CALLBACK_ANIMATION, this, null);
+ mChoreographer.postCallback(Choreographer.CALLBACK_ANIMATION, mAnimate, null);
mAnimationScheduled = true;
}
}
+
+ // Called by the Choreographer.
+ final Runnable mAnimate = new Runnable() {
+ @Override
+ public void run() {
+ mAnimationScheduled = false;
+ doAnimationFrame(mChoreographer.getFrameTime());
+ }
+ };
+
+ // Called by the Choreographer.
+ final Runnable mCommit = new Runnable() {
+ @Override
+ public void run() {
+ commitAnimationFrame(mChoreographer.getFrameTime());
+ }
+ };
}
/**
@@ -768,6 +817,7 @@
*
* @return the number of milliseconds to delay running the animation
*/
+ @Override
public long getStartDelay() {
return mUnscaledStartDelay;
}
@@ -778,6 +828,7 @@
* @param startDelay The amount of the delay, in milliseconds
*/
+ @Override
public void setStartDelay(long startDelay) {
this.mStartDelay = (long)(startDelay * sDurationScale);
mUnscaledStartDelay = startDelay;
@@ -1148,6 +1199,7 @@
long currentPlayTime = currentTime - mStartTime;
long timeLeft = mDuration - currentPlayTime;
mStartTime = currentTime - timeLeft;
+ mStartTimeCommitted = true; // do not allow start time to be compensated for jank
mReversing = !mReversing;
} else if (mStarted) {
end();
@@ -1254,9 +1306,9 @@
}
long deltaTime = currentTime - mDelayStartTime;
if (deltaTime > mStartDelay) {
- // startDelay ended - start the anim and record the
- // mStartTime appropriately
- mStartTime = currentTime - (deltaTime - mStartDelay);
+ // startDelay ended - start the anim and record the mStartTime appropriately
+ mStartTime = mDelayStartTime + mStartDelay;
+ mStartTimeCommitted = true; // do not allow start time to be compensated for jank
mPlayingState = RUNNING;
return true;
}
@@ -1264,6 +1316,22 @@
}
/**
+ * Applies an adjustment to the animation to compensate for jank between when
+ * the animation first ran and when the frame was drawn.
+ */
+ void commitAnimationFrame(long adjustment) {
+ if (!mStartTimeCommitted) {
+ mStartTimeCommitted = true;
+ if (mPlayingState == RUNNING && adjustment > 0) {
+ mStartTime += adjustment;
+ if (DEBUG) {
+ Log.d(TAG, "Adjusted start time by " + adjustment + " ms: " + toString());
+ }
+ }
+ }
+ }
+
+ /**
* This internal function processes a single animation frame for a given animation. The
* currentTime parameter is the timing pulse sent by the handler, used to calculate the
* elapsed duration, and therefore
@@ -1303,6 +1371,8 @@
mCurrentIteration += (int) fraction;
fraction = fraction % 1f;
mStartTime += mDuration;
+ // Note: We do not need to update the value of mStartTimeCommitted here
+ // since we just added a duration offset.
} else {
done = true;
fraction = Math.min(fraction, 1.0f);
@@ -1334,6 +1404,7 @@
mStartTime = frameTime - seekTime;
mSeekFraction = -1;
}
+ mStartTimeCommitted = false; // allow start time to be compensated for jank
}
if (mPaused) {
if (mPauseTime < 0) {
@@ -1345,6 +1416,7 @@
if (mPauseTime > 0) {
// Offset by the duration that the animation was paused
mStartTime += (frameTime - mPauseTime);
+ mStartTimeCommitted = false; // allow start time to be compensated for jank
}
}
// The frame time might be before the start time during the first frame of
diff --git a/core/java/android/view/Choreographer.java b/core/java/android/view/Choreographer.java
index c8149d9..79a8489 100644
--- a/core/java/android/view/Choreographer.java
+++ b/core/java/android/view/Choreographer.java
@@ -71,7 +71,12 @@
*/
public final class Choreographer {
private static final String TAG = "Choreographer";
- private static final boolean DEBUG = false;
+
+ // Prints debug messages about jank which was detected (low volume).
+ private static final boolean DEBUG_JANK = false;
+
+ // Prints debug messages about every frame and callback registered (high volume).
+ private static final boolean DEBUG_FRAMES = false;
// The default amount of time in ms between animation frames.
// When vsync is not enabled, we want to have some idea of how long we should
@@ -139,6 +144,7 @@
private boolean mCallbacksRunning;
private long mLastFrameTimeNanos;
private long mFrameIntervalNanos;
+ private boolean mDebugPrintNextFrameTimeDelta;
/**
* Contains information about the current frame for jank-tracking,
@@ -166,13 +172,25 @@
public static final int CALLBACK_ANIMATION = 1;
/**
- * Callback type: Traversal callback. Handles layout and draw. Runs last
+ * Callback type: Traversal callback. Handles layout and draw. Runs
* after all other asynchronous messages have been handled.
* @hide
*/
public static final int CALLBACK_TRAVERSAL = 2;
- private static final int CALLBACK_LAST = CALLBACK_TRAVERSAL;
+ /**
+ * Callback type: Commit callback. Handles post-draw operations for the frame.
+ * Runs after traversal completes. The {@link #getFrameTime() frame time} reported
+ * during this callback may be updated to reflect delays that occurred while
+ * traversals were in progress in case heavy layout operations caused some frames
+ * to be skipped. The frame time reported during this callback provides a better
+ * estimate of the start time of the frame in which animations (and other updates
+ * to the view hierarchy state) actually took effect.
+ * @hide
+ */
+ public static final int CALLBACK_COMMIT = 3;
+
+ private static final int CALLBACK_LAST = CALLBACK_COMMIT;
private Choreographer(Looper looper) {
mLooper = looper;
@@ -332,7 +350,7 @@
private void postCallbackDelayedInternal(int callbackType,
Object action, Object token, long delayMillis) {
- if (DEBUG) {
+ if (DEBUG_FRAMES) {
Log.d(TAG, "PostCallback: type=" + callbackType
+ ", action=" + action + ", token=" + token
+ ", delayMillis=" + delayMillis);
@@ -376,7 +394,7 @@
}
private void removeCallbacksInternal(int callbackType, Object action, Object token) {
- if (DEBUG) {
+ if (DEBUG_FRAMES) {
Log.d(TAG, "RemoveCallbacks: type=" + callbackType
+ ", action=" + action + ", token=" + token);
}
@@ -492,7 +510,7 @@
if (!mFrameScheduled) {
mFrameScheduled = true;
if (USE_VSYNC) {
- if (DEBUG) {
+ if (DEBUG_FRAMES) {
Log.d(TAG, "Scheduling next frame on vsync.");
}
@@ -509,7 +527,7 @@
} else {
final long nextFrameTime = Math.max(
mLastFrameTimeNanos / TimeUtils.NANOS_PER_MS + sFrameDelay, now);
- if (DEBUG) {
+ if (DEBUG_FRAMES) {
Log.d(TAG, "Scheduling next frame in " + (nextFrameTime - now) + " ms.");
}
Message msg = mHandler.obtainMessage(MSG_DO_FRAME);
@@ -526,6 +544,12 @@
return; // no work to do
}
+ if (DEBUG_JANK && mDebugPrintNextFrameTimeDelta) {
+ mDebugPrintNextFrameTimeDelta = false;
+ Log.d(TAG, "Frame time delta: "
+ + ((frameTimeNanos - mLastFrameTimeNanos) * 0.000001f) + " ms");
+ }
+
long intendedFrameTimeNanos = frameTimeNanos;
startNanos = System.nanoTime();
final long jitterNanos = startNanos - frameTimeNanos;
@@ -536,7 +560,7 @@
+ "The application may be doing too much work on its main thread.");
}
final long lastFrameOffset = jitterNanos % mFrameIntervalNanos;
- if (DEBUG) {
+ if (DEBUG_JANK) {
Log.d(TAG, "Missed vsync by " + (jitterNanos * 0.000001f) + " ms "
+ "which is more than the frame interval of "
+ (mFrameIntervalNanos * 0.000001f) + " ms! "
@@ -547,7 +571,7 @@
}
if (frameTimeNanos < mLastFrameTimeNanos) {
- if (DEBUG) {
+ if (DEBUG_JANK) {
Log.d(TAG, "Frame time appears to be going backwards. May be due to a "
+ "previously skipped frame. Waiting for next vsync.");
}
@@ -569,7 +593,9 @@
mFrameInfo.markPerformTraversalsStart();
doCallbacks(Choreographer.CALLBACK_TRAVERSAL, frameTimeNanos);
- if (DEBUG) {
+ doCallbacks(Choreographer.CALLBACK_COMMIT, frameTimeNanos);
+
+ if (DEBUG_FRAMES) {
final long endNanos = System.nanoTime();
Log.d(TAG, "Frame " + frame + ": Finished, took "
+ (endNanos - startNanos) * 0.000001f + " ms, latency "
@@ -583,16 +609,43 @@
// We use "now" to determine when callbacks become due because it's possible
// for earlier processing phases in a frame to post callbacks that should run
// in a following phase, such as an input event that causes an animation to start.
- final long now = SystemClock.uptimeMillis();
- callbacks = mCallbackQueues[callbackType].extractDueCallbacksLocked(now);
+ final long now = System.nanoTime();
+ callbacks = mCallbackQueues[callbackType].extractDueCallbacksLocked(
+ now / TimeUtils.NANOS_PER_MS);
if (callbacks == null) {
return;
}
mCallbacksRunning = true;
+
+ // Update the frame time if necessary when committing the frame.
+ // We only update the frame time if we are more than 2 frames late reaching
+ // the commit phase. This ensures that the frame time which is observed by the
+ // callbacks will always increase from one frame to the next and never repeat.
+ // We never want the next frame's starting frame time to end up being less than
+ // or equal to the previous frame's commit frame time. Keep in mind that the
+ // next frame has most likely already been scheduled by now so we play it
+ // safe by ensuring the commit time is always at least one frame behind.
+ if (callbackType == Choreographer.CALLBACK_COMMIT) {
+ final long jitterNanos = now - frameTimeNanos;
+ if (jitterNanos >= 2 * mFrameIntervalNanos) {
+ final long lastFrameOffset = jitterNanos % mFrameIntervalNanos
+ + mFrameIntervalNanos;
+ if (DEBUG_JANK) {
+ Log.d(TAG, "Commit callback delayed by " + (jitterNanos * 0.000001f)
+ + " ms which is more than twice the frame interval of "
+ + (mFrameIntervalNanos * 0.000001f) + " ms! "
+ + "Setting frame time to " + (lastFrameOffset * 0.000001f)
+ + " ms in the past.");
+ mDebugPrintNextFrameTimeDelta = true;
+ }
+ frameTimeNanos = now - lastFrameOffset;
+ mLastFrameTimeNanos = frameTimeNanos;
+ }
+ }
}
try {
for (CallbackRecord c = callbacks; c != null; c = c.next) {
- if (DEBUG) {
+ if (DEBUG_FRAMES) {
Log.d(TAG, "RunCallback: type=" + callbackType
+ ", action=" + c.action + ", token=" + c.token
+ ", latencyMillis=" + (SystemClock.uptimeMillis() - c.dueTime));