Trace each stage of Choreographer driven frames

bug:21374535

Change-Id: I332dac216defbc4517441e2a9cdffdf71731f1e6

core/java/android/view/Choreographer.java

@@ -22,6 +22,7 @@ import android.os.Looper;
 import android.os.Message;
 import android.os.SystemClock;
 import android.os.SystemProperties;
+import android.os.Trace;
 import android.util.Log;
 import android.util.TimeUtils;
 
@@ -159,6 +160,14 @@ public final class Choreographer {
      */
     FrameInfo mFrameInfo = new FrameInfo();
 
+    /**
+     * Must be kept in sync with CALLBACK_* ints below, used to index into this array.
+     * @hide
+     */
+    private static final String[] CALLBACK_TRACE_TITLES = {
+            "input", "animation", "traversal", "commit"
+    };
+
     /**
      * Callback type: Input callback.  Runs first.
      * @hide
@@ -584,6 +593,9 @@ public final class Choreographer {
             mLastFrameTimeNanos = frameTimeNanos;
         }
 
+        try {
+            Trace.traceBegin(Trace.TRACE_TAG_VIEW, "Choreographer#doFrame");
+
             mFrameInfo.markInputHandlingStart();
             doCallbacks(Choreographer.CALLBACK_INPUT, frameTimeNanos);
 
@@ -594,6 +606,9 @@ public final class Choreographer {
             doCallbacks(Choreographer.CALLBACK_TRAVERSAL, frameTimeNanos);
 
             doCallbacks(Choreographer.CALLBACK_COMMIT, frameTimeNanos);
+        } finally {
+            Trace.traceEnd(Trace.TRACE_TAG_VIEW);
+        }
 
         if (DEBUG_FRAMES) {
             final long endNanos = System.nanoTime();
@@ -627,6 +642,7 @@ public final class Choreographer {
             // safe by ensuring the commit time is always at least one frame behind.
             if (callbackType == Choreographer.CALLBACK_COMMIT) {
                 final long jitterNanos = now - frameTimeNanos;
+                Trace.traceCounter(Trace.TRACE_TAG_VIEW, "jitterNanos", (int) jitterNanos);
                 if (jitterNanos >= 2 * mFrameIntervalNanos) {
                     final long lastFrameOffset = jitterNanos % mFrameIntervalNanos
                             + mFrameIntervalNanos;
@@ -644,6 +660,7 @@ public final class Choreographer {
             }
         }
         try {
+            Trace.traceBegin(Trace.TRACE_TAG_VIEW, CALLBACK_TRACE_TITLES[callbackType]);
             for (CallbackRecord c = callbacks; c != null; c = c.next) {
                 if (DEBUG_FRAMES) {
                     Log.d(TAG, "RunCallback: type=" + callbackType
@@ -661,6 +678,7 @@ public final class Choreographer {
                     callbacks = next;
                 } while (callbacks != null);
             }
+            Trace.traceEnd(Trace.TRACE_TAG_VIEW);
         }
     }
 

core/java/android/view/ViewRootImpl.java

@@ -1105,12 +1105,7 @@ public final class ViewRootImpl implements ViewParent,
                 Debug.startMethodTracing("ViewAncestor");
             }
 
-            Trace.traceBegin(Trace.TRACE_TAG_VIEW, "performTraversals");
-            try {
             performTraversals();
-            } finally {
-                Trace.traceEnd(Trace.TRACE_TAG_VIEW);
-            }
 
             if (mProfile) {
                 Debug.stopMethodTracing();