Merge "Infrastructure of Always-on tracing"

4 files changed, 535 insertions, 2 deletions

diff --git a/core/java/android/view/FrameMetrics.java b/core/java/android/view/FrameMetrics.java
index 054dff726ca1..32cc30be8de4 100644
--- a/core/java/android/view/FrameMetrics.java
+++ b/core/java/android/view/FrameMetrics.java
@@ -250,8 +250,11 @@ public final class FrameMetrics {
         Index.INTENDED_VSYNC, Index.FRAME_COMPLETED,
     };
 
+    /**
+     * @hide
+     */
     @UnsupportedAppUsage
-    /* package */ final long[] mTimingData;
+    public final long[] mTimingData;
 
     /**
      * Constructs a FrameMetrics object as a copy.
@@ -270,7 +273,7 @@ public final class FrameMetrics {
     /**
      * @hide
      */
-    FrameMetrics() {
+    public FrameMetrics() {
         mTimingData = new long[Index.FRAME_STATS_COUNT];
     }
 
diff --git a/core/java/com/android/internal/jank/FrameTracker.java b/core/java/com/android/internal/jank/FrameTracker.java
new file mode 100644
index 000000000000..f9a2ecc10dc8
--- /dev/null
+++ b/core/java/com/android/internal/jank/FrameTracker.java
@@ -0,0 +1,234 @@
+/*
+ * Copyright (C) 2020 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 com.android.internal.jank;
+
+import android.annotation.NonNull;
+import android.graphics.HardwareRendererObserver;
+import android.os.Handler;
+import android.os.Trace;
+import android.util.Log;
+import android.view.FrameMetrics;
+import android.view.ThreadedRenderer;
+
+import com.android.internal.annotations.VisibleForTesting;
+import com.android.internal.jank.InteractionJankMonitor.Session;
+
+/**
+ * @hide
+ */
+public class FrameTracker implements HardwareRendererObserver.OnFrameMetricsAvailableListener {
+    private static final String TAG = FrameTracker.class.getSimpleName();
+    private static final boolean DEBUG = false;
+    //TODO (163431584): need also consider other refresh rates.
+    private static final long CRITERIA = 1000000000 / 60;
+    @VisibleForTesting
+    public static final long UNKNOWN_TIMESTAMP = -1;
+
+    @VisibleForTesting
+    public long mBeginTime = UNKNOWN_TIMESTAMP;
+    @VisibleForTesting
+    public long mEndTime = UNKNOWN_TIMESTAMP;
+    public boolean mShouldTriggerTrace;
+    public HardwareRendererObserver mObserver;
+    public ThreadedRendererWrapper mRendererWrapper;
+    public FrameMetricsWrapper mMetricsWrapper;
+
+    private Session mSession;
+
+    public FrameTracker(@NonNull Session session,
+            @NonNull Handler handler, @NonNull ThreadedRenderer renderer) {
+        mSession = session;
+        mRendererWrapper = new ThreadedRendererWrapper(renderer);
+        mMetricsWrapper = new FrameMetricsWrapper();
+        mObserver = new HardwareRendererObserver(this, mMetricsWrapper.getTiming(), handler);
+    }
+
+    /**
+     * This constructor is only for unit tests.
+     * @param session a trace session.
+     * @param renderer a test double for ThreadedRenderer
+     * @param metrics a test double for FrameMetrics
+     */
+    @VisibleForTesting
+    public FrameTracker(@NonNull Session session, Handler handler,
+            @NonNull ThreadedRendererWrapper renderer, @NonNull FrameMetricsWrapper metrics) {
+        mSession = session;
+        mRendererWrapper = renderer;
+        mMetricsWrapper = metrics;
+        mObserver = new HardwareRendererObserver(this, mMetricsWrapper.getTiming(), handler);
+    }
+
+    /**
+     * Begin a trace session of the CUJ.
+     */
+    public void begin() {
+        long timestamp = System.nanoTime();
+        if (DEBUG) {
+            Log.d(TAG, "begin: time(ns)=" + timestamp + ", begin(ns)=" + mBeginTime
+                    + ", end(ns)=" + mEndTime + ", session=" + mSession);
+        }
+        if (mBeginTime != UNKNOWN_TIMESTAMP && mEndTime == UNKNOWN_TIMESTAMP) {
+            // We have an ongoing tracing already, skip subsequent calls.
+            return;
+        }
+        mBeginTime = timestamp;
+        mEndTime = UNKNOWN_TIMESTAMP;
+        Trace.beginAsyncSection(mSession.getName(), (int) mBeginTime);
+        mRendererWrapper.addObserver(mObserver);
+    }
+
+    /**
+     * End the trace session of the CUJ.
+     */
+    public void end() {
+        long timestamp = System.nanoTime();
+        if (DEBUG) {
+            Log.d(TAG, "end: time(ns)=" + timestamp + ", begin(ns)=" + mBeginTime
+                    + ", end(ns)=" + mEndTime + ", session=" + mSession);
+        }
+        if (mBeginTime == UNKNOWN_TIMESTAMP || mEndTime != UNKNOWN_TIMESTAMP) {
+            // We haven't started a trace yet.
+            return;
+        }
+        mEndTime = timestamp;
+        Trace.endAsyncSection(mSession.getName(), (int) mBeginTime);
+    }
+
+    /**
+     * Check if we had a janky frame according to the metrics.
+     * @param metrics frame metrics
+     * @return true if it is a janky frame
+     */
+    @VisibleForTesting
+    public boolean isJankyFrame(FrameMetricsWrapper metrics) {
+        long totalDurationMs = metrics.getMetric(FrameMetrics.TOTAL_DURATION);
+        boolean isFirstFrame = metrics.getMetric(FrameMetrics.FIRST_DRAW_FRAME) == 1;
+        boolean isJanky = !isFirstFrame && totalDurationMs - CRITERIA > 0;
+
+        if (DEBUG) {
+            StringBuilder sb = new StringBuilder();
+            sb.append(isJanky).append(",");
+            sb.append(metrics.getMetric(FrameMetrics.FIRST_DRAW_FRAME)).append(",");
+            sb.append(metrics.getMetric(FrameMetrics.INPUT_HANDLING_DURATION)).append(",");
+            sb.append(metrics.getMetric(FrameMetrics.ANIMATION_DURATION)).append(",");
+            sb.append(metrics.getMetric(FrameMetrics.LAYOUT_MEASURE_DURATION)).append(",");
+            sb.append(metrics.getMetric(FrameMetrics.DRAW_DURATION)).append(",");
+            sb.append(metrics.getMetric(FrameMetrics.SYNC_DURATION)).append(",");
+            sb.append(metrics.getMetric(FrameMetrics.COMMAND_ISSUE_DURATION)).append(",");
+            sb.append(metrics.getMetric(FrameMetrics.SWAP_BUFFERS_DURATION)).append(",");
+            sb.append(totalDurationMs).append(",");
+            sb.append(metrics.getMetric(FrameMetrics.INTENDED_VSYNC_TIMESTAMP)).append(",");
+            sb.append(metrics.getMetric(FrameMetrics.VSYNC_TIMESTAMP)).append(",");
+            Log.v(TAG, "metrics=" + sb.toString());
+        }
+
+        return isJanky;
+    }
+
+    @Override
+    public void onFrameMetricsAvailable(int dropCountSinceLastInvocation) {
+        // Since this callback might come a little bit late after the end() call.
+        // We should keep tracking the begin / end timestamp.
+        // Then compare with vsync timestamp to check if the frame is in the duration of the CUJ.
+
+        if (mBeginTime == UNKNOWN_TIMESTAMP) return; // We haven't started tracing yet.
+        long vsyncTimestamp = mMetricsWrapper.getMetric(FrameMetrics.VSYNC_TIMESTAMP);
+        if (vsyncTimestamp < mBeginTime) return; // The tracing has been started.
+
+        // If the end time has not been set, we are still in the tracing.
+        if (mEndTime != UNKNOWN_TIMESTAMP && vsyncTimestamp > mEndTime) {
+            // The tracing has been ended, remove the observer, see if need to trigger perfetto.
+            mRendererWrapper.removeObserver(mObserver);
+            // Trigger perfetto if necessary.
+            if (mShouldTriggerTrace) {
+                if (DEBUG) {
+                    Log.v(TAG, "Found janky frame, triggering perfetto.");
+                }
+                triggerPerfetto();
+            }
+            return;
+        }
+
+        // The frame is in the duration of the CUJ, check if it catches the deadline.
+        if (isJankyFrame(mMetricsWrapper)) {
+            mShouldTriggerTrace = true;
+        }
+    }
+
+    /**
+     * Trigger the prefetto daemon.
+     */
+    @VisibleForTesting
+    public void triggerPerfetto() {
+        InteractionJankMonitor.trigger();
+    }
+
+    /**
+     * A wrapper class that we can spy FrameMetrics (a final class) in unit tests.
+     */
+    public static class FrameMetricsWrapper {
+        private FrameMetrics mFrameMetrics;
+
+        public FrameMetricsWrapper() {
+            mFrameMetrics = new FrameMetrics();
+        }
+
+        /**
+         * Wrapper method.
+         * @return timing data of the metrics
+         */
+        public long[] getTiming() {
+            return mFrameMetrics.mTimingData;
+        }
+
+        /**
+         * Wrapper method.
+         * @param index specific index of the timing data
+         * @return the timing data of the specified index
+         */
+        public long getMetric(int index) {
+            return mFrameMetrics.getMetric(index);
+        }
+    }
+
+    /**
+     * A wrapper class that we can spy ThreadedRenderer (a final class) in unit tests.
+     */
+    public static class ThreadedRendererWrapper {
+        private ThreadedRenderer mRenderer;
+
+        public ThreadedRendererWrapper(ThreadedRenderer renderer) {
+            mRenderer = renderer;
+        }
+
+        /**
+         * Wrapper method.
+         * @param observer observer
+         */
+        public void addObserver(HardwareRendererObserver observer) {
+            mRenderer.addObserver(observer);
+        }
+
+        /**
+         * Wrapper method.
+         * @param observer observer
+         */
+        public void removeObserver(HardwareRendererObserver observer) {
+            mRenderer.removeObserver(observer);
+        }
+    }
+}
diff --git a/core/java/com/android/internal/jank/InteractionJankMonitor.java b/core/java/com/android/internal/jank/InteractionJankMonitor.java
new file mode 100644
index 000000000000..6bfb178bc102
--- /dev/null
+++ b/core/java/com/android/internal/jank/InteractionJankMonitor.java
@@ -0,0 +1,181 @@
+/*
+ * Copyright (C) 2020 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 com.android.internal.jank;
+
+import android.annotation.IntDef;
+import android.annotation.NonNull;
+import android.os.HandlerThread;
+import android.view.ThreadedRenderer;
+import android.view.View;
+
+import com.android.internal.annotations.VisibleForTesting;
+
+import java.lang.annotation.Retention;
+import java.lang.annotation.RetentionPolicy;
+import java.util.HashMap;
+import java.util.Map;
+
+/**
+ * This class let users to begin and end the always on tracing mechanism.
+ * @hide
+ */
+public class InteractionJankMonitor {
+    private static final String TAG = InteractionJankMonitor.class.getSimpleName();
+    private static final boolean DEBUG = false;
+    private static final Object LOCK = new Object();
+    public static final int CUJ_NOTIFICATION_SHADE_MOTION = 0;
+    public static final int CUJ_NOTIFICATION_SHADE_GESTURE = 1;
+
+    private static ThreadedRenderer sRenderer;
+    private static Map<String, FrameTracker> sRunningTracker;
+    private static HandlerThread sWorker;
+    private static boolean sInitialized;
+
+    /** @hide */
+    @IntDef({
+            CUJ_NOTIFICATION_SHADE_MOTION,
+            CUJ_NOTIFICATION_SHADE_GESTURE
+    })
+    @Retention(RetentionPolicy.SOURCE)
+    public @interface CujType {}
+
+    /**
+     * @param view Any view in the view tree to get context and ThreadedRenderer.
+     */
+    public static void init(@NonNull View view) {
+        init(view, null, null, null);
+    }
+
+    /**
+     * Should be only invoked internally or from unit tests.
+     */
+    @VisibleForTesting
+    public static void init(@NonNull View view, @NonNull ThreadedRenderer renderer,
+            @NonNull Map<String, FrameTracker> map, @NonNull HandlerThread worker) {
+        //TODO (163505250): This should be no-op if not in droid food rom.
+        synchronized (LOCK) {
+            if (!sInitialized) {
+                if (!view.isAttachedToWindow()) {
+                    throw new IllegalStateException("View is not attached!");
+                }
+                sRenderer = renderer == null ? view.getThreadedRenderer() : renderer;
+                sRunningTracker = map == null ? new HashMap<>() : map;
+                sWorker = worker == null ? new HandlerThread("Aot-Worker") : worker;
+                sWorker.start();
+                sInitialized = true;
+            }
+        }
+    }
+
+    /**
+     * Must invoke init() before invoking this method.
+     */
+    public static void begin(@NonNull @CujType int cujType) {
+        begin(cujType, null);
+    }
+
+    /**
+     * Should be only invoked internally or from unit tests.
+     */
+    @VisibleForTesting
+    public static void begin(@NonNull @CujType int cujType, FrameTracker tracker) {
+        //TODO (163505250): This should be no-op if not in droid food rom.
+        //TODO (163510843): Remove synchronized, add @UiThread if only invoked from ui threads.
+        synchronized (LOCK) {
+            checkInitStateLocked();
+            Session session = new Session(cujType);
+            FrameTracker currentTracker = getTracker(session.getName());
+            if (currentTracker != null) return;
+            if (tracker == null) {
+                tracker = new FrameTracker(session, sWorker.getThreadHandler(), sRenderer);
+            }
+            sRunningTracker.put(session.getName(), tracker);
+            tracker.begin();
+        }
+    }
+
+    /**
+     * Must invoke init() before invoking this method.
+     */
+    public static void end(@NonNull @CujType int cujType) {
+        //TODO (163505250): This should be no-op if not in droid food rom.
+        //TODO (163510843): Remove synchronized, add @UiThread if only invoked from ui threads.
+        synchronized (LOCK) {
+            checkInitStateLocked();
+            Session session = new Session(cujType);
+            FrameTracker tracker = getTracker(session.getName());
+            if (tracker != null) {
+                tracker.end();
+                sRunningTracker.remove(session.getName());
+            }
+        }
+    }
+
+    private static void checkInitStateLocked() {
+        if (!sInitialized) {
+            throw new IllegalStateException("InteractionJankMonitor not initialized!");
+        }
+    }
+
+    /**
+     * Should be only invoked from unit tests.
+     */
+    @VisibleForTesting
+    public static void reset() {
+        sInitialized = false;
+        sRenderer = null;
+        sRunningTracker = null;
+        if (sWorker != null) {
+            sWorker.quit();
+            sWorker = null;
+        }
+    }
+
+    private static FrameTracker getTracker(String sessionName) {
+        synchronized (LOCK) {
+            return sRunningTracker.get(sessionName);
+        }
+    }
+
+    /**
+     * Trigger the perfetto daemon to collect and upload data.
+     */
+    public static void trigger() {
+        sWorker.getThreadHandler().post(
+                () -> PerfettoTrigger.trigger(PerfettoTrigger.TRIGGER_TYPE_JANK));
+    }
+
+    /**
+     * A class to represent a session.
+     */
+    public static class Session {
+        private @CujType int mId;
+
+        public Session(@CujType int session) {
+            mId = session;
+        }
+
+        public int getId() {
+            return mId;
+        }
+
+        public String getName() {
+            return "CujType<" + mId + ">";
+        }
+    }
+
+}
diff --git a/core/java/com/android/internal/jank/PerfettoTrigger.java b/core/java/com/android/internal/jank/PerfettoTrigger.java
new file mode 100644
index 000000000000..6c8d3cdcf5ae
--- /dev/null
+++ b/core/java/com/android/internal/jank/PerfettoTrigger.java
@@ -0,0 +1,115 @@
+/*
+ * Copyright (C) 2020 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.
+ */
+
+//TODO (165884885): Make PerfettoTrigger more generic and move it to another package.
+package com.android.internal.jank;
+
+import android.annotation.IntDef;
+import android.annotation.NonNull;
+import android.util.Log;
+
+import java.io.BufferedReader;
+import java.io.IOException;
+import java.io.InputStreamReader;
+import java.lang.annotation.Retention;
+import java.lang.annotation.RetentionPolicy;
+
+/**
+ * A trigger implementation with perfetto backend.
+ * @hide
+ */
+public class PerfettoTrigger {
+    private static final String TAG = PerfettoTrigger.class.getSimpleName();
+    private static final boolean DEBUG = false;
+    private static final String TRIGGER_COMMAND = "/system/bin/trigger_perfetto";
+    private static final String[] TRIGGER_TYPE_NAMES = new String[] { "jank-tracker" };
+    public static final int TRIGGER_TYPE_JANK = 0;
+
+    /** @hide */
+    @IntDef({
+            TRIGGER_TYPE_JANK
+    })
+    @Retention(RetentionPolicy.SOURCE)
+    public @interface TriggerType {}
+
+    /**
+     * @param type the trigger type
+     */
+    public static void trigger(@NonNull @TriggerType int type) {
+        try {
+            Token token = new Token(type, TRIGGER_TYPE_NAMES[type]);
+            ProcessBuilder pb = new ProcessBuilder(TRIGGER_COMMAND, token.getName());
+            if (DEBUG) {
+                StringBuilder sb = new StringBuilder();
+                for (String arg : pb.command()) {
+                    sb.append(arg).append(" ");
+                }
+                Log.d(TAG, "Triggering " + sb.toString());
+            }
+            Process process = pb.start();
+            if (DEBUG) {
+                readConsoleOutput(process);
+            }
+        } catch (IOException | InterruptedException e) {
+            Log.w(TAG, "Failed to trigger " + type, e);
+        }
+    }
+
+    private static void readConsoleOutput(@NonNull Process process)
+            throws IOException, InterruptedException {
+        process.waitFor();
+        try (BufferedReader errReader =
+                     new BufferedReader(new InputStreamReader(process.getErrorStream()))) {
+            StringBuilder errLine = new StringBuilder();
+            String line;
+            while ((line = errReader.readLine()) != null) {
+                errLine.append(line).append("\n");
+            }
+            errLine.append(", code=").append(process.exitValue());
+            Log.d(TAG, "err message=" + errLine.toString());
+        }
+    }
+
+    /**
+     * Token which is used to trigger perfetto.
+     */
+    public static class Token {
+        private int mType;
+        private String mName;
+
+        Token(@TriggerType int type, String name) {
+            mType = type;
+            mName = name;
+        }
+
+        /**
+         * Get trigger type.
+         * @return trigger type, should be @TriggerType
+         */
+        public int getType() {
+            return mType;
+        }
+
+        /**
+         * Get name of this token as the argument while triggering perfetto.
+         * @return name
+         */
+        public String getName() {
+            return mName;
+        }
+    }
+
+}