From ba6adf66d3c44c0aa2fd8a224862ff1901d64300 Mon Sep 17 00:00:00 2001 From: John Reck Date: Thu, 19 Feb 2015 14:36:50 -0800 Subject: Initial attempt at jank-tracking stat collection Is a bit naive, perhaps overly aggressive, but sorta works Change-Id: I01a774e00dbe681439c02557d9728ae43c45ce50 --- core/java/android/view/Choreographer.java | 20 ++++ core/java/android/view/FrameInfo.java | 118 ++++++++++++++++++++++++ core/java/android/view/HardwareRenderer.java | 2 +- core/java/android/view/ThreadedRenderer.java | 77 ++++++++-------- core/java/android/view/ViewRootImpl.java | 16 +++- core/java/android/view/WindowManagerGlobal.java | 4 +- 6 files changed, 192 insertions(+), 45 deletions(-) create mode 100644 core/java/android/view/FrameInfo.java (limited to 'core/java/android/view') diff --git a/core/java/android/view/Choreographer.java b/core/java/android/view/Choreographer.java index f41afcf..c8149d9 100644 --- a/core/java/android/view/Choreographer.java +++ b/core/java/android/view/Choreographer.java @@ -141,6 +141,19 @@ public final class Choreographer { private long mFrameIntervalNanos; /** + * Contains information about the current frame for jank-tracking, + * mainly timings of key events along with a bit of metadata about + * view tree state + * + * TODO: Is there a better home for this? Currently Choreographer + * is the only one with CALLBACK_ANIMATION start time, hence why this + * resides here. + * + * @hide + */ + FrameInfo mFrameInfo = new FrameInfo(); + + /** * Callback type: Input callback. Runs first. * @hide */ @@ -513,6 +526,7 @@ public final class Choreographer { return; // no work to do } + long intendedFrameTimeNanos = frameTimeNanos; startNanos = System.nanoTime(); final long jitterNanos = startNanos - frameTimeNanos; if (jitterNanos >= mFrameIntervalNanos) { @@ -541,12 +555,18 @@ public final class Choreographer { return; } + mFrameInfo.setVsync(intendedFrameTimeNanos, frameTimeNanos); mFrameScheduled = false; mLastFrameTimeNanos = frameTimeNanos; } + mFrameInfo.markInputHandlingStart(); doCallbacks(Choreographer.CALLBACK_INPUT, frameTimeNanos); + + mFrameInfo.markAnimationsStart(); doCallbacks(Choreographer.CALLBACK_ANIMATION, frameTimeNanos); + + mFrameInfo.markPerformTraversalsStart(); doCallbacks(Choreographer.CALLBACK_TRAVERSAL, frameTimeNanos); if (DEBUG) { diff --git a/core/java/android/view/FrameInfo.java b/core/java/android/view/FrameInfo.java new file mode 100644 index 0000000..c79547c --- /dev/null +++ b/core/java/android/view/FrameInfo.java @@ -0,0 +1,118 @@ +/* + * Copyright (C) 2015 The Android Open Source Project + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package android.view; + +import android.annotation.IntDef; + +import java.lang.annotation.Retention; +import java.lang.annotation.RetentionPolicy; + +/** + * Class that contains all the timing information for the current frame. This + * is used in conjunction with the hardware renderer to provide + * continous-monitoring jank events + * + * All times in nanoseconds from CLOCK_MONOTONIC/System.nanoTime() + * + * To minimize overhead from System.nanoTime() calls we infer durations of + * things by knowing the ordering of the events. For example, to know how + * long layout & measure took it's displayListRecordStart - performTraversalsStart. + * + * These constants must be kept in sync with FrameInfo.h in libhwui and are + * used for indexing into AttachInfo's mFrameInfo long[], which is intended + * to be quick to pass down to native via JNI, hence a pre-packed format + * + * @hide + */ +final class FrameInfo { + + long[] mFrameInfo = new long[9]; + + // Various flags set to provide extra metadata about the current frame + private static final int FLAGS = 0; + + // Is this the first-draw following a window layout? + public static final long FLAG_WINDOW_LAYOUT_CHANGED = 1; + + @IntDef(flag = true, value = { + FLAG_WINDOW_LAYOUT_CHANGED }) + @Retention(RetentionPolicy.SOURCE) + public @interface FrameInfoFlags {} + + // The intended vsync time, unadjusted by jitter + private static final int INTENDED_VSYNC = 1; + + // Jitter-adjusted vsync time, this is what was used as input into the + // animation & drawing system + private static final int VSYNC = 2; + + // The time of the oldest input event + private static final int OLDEST_INPUT_EVENT = 3; + + // The time of the newest input event + private static final int NEWEST_INPUT_EVENT = 4; + + // When input event handling started + private static final int HANDLE_INPUT_START = 5; + + // When animation evaluations started + private static final int ANIMATION_START = 6; + + // When ViewRootImpl#performTraversals() started + private static final int PERFORM_TRAVERSALS_START = 7; + + // When View:draw() started + private static final int DRAW_START = 8; + + public void setVsync(long intendedVsync, long usedVsync) { + mFrameInfo[INTENDED_VSYNC] = intendedVsync; + mFrameInfo[VSYNC] = usedVsync; + mFrameInfo[OLDEST_INPUT_EVENT] = Long.MAX_VALUE; + mFrameInfo[NEWEST_INPUT_EVENT] = 0; + mFrameInfo[FLAGS] = 0; + } + + public void updateInputEventTime(long inputEventTime, long inputEventOldestTime) { + if (inputEventOldestTime < mFrameInfo[OLDEST_INPUT_EVENT]) { + mFrameInfo[OLDEST_INPUT_EVENT] = inputEventOldestTime; + } + if (inputEventTime > mFrameInfo[NEWEST_INPUT_EVENT]) { + mFrameInfo[NEWEST_INPUT_EVENT] = inputEventTime; + } + } + + public void markInputHandlingStart() { + mFrameInfo[HANDLE_INPUT_START] = System.nanoTime(); + } + + public void markAnimationsStart() { + mFrameInfo[ANIMATION_START] = System.nanoTime(); + } + + public void markPerformTraversalsStart() { + mFrameInfo[PERFORM_TRAVERSALS_START] = System.nanoTime(); + } + + public void markDrawStart() { + mFrameInfo[DRAW_START] = System.nanoTime(); + } + + public void addFlags(@FrameInfoFlags long flags) { + mFrameInfo[FLAGS] |= flags; + } + +} diff --git a/core/java/android/view/HardwareRenderer.java b/core/java/android/view/HardwareRenderer.java index c5c3f83..aa61885 100644 --- a/core/java/android/view/HardwareRenderer.java +++ b/core/java/android/view/HardwareRenderer.java @@ -278,7 +278,7 @@ public abstract class HardwareRenderer { /** * Outputs extra debugging information in the specified file descriptor. */ - abstract void dumpGfxInfo(PrintWriter pw, FileDescriptor fd); + abstract void dumpGfxInfo(PrintWriter pw, FileDescriptor fd, String[] args); /** * Loads system properties used by the renderer. This method is invoked diff --git a/core/java/android/view/ThreadedRenderer.java b/core/java/android/view/ThreadedRenderer.java index ad4a048..df0838f 100644 --- a/core/java/android/view/ThreadedRenderer.java +++ b/core/java/android/view/ThreadedRenderer.java @@ -16,8 +16,7 @@ package android.view; -import com.android.internal.R; - +import android.annotation.IntDef; import android.content.Context; import android.content.res.Resources; import android.content.res.TypedArray; @@ -27,16 +26,18 @@ import android.graphics.drawable.Drawable; import android.os.IBinder; import android.os.RemoteException; import android.os.ServiceManager; -import android.os.SystemProperties; import android.os.Trace; import android.util.Log; import android.util.LongSparseArray; -import android.util.TimeUtils; import android.view.Surface.OutOfResourcesException; import android.view.View.AttachInfo; +import com.android.internal.R; + import java.io.FileDescriptor; import java.io.PrintWriter; +import java.lang.annotation.Retention; +import java.lang.annotation.RetentionPolicy; import java.util.ArrayList; import java.util.HashSet; @@ -74,6 +75,14 @@ public class ThreadedRenderer extends HardwareRenderer { PROFILE_PROPERTY_VISUALIZE_BARS, }; + private static final int FLAG_DUMP_FRAMESTATS = 1 << 0; + private static final int FLAG_DUMP_RESET = 1 << 1; + + @IntDef(flag = true, value = { + FLAG_DUMP_FRAMESTATS, FLAG_DUMP_RESET }) + @Retention(RetentionPolicy.SOURCE) + public @interface DumpFlags {} + // Size of the rendered content. private int mWidth, mHeight; @@ -93,12 +102,12 @@ public class ThreadedRenderer extends HardwareRenderer { private final float mLightRadius; private final int mAmbientShadowAlpha; private final int mSpotShadowAlpha; + private final float mDensity; private long mNativeProxy; private boolean mInitialized = false; private RenderNode mRootNode; private Choreographer mChoreographer; - private boolean mProfilingEnabled; private boolean mRootNodeNeedsUpdate; ThreadedRenderer(Context context, boolean translucent) { @@ -110,6 +119,7 @@ public class ThreadedRenderer extends HardwareRenderer { (int) (255 * a.getFloat(R.styleable.Lighting_ambientShadowAlpha, 0) + 0.5f); mSpotShadowAlpha = (int) (255 * a.getFloat(R.styleable.Lighting_spotShadowAlpha, 0) + 0.5f); a.recycle(); + mDensity = context.getResources().getDisplayMetrics().density; long rootNodePtr = nCreateRootRenderNode(); mRootNode = RenderNode.adopt(rootNodePtr); @@ -214,7 +224,7 @@ public class ThreadedRenderer extends HardwareRenderer { mRootNode.setLeftTopRightBottom(-mInsetLeft, -mInsetTop, mSurfaceWidth, mSurfaceHeight); nSetup(mNativeProxy, mSurfaceWidth, mSurfaceHeight, lightX, mLightY, mLightZ, mLightRadius, - mAmbientShadowAlpha, mSpotShadowAlpha); + mAmbientShadowAlpha, mSpotShadowAlpha, mDensity); } @Override @@ -233,32 +243,25 @@ public class ThreadedRenderer extends HardwareRenderer { } @Override - void dumpGfxInfo(PrintWriter pw, FileDescriptor fd) { + void dumpGfxInfo(PrintWriter pw, FileDescriptor fd, String[] args) { pw.flush(); - nDumpProfileInfo(mNativeProxy, fd); - } - - private static int search(String[] values, String value) { - for (int i = 0; i < values.length; i++) { - if (values[i].equals(value)) return i; + int flags = 0; + for (int i = 0; i < args.length; i++) { + switch (args[i]) { + case "framestats": + flags |= FLAG_DUMP_FRAMESTATS; + break; + case "reset": + flags |= FLAG_DUMP_RESET; + break; + } } - return -1; - } - - private static boolean checkIfProfilingRequested() { - String profiling = SystemProperties.get(HardwareRenderer.PROFILE_PROPERTY); - int graphType = search(VISUALIZERS, profiling); - return (graphType >= 0) || Boolean.parseBoolean(profiling); + nDumpProfileInfo(mNativeProxy, fd, flags); } @Override boolean loadSystemProperties() { boolean changed = nLoadSystemProperties(mNativeProxy); - boolean wantProfiling = checkIfProfilingRequested(); - if (wantProfiling != mProfilingEnabled) { - mProfilingEnabled = wantProfiling; - changed = true; - } if (changed) { invalidateRoot(); } @@ -307,20 +310,12 @@ public class ThreadedRenderer extends HardwareRenderer { @Override void draw(View view, AttachInfo attachInfo, HardwareDrawCallbacks callbacks) { attachInfo.mIgnoreDirtyState = true; - long frameTimeNanos = mChoreographer.getFrameTimeNanos(); - attachInfo.mDrawingTime = frameTimeNanos / TimeUtils.NANOS_PER_MS; - long recordDuration = 0; - if (mProfilingEnabled) { - recordDuration = System.nanoTime(); - } + final Choreographer choreographer = attachInfo.mViewRootImpl.mChoreographer; + choreographer.mFrameInfo.markDrawStart(); updateRootDisplayList(view, callbacks); - if (mProfilingEnabled) { - recordDuration = System.nanoTime() - recordDuration; - } - attachInfo.mIgnoreDirtyState = false; // register animating rendernodes which started animating prior to renderer @@ -337,8 +332,8 @@ public class ThreadedRenderer extends HardwareRenderer { attachInfo.mPendingAnimatingRenderNodes = null; } - int syncResult = nSyncAndDrawFrame(mNativeProxy, frameTimeNanos, - recordDuration, view.getResources().getDisplayMetrics().density); + final long[] frameInfo = choreographer.mFrameInfo.mFrameInfo; + int syncResult = nSyncAndDrawFrame(mNativeProxy, frameInfo, frameInfo.length); if ((syncResult & SYNC_LOST_SURFACE_REWARD_IF_FOUND) != 0) { setEnabled(false); attachInfo.mViewRootImpl.mSurface.release(); @@ -500,10 +495,9 @@ public class ThreadedRenderer extends HardwareRenderer { private static native boolean nPauseSurface(long nativeProxy, Surface window); private static native void nSetup(long nativeProxy, int width, int height, float lightX, float lightY, float lightZ, float lightRadius, - int ambientShadowAlpha, int spotShadowAlpha); + int ambientShadowAlpha, int spotShadowAlpha, float density); private static native void nSetOpaque(long nativeProxy, boolean opaque); - private static native int nSyncAndDrawFrame(long nativeProxy, - long frameTimeNanos, long recordDuration, float density); + private static native int nSyncAndDrawFrame(long nativeProxy, long[] frameInfo, int size); private static native void nDestroy(long nativeProxy); private static native void nRegisterAnimatingRenderNode(long rootRenderNode, long animatingNode); @@ -523,5 +517,6 @@ public class ThreadedRenderer extends HardwareRenderer { private static native void nStopDrawing(long nativeProxy); private static native void nNotifyFramePending(long nativeProxy); - private static native void nDumpProfileInfo(long nativeProxy, FileDescriptor fd); + private static native void nDumpProfileInfo(long nativeProxy, FileDescriptor fd, + @DumpFlags int dumpFlags); } diff --git a/core/java/android/view/ViewRootImpl.java b/core/java/android/view/ViewRootImpl.java index 24fae8a..87fe216 100644 --- a/core/java/android/view/ViewRootImpl.java +++ b/core/java/android/view/ViewRootImpl.java @@ -56,6 +56,7 @@ import android.util.AndroidRuntimeException; import android.util.DisplayMetrics; import android.util.Log; import android.util.Slog; +import android.util.TimeUtils; import android.util.TypedValue; import android.view.Surface.OutOfResourcesException; import android.view.View.AttachInfo; @@ -1513,6 +1514,7 @@ public final class ViewRootImpl implements ViewParent, // to resume them mDirty.set(0, 0, mWidth, mHeight); } + mChoreographer.mFrameInfo.addFlags(FrameInfo.FLAG_WINDOW_LAYOUT_CHANGED); } final int surfaceGenerationId = mSurface.getGenerationId(); relayoutResult = relayoutWindow(params, viewVisibility, insetsPending); @@ -2516,6 +2518,9 @@ public final class ViewRootImpl implements ViewParent, } } + mAttachInfo.mDrawingTime = + mChoreographer.getFrameTimeNanos() / TimeUtils.NANOS_PER_MS; + if (!dirty.isEmpty() || mIsAnimating || accessibilityFocusDirty) { if (mAttachInfo.mHardwareRenderer != null && mAttachInfo.mHardwareRenderer.isEnabled()) { // If accessibility focus moved, always invalidate the root. @@ -2635,7 +2640,6 @@ public final class ViewRootImpl implements ViewParent, dirty.setEmpty(); mIsAnimating = false; - attachInfo.mDrawingTime = SystemClock.uptimeMillis(); mView.mPrivateFlags |= View.PFLAG_DRAWN; if (DEBUG_DRAW) { @@ -5789,6 +5793,16 @@ public final class ViewRootImpl implements ViewParent, Trace.traceCounter(Trace.TRACE_TAG_INPUT, mPendingInputEventQueueLengthCounterName, mPendingInputEventCount); + long eventTime = q.mEvent.getEventTimeNano(); + long oldestEventTime = eventTime; + if (q.mEvent instanceof MotionEvent) { + MotionEvent me = (MotionEvent)q.mEvent; + if (me.getHistorySize() > 0) { + oldestEventTime = me.getHistoricalEventTimeNano(0); + } + } + mChoreographer.mFrameInfo.updateInputEventTime(eventTime, oldestEventTime); + deliverInputEvent(q); } diff --git a/core/java/android/view/WindowManagerGlobal.java b/core/java/android/view/WindowManagerGlobal.java index 279627a..1cebe3f 100644 --- a/core/java/android/view/WindowManagerGlobal.java +++ b/core/java/android/view/WindowManagerGlobal.java @@ -492,7 +492,7 @@ public final class WindowManagerGlobal { } } - public void dumpGfxInfo(FileDescriptor fd) { + public void dumpGfxInfo(FileDescriptor fd, String[] args) { FileOutputStream fout = new FileOutputStream(fd); PrintWriter pw = new FastPrintWriter(fout); try { @@ -509,7 +509,7 @@ public final class WindowManagerGlobal { HardwareRenderer renderer = root.getView().mAttachInfo.mHardwareRenderer; if (renderer != null) { - renderer.dumpGfxInfo(pw, fd); + renderer.dumpGfxInfo(pw, fd, args); } } -- cgit v1.1