Merge "Ensure all FrameTracker invocation run on either main or ui thread" into tm-qpr-dev am: 91a0bbdddf

Original change: https://googleplex-android-review.googlesource.com/c/platform/frameworks/base/+/18654746

Change-Id: I2b159823f2952f1de43f11bdbeadfe6971767471
Signed-off-by: Automerger Merge Worker <android-build-automerger-merge-worker@system.gserviceaccount.com>

core/java/com/android/internal/jank/FrameTracker.java

@@ -26,10 +26,12 @@ import static android.view.SurfaceControl.JankData.SURFACE_FLINGER_SCHEDULING;
 
 import static com.android.internal.jank.InteractionJankMonitor.ACTION_SESSION_CANCEL;
 import static com.android.internal.jank.InteractionJankMonitor.ACTION_SESSION_END;
+import static com.android.internal.jank.InteractionJankMonitor.EXECUTOR_TASK_TIMEOUT;
 
 import android.annotation.IntDef;
 import android.annotation.NonNull;
 import android.annotation.Nullable;
+import android.annotation.UiThread;
 import android.graphics.HardwareRendererObserver;
 import android.os.Handler;
 import android.os.Trace;
@@ -85,8 +87,9 @@ public class FrameTracker extends SurfaceControl.OnJankDataListener
     public @interface Reasons {
     }
 
+    @VisibleForTesting
+    public final InteractionJankMonitor mMonitor;
     private final HardwareRendererObserver mObserver;
-    private SurfaceControl mSurfaceControl;
     private final int mTraceThresholdMissedFrames;
     private final int mTraceThresholdFrameTimeMillis;
     private final ThreadedRendererWrapper mRendererWrapper;
@@ -99,17 +102,17 @@ public class FrameTracker extends SurfaceControl.OnJankDataListener
     private final Handler mHandler;
     private final ChoreographerWrapper mChoreographer;
     private final StatsLogWrapper mStatsLog;
-    private final Object mLock = InteractionJankMonitor.getInstance().getLock();
     private final boolean mDeferMonitoring;
+    private final FrameTrackerListener mListener;
 
     @VisibleForTesting
     public final boolean mSurfaceOnly;
 
+    private SurfaceControl mSurfaceControl;
     private long mBeginVsyncId = INVALID_ID;
     private long mEndVsyncId = INVALID_ID;
     private boolean mMetricsFinalized;
     private boolean mCancelled = false;
-    private FrameTrackerListener mListener;
     private boolean mTracingStarted = false;
     private Runnable mWaitForFinishTimedOut;
 
@@ -142,16 +145,52 @@ public class FrameTracker extends SurfaceControl.OnJankDataListener
             this.jankType = jankType;
             this.isFirstFrame = isFirstFrame;
         }
+
+        @Override
+        public String toString() {
+            StringBuilder str = new StringBuilder();
+            switch (jankType) {
+                case JANK_NONE:
+                    str.append("JANK_NONE");
+                    break;
+                case JANK_APP_DEADLINE_MISSED:
+                    str.append("JANK_APP_DEADLINE_MISSED");
+                    break;
+                case JANK_SURFACEFLINGER_DEADLINE_MISSED:
+                    str.append("JANK_SURFACEFLINGER_DEADLINE_MISSED");
+                    break;
+                case JANK_SURFACEFLINGER_GPU_DEADLINE_MISSED:
+                    str.append("JANK_SURFACEFLINGER_GPU_DEADLINE_MISSED");
+                    break;
+                case DISPLAY_HAL:
+                    str.append("DISPLAY_HAL");
+                    break;
+                case PREDICTION_ERROR:
+                    str.append("PREDICTION_ERROR");
+                    break;
+                case SURFACE_FLINGER_SCHEDULING:
+                    str.append("SURFACE_FLINGER_SCHEDULING");
+                    break;
+                default:
+                    str.append("UNKNOWN: ").append(jankType);
+                    break;
+            }
+            str.append(", ").append(frameVsyncId);
+            str.append(", ").append(totalDurationNanos);
+            return str.toString();
+        }
     }
 
-    public FrameTracker(@NonNull Session session, @NonNull Handler handler,
+    public FrameTracker(@NonNull InteractionJankMonitor monitor, @NonNull Session session,
-            @Nullable ThreadedRendererWrapper renderer, @Nullable ViewRootWrapper viewRootWrapper,
+            @NonNull Handler handler, @Nullable ThreadedRendererWrapper renderer,
+            @Nullable ViewRootWrapper viewRootWrapper,
             @NonNull SurfaceControlWrapper surfaceControlWrapper,
             @NonNull ChoreographerWrapper choreographer,
             @Nullable FrameMetricsWrapper metrics,
             @NonNull StatsLogWrapper statsLog,
             int traceThresholdMissedFrames, int traceThresholdFrameTimeMillis,
             @Nullable FrameTrackerListener listener, @NonNull Configuration config) {
+        mMonitor = monitor;
         mSurfaceOnly = config.isSurfaceOnly();
         mSession = session;
         mHandler = handler;
@@ -186,17 +225,15 @@ public class FrameTracker extends SurfaceControl.OnJankDataListener
             mSurfaceChangedCallback = new ViewRootImpl.SurfaceChangedCallback() {
                 @Override
                 public void surfaceCreated(SurfaceControl.Transaction t) {
-                    synchronized (mLock) {
+                    getHandler().runWithScissors(() -> {
                         if (mSurfaceControl == null) {
                             mSurfaceControl = mViewRoot.getSurfaceControl();
                             if (mBeginVsyncId != INVALID_ID) {
-                                mSurfaceControlWrapper.addJankStatsListener(
+                                // Previous begin invocation is not successfully, begin it again.
-                                        FrameTracker.this, mSurfaceControl);
+                                begin();
-                                markEvent("FT#deferMonitoring");
-                                postTraceStartMarker();
-                            }
                             }
                         }
+                    }, EXECUTOR_TASK_TIMEOUT);
                 }
 
                 @Override
@@ -208,8 +245,7 @@ public class FrameTracker extends SurfaceControl.OnJankDataListener
 
                     // Wait a while to give the system a chance for the remaining
                     // frames to arrive, then force finish the session.
-                    mHandler.postDelayed(() -> {
+                    getHandler().postDelayed(() -> {
-                        synchronized (mLock) {
                         if (DEBUG) {
                             Log.d(TAG, "surfaceDestroyed: " + mSession.getName()
                                     + ", finalized=" + mMetricsFinalized
@@ -220,7 +256,6 @@ public class FrameTracker extends SurfaceControl.OnJankDataListener
                             end(REASON_END_SURFACE_DESTROYED);
                             finish();
                         }
-                        }
                     }, 50);
                 }
             };
@@ -230,35 +265,42 @@ public class FrameTracker extends SurfaceControl.OnJankDataListener
         }
     }
 
+    @VisibleForTesting
+    public Handler getHandler() {
+        return mHandler;
+    }
+
     /**
      * Begin a trace session of the CUJ.
      */
+    @UiThread
     public void begin() {
-        synchronized (mLock) {
         final long currentVsync = mChoreographer.getVsyncId();
         // In normal case, we should begin at the next frame,
         // the id of the next frame is not simply increased by 1,
         // but we can exclude the current frame at least.
+        if (mBeginVsyncId == INVALID_ID) {
             mBeginVsyncId = mDeferMonitoring ? currentVsync + 1 : currentVsync;
-            if (DEBUG) {
-                Log.d(TAG, "begin: " + mSession.getName() + ", begin=" + mBeginVsyncId
-                        + ", defer=" + mDeferMonitoring);
         }
         if (mSurfaceControl != null) {
-                if (mDeferMonitoring) {
+            if (DEBUG) {
+                Log.d(TAG, "begin: " + mSession.getName() + ", begin=" + mBeginVsyncId
+                        + ", defer=" + mDeferMonitoring + ", current=" + currentVsync);
+            }
+            if (mDeferMonitoring && currentVsync < mBeginVsyncId) {
                 markEvent("FT#deferMonitoring");
                 // Normal case, we begin the instrument from the very beginning,
                 // will exclude the first frame.
-                    postTraceStartMarker();
+                postTraceStartMarker(this::beginInternal);
             } else {
                 // If we don't begin the instrument from the very beginning,
                 // there is no need to skip the frame where the begin invocation happens.
                 beginInternal();
             }
-                mSurfaceControlWrapper.addJankStatsListener(this, mSurfaceControl);
+        } else {
-            }
+            if (DEBUG) {
-            if (!mSurfaceOnly) {
+                Log.d(TAG, "begin: defer beginning since the surface is not ready for CUJ="
-                mRendererWrapper.addObserver(mObserver);
+                        + mSession.getName());
             }
         }
     }
@@ -267,27 +309,29 @@ public class FrameTracker extends SurfaceControl.OnJankDataListener
      * Start trace section at appropriate time.
      */
     @VisibleForTesting
-    public void postTraceStartMarker() {
+    public void postTraceStartMarker(Runnable action) {
-        mChoreographer.mChoreographer.postCallback(
+        mChoreographer.mChoreographer.postCallback(Choreographer.CALLBACK_INPUT, action, null);
-                Choreographer.CALLBACK_INPUT, this::beginInternal, null);
     }
 
+    @UiThread
     private void beginInternal() {
-        synchronized (mLock) {
         if (mCancelled || mEndVsyncId != INVALID_ID) {
             return;
         }
         mTracingStarted = true;
         markEvent("FT#begin");
         Trace.beginAsyncSection(mSession.getName(), (int) mBeginVsyncId);
+        mSurfaceControlWrapper.addJankStatsListener(this, mSurfaceControl);
+        if (!mSurfaceOnly) {
+            mRendererWrapper.addObserver(mObserver);
         }
     }
 
     /**
      * End the trace session of the CUJ.
      */
+    @UiThread
     public boolean end(@Reasons int reason) {
-        synchronized (mLock) {
         if (mCancelled || mEndVsyncId != INVALID_ID) return false;
         mEndVsyncId = mChoreographer.getVsyncId();
         // Cancel the session if:
@@ -314,24 +358,23 @@ public class FrameTracker extends SurfaceControl.OnJankDataListener
                 Log.e(TAG, "force finish cuj because of time out:" + mSession.getName());
                 finish();
             };
-                mHandler.postDelayed(mWaitForFinishTimedOut, TimeUnit.SECONDS.toMillis(10));
+            getHandler().postDelayed(mWaitForFinishTimedOut, TimeUnit.SECONDS.toMillis(10));
             notifyCujEvent(ACTION_SESSION_END);
             return true;
         }
     }
-    }
 
     /**
      * Cancel the trace session of the CUJ.
      */
+    @UiThread
     public boolean cancel(@Reasons int reason) {
-        synchronized (mLock) {
         final boolean cancelFromEnd =
                 reason == REASON_CANCEL_NOT_BEGUN || reason == REASON_CANCEL_SAME_VSYNC;
         if (mCancelled || (mEndVsyncId != INVALID_ID && !cancelFromEnd)) return false;
         mCancelled = true;
         markEvent("FT#cancel#" + reason);
-            // We don't need to end the trace section if it never begun.
+        // We don't need to end the trace section if it has never begun.
         if (mTracingStarted) {
             Trace.endAsyncSection(mSession.getName(), (int) mBeginVsyncId);
         }
@@ -350,7 +393,6 @@ public class FrameTracker extends SurfaceControl.OnJankDataListener
         notifyCujEvent(ACTION_SESSION_CANCEL);
         return true;
     }
-    }
 
     private void markEvent(String desc) {
         Trace.beginSection(TextUtils.formatSimple("%s#%s", mSession.getName(), desc));
@@ -364,8 +406,8 @@ public class FrameTracker extends SurfaceControl.OnJankDataListener
 
     @Override
     public void onJankDataAvailable(SurfaceControl.JankData[] jankData) {
-        synchronized (mLock) {
+        postCallback(() -> {
-            if (mCancelled) {
+            if (mCancelled || mMetricsFinalized) {
                 return;
             }
 
@@ -384,10 +426,19 @@ public class FrameTracker extends SurfaceControl.OnJankDataListener
                 }
             }
             processJankInfos();
-        }
+        });
     }
 
-    private @Nullable JankInfo findJankInfo(long frameVsyncId) {
+    /**
+     * For easier argument capture.
+     */
+    @VisibleForTesting
+    public void postCallback(Runnable callback) {
+        getHandler().post(callback);
+    }
+
+    @Nullable
+    private JankInfo findJankInfo(long frameVsyncId) {
         return mJankInfos.get((int) frameVsyncId);
     }
 
@@ -400,8 +451,8 @@ public class FrameTracker extends SurfaceControl.OnJankDataListener
 
     @Override
     public void onFrameMetricsAvailable(int dropCountSinceLastInvocation) {
-        synchronized (mLock) {
+        postCallback(() -> {
-            if (mCancelled) {
+            if (mCancelled || mMetricsFinalized) {
                 return;
             }
 
@@ -426,9 +477,10 @@ public class FrameTracker extends SurfaceControl.OnJankDataListener
                         frameVsyncId, totalDurationNanos, isFirstFrame));
             }
             processJankInfos();
-        }
+        });
     }
 
+    @UiThread
     private boolean hasReceivedCallbacksAfterEnd() {
         if (mEndVsyncId == INVALID_ID) {
             return false;
@@ -451,6 +503,7 @@ public class FrameTracker extends SurfaceControl.OnJankDataListener
         return false;
     }
 
+    @UiThread
     private void processJankInfos() {
         if (mMetricsFinalized) {
             return;
@@ -467,9 +520,12 @@ public class FrameTracker extends SurfaceControl.OnJankDataListener
                 : info.hwuiCallbackFired && info.surfaceControlCallbackFired;
     }
 
+    @UiThread
     private void finish() {
-        mHandler.removeCallbacks(mWaitForFinishTimedOut);
+        getHandler().removeCallbacks(mWaitForFinishTimedOut);
         mWaitForFinishTimedOut = null;
+        if (mMetricsFinalized || mCancelled) return;
+        markEvent("FT#finish#" + mJankInfos.size());
         mMetricsFinalized = true;
 
         // The tracing has been ended, remove the observer, see if need to trigger perfetto.
@@ -496,7 +552,7 @@ public class FrameTracker extends SurfaceControl.OnJankDataListener
                 totalFramesCount++;
                 boolean missedFrame = false;
                 if ((info.jankType & JANK_APP_DEADLINE_MISSED) != 0) {
-                    Log.w(TAG, "Missed App frame:" + info.jankType);
+                    Log.w(TAG, "Missed App frame:" + info + ", CUJ=" + mSession.getName());
                     missedAppFramesCount++;
                     missedFrame = true;
                 }
@@ -505,7 +561,7 @@ public class FrameTracker extends SurfaceControl.OnJankDataListener
                         || (info.jankType & JANK_SURFACEFLINGER_GPU_DEADLINE_MISSED) != 0
                         || (info.jankType & SURFACE_FLINGER_SCHEDULING) != 0
                         || (info.jankType & PREDICTION_ERROR) != 0) {
-                    Log.w(TAG, "Missed SF frame:" + info.jankType);
+                    Log.w(TAG, "Missed SF frame:" + info + ", CUJ=" + mSession.getName());
                     missedSfFramesCount++;
                     missedFrame = true;
                 }
@@ -520,13 +576,15 @@ public class FrameTracker extends SurfaceControl.OnJankDataListener
                 // TODO (b/174755489): Early latch currently gets fired way too often, so we have
                 // to ignore it for now.
                 if (!mSurfaceOnly && !info.hwuiCallbackFired) {
-                    Log.w(TAG, "Missing HWUI jank callback for vsyncId: " + info.frameVsyncId);
+                    Log.w(TAG, "Missing HWUI jank callback for vsyncId: " + info.frameVsyncId
+                            + ", CUJ=" + mSession.getName());
                 }
             }
             if (!mSurfaceOnly && info.hwuiCallbackFired) {
                 maxFrameTimeNanos = Math.max(info.totalDurationNanos, maxFrameTimeNanos);
                 if (!info.surfaceControlCallbackFired) {
-                    Log.w(TAG, "Missing SF jank callback for vsyncId: " + info.frameVsyncId);
+                    Log.w(TAG, "Missing SF jank callback for vsyncId: " + info.frameVsyncId
+                            + ", CUJ=" + mSession.getName());
                 }
             }
         }
@@ -586,6 +644,7 @@ public class FrameTracker extends SurfaceControl.OnJankDataListener
      * Remove all the registered listeners, observers and callbacks.
      */
     @VisibleForTesting
+    @UiThread
     public void removeObservers() {
         mSurfaceControlWrapper.removeJankStatsListener(this);
         if (!mSurfaceOnly) {
@@ -601,7 +660,7 @@ public class FrameTracker extends SurfaceControl.OnJankDataListener
      * Trigger the prefetto daemon.
      */
     public void triggerPerfetto() {
-        InteractionJankMonitor.getInstance().trigger(mSession);
+        mMonitor.trigger(mSession);
     }
 
     /**
@@ -666,10 +725,18 @@ public class FrameTracker extends SurfaceControl.OnJankDataListener
             mViewRoot = viewRoot;
         }
 
+        /**
+         * {@link ViewRootImpl#addSurfaceChangedCallback(ViewRootImpl.SurfaceChangedCallback)}
+         * @param callback {@link ViewRootImpl.SurfaceChangedCallback}
+         */
         public void addSurfaceChangedCallback(ViewRootImpl.SurfaceChangedCallback callback) {
             mViewRoot.addSurfaceChangedCallback(callback);
         }
 
+        /**
+         * {@link ViewRootImpl#removeSurfaceChangedCallback(ViewRootImpl.SurfaceChangedCallback)}
+         * @param callback {@link ViewRootImpl.SurfaceChangedCallback}
+         */
         public void removeSurfaceChangedCallback(ViewRootImpl.SurfaceChangedCallback callback) {
             mViewRoot.removeSurfaceChangedCallback(callback);
         }

core/java/com/android/internal/jank/InteractionJankMonitor.java

@@ -86,8 +86,11 @@ import static com.android.internal.util.FrameworkStatsLog.UIINTERACTION_FRAME_IN
 
 import android.annotation.IntDef;
 import android.annotation.NonNull;
+import android.annotation.UiThread;
+import android.annotation.WorkerThread;
 import android.content.Context;
 import android.os.Build;
+import android.os.Handler;
 import android.os.HandlerExecutor;
 import android.os.HandlerThread;
 import android.provider.DeviceConfig;
@@ -98,6 +101,7 @@ import android.view.Choreographer;
 import android.view.SurfaceControl;
 import android.view.View;
 
+import com.android.internal.annotations.GuardedBy;
 import com.android.internal.annotations.VisibleForTesting;
 import com.android.internal.jank.FrameTracker.ChoreographerWrapper;
 import com.android.internal.jank.FrameTracker.FrameMetricsWrapper;
@@ -131,6 +135,7 @@ public class InteractionJankMonitor {
 
     private static final String DEFAULT_WORKER_NAME = TAG + "-Worker";
     private static final long DEFAULT_TIMEOUT_MS = TimeUnit.SECONDS.toMillis(2L);
+    static final long EXECUTOR_TASK_TIMEOUT = 500;
     private static final String SETTINGS_ENABLED_KEY = "enabled";
     private static final String SETTINGS_SAMPLING_INTERVAL_KEY = "sampling_interval";
     private static final String SETTINGS_THRESHOLD_MISSED_FRAMES_KEY =
@@ -290,13 +295,14 @@ public class InteractionJankMonitor {
     private final DeviceConfig.OnPropertiesChangedListener mPropertiesChangedListener =
             this::updateProperties;
 
-    private final FrameMetricsWrapper mMetrics;
+    @GuardedBy("mLock")
     private final SparseArray<FrameTracker> mRunningTrackers;
+    @GuardedBy("mLock")
     private final SparseArray<Runnable> mTimeoutActions;
     private final HandlerThread mWorker;
     private final Object mLock = new Object();
 
-    private boolean mEnabled = DEFAULT_ENABLED;
+    private volatile boolean mEnabled = DEFAULT_ENABLED;
     private int mSamplingInterval = DEFAULT_SAMPLING_INTERVAL;
     private int mTraceThresholdMissedFrames = DEFAULT_TRACE_THRESHOLD_MISSED_FRAMES;
     private int mTraceThresholdFrameTimeMillis = DEFAULT_TRACE_THRESHOLD_FRAME_TIME_MILLIS;
@@ -398,9 +404,7 @@ public class InteractionJankMonitor {
         mRunningTrackers = new SparseArray<>();
         mTimeoutActions = new SparseArray<>();
         mWorker = worker;
-        mMetrics = new FrameMetricsWrapper();
         mWorker.start();
-        mEnabled = DEFAULT_ENABLED;
         mSamplingInterval = DEFAULT_SAMPLING_INTERVAL;
 
         // Post initialization to the background in case we're running on the main
@@ -413,10 +417,7 @@ public class InteractionJankMonitor {
                 DeviceConfig.NAMESPACE_INTERACTION_JANK_MONITOR,
                 new HandlerExecutor(mWorker.getThreadHandler()),
                 mPropertiesChangedListener);
-    }
+        mEnabled = DEFAULT_ENABLED;
-
-    Object getLock() {
-        return mLock;
     }
 
     /**
@@ -433,27 +434,27 @@ public class InteractionJankMonitor {
                 view == null ? null : new ThreadedRendererWrapper(view.getThreadedRenderer());
         final ViewRootWrapper viewRoot =
                 view == null ? null : new ViewRootWrapper(view.getViewRootImpl());
-
         final SurfaceControlWrapper surfaceControl = new SurfaceControlWrapper();
         final ChoreographerWrapper choreographer =
                 new ChoreographerWrapper(Choreographer.getInstance());
+        final FrameTrackerListener eventsListener = (s, act) -> handleCujEvents(act, s);
+        final FrameMetricsWrapper frameMetrics = new FrameMetricsWrapper();
 
-        synchronized (mLock) {
+        return new FrameTracker(this, session, config.getHandler(), threadedRenderer, viewRoot,
-            FrameTrackerListener eventsListener = (s, act) -> handleCujEvents(act, s);
+                surfaceControl, choreographer, frameMetrics, new FrameTracker.StatsLogWrapper(),
-            return new FrameTracker(session, mWorker.getThreadHandler(),
-                    threadedRenderer, viewRoot, surfaceControl, choreographer,
-                    mMetrics, new FrameTracker.StatsLogWrapper(),
                 mTraceThresholdMissedFrames, mTraceThresholdFrameTimeMillis,
                 eventsListener, config);
     }
-    }
 
+    @UiThread
     private void handleCujEvents(String action, Session session) {
         // Clear the running and timeout tasks if the end / cancel was fired within the tracker.
         // Or we might have memory leaks.
         if (needRemoveTasks(action, session)) {
+            getTracker(session.getCuj()).getHandler().runWithScissors(() -> {
                 removeTimeout(session.getCuj());
                 removeTracker(session.getCuj());
+            }, EXECUTOR_TASK_TIMEOUT);
         }
     }
 
@@ -470,7 +471,7 @@ public class InteractionJankMonitor {
         synchronized (mLock) {
             Runnable timeout = mTimeoutActions.get(cujType);
             if (timeout != null) {
-                mWorker.getThreadHandler().removeCallbacks(timeout);
+                getTracker(cujType).getHandler().removeCallbacks(timeout);
                 mTimeoutActions.remove(cujType);
             }
         }
@@ -495,9 +496,7 @@ public class InteractionJankMonitor {
      */
     public boolean begin(View v, @CujType int cujType) {
         try {
-            return beginInternal(
+            return begin(Configuration.Builder.withView(cujType, v));
-                    Configuration.Builder.withView(cujType, v)
-                            .build());
         } catch (IllegalArgumentException ex) {
             Log.d(TAG, "Build configuration failed!", ex);
             return false;
@@ -508,19 +507,27 @@ public class InteractionJankMonitor {
      * Begins a trace session.
      *
      * @param builder the builder of the configurations for instrumenting the CUJ.
-     * @return boolean true if the tracker is started successfully, false otherwise.
+     * @return boolean true if the tracker is begun successfully, false otherwise.
      */
     public boolean begin(@NonNull Configuration.Builder builder) {
         try {
-            return beginInternal(builder.build());
+            final Configuration config = builder.build();
+            final TrackerResult result = new TrackerResult();
+            final boolean success = config.getHandler().runWithScissors(
+                    () -> result.mResult = beginInternal(config), EXECUTOR_TASK_TIMEOUT);
+            if (!success) {
+                Log.d(TAG, "begin failed due to timeout, CUJ=" + getNameOfCuj(config.mCujType));
+                return false;
+            }
+            return result.mResult;
         } catch (IllegalArgumentException ex) {
             Log.d(TAG, "Build configuration failed!", ex);
             return false;
         }
     }
 
+    @UiThread
     private boolean beginInternal(@NonNull Configuration conf) {
-        synchronized (mLock) {
         int cujType = conf.mCujType;
         if (!shouldMonitor(cujType)) return false;
         FrameTracker tracker = getTracker(cujType);
@@ -529,7 +536,7 @@ public class InteractionJankMonitor {
 
         // begin a new trace session.
         tracker = createFrameTracker(conf, new Session(cujType, conf.mTag));
-            mRunningTrackers.put(cujType, tracker);
+        putTracker(cujType, tracker);
         tracker.begin();
 
         // Cancel the trace if we don't get an end() call in specified duration.
@@ -537,7 +544,6 @@ public class InteractionJankMonitor {
                 cujType, conf.mTimeout, () -> cancel(cujType, REASON_CANCEL_TIMEOUT));
         return true;
     }
-    }
 
     /**
      * Check if the monitoring is enabled and if it should be sampled.
@@ -565,8 +571,10 @@ public class InteractionJankMonitor {
      */
     @VisibleForTesting
     public void scheduleTimeoutAction(@CujType int cuj, long timeout, Runnable action) {
+        synchronized (mLock) {
             mTimeoutActions.put(cuj, action);
-        mWorker.getThreadHandler().postDelayed(action, timeout);
+            getTracker(cuj).getHandler().postDelayed(action, timeout);
+        }
     }
 
     /**
@@ -576,11 +584,29 @@ public class InteractionJankMonitor {
      * @return boolean true if the tracker is ended successfully, false otherwise.
      */
     public boolean end(@CujType int cujType) {
-        synchronized (mLock) {
+        FrameTracker tracker = getTracker(cujType);
+        // Skip this call since we haven't started a trace yet.
+        if (tracker == null) return false;
+        try {
+            final TrackerResult result = new TrackerResult();
+            final boolean success = tracker.getHandler().runWithScissors(
+                    () -> result.mResult = endInternal(cujType), EXECUTOR_TASK_TIMEOUT);
+            if (!success) {
+                Log.d(TAG, "end failed due to timeout, CUJ=" + getNameOfCuj(cujType));
+                return false;
+            }
+            return result.mResult;
+        } catch (IllegalArgumentException ex) {
+            Log.d(TAG, "Execute end task failed!", ex);
+            return false;
+        }
+    }
+
+    @UiThread
+    private boolean endInternal(@CujType int cujType) {
         // remove the timeout action first.
         removeTimeout(cujType);
         FrameTracker tracker = getTracker(cujType);
-            // Skip this call since we haven't started a trace yet.
         if (tracker == null) return false;
         // if the end call doesn't return true, another thread is handling end of the cuj.
         if (tracker.end(REASON_END_NORMAL)) {
@@ -588,7 +614,6 @@ public class InteractionJankMonitor {
         }
         return true;
     }
-    }
 
     /**
      * Cancels the trace session.
@@ -606,11 +631,29 @@ public class InteractionJankMonitor {
      */
     @VisibleForTesting
     public boolean cancel(@CujType int cujType, @Reasons int reason) {
-        synchronized (mLock) {
+        FrameTracker tracker = getTracker(cujType);
+        // Skip this call since we haven't started a trace yet.
+        if (tracker == null) return false;
+        try {
+            final TrackerResult result = new TrackerResult();
+            final boolean success = tracker.getHandler().runWithScissors(
+                    () -> result.mResult = cancelInternal(cujType, reason), EXECUTOR_TASK_TIMEOUT);
+            if (!success) {
+                Log.d(TAG, "cancel failed due to timeout, CUJ=" + getNameOfCuj(cujType));
+                return false;
+            }
+            return result.mResult;
+        } catch (IllegalArgumentException ex) {
+            Log.d(TAG, "Execute cancel task failed!", ex);
+            return false;
+        }
+    }
+
+    @UiThread
+    private boolean cancelInternal(@CujType int cujType, @Reasons int reason) {
         // remove the timeout action first.
         removeTimeout(cujType);
         FrameTracker tracker = getTracker(cujType);
-            // Skip this call since we haven't started a trace yet.
         if (tracker == null) return false;
         // if the cancel call doesn't return true, another thread is handling cancel of the cuj.
         if (tracker.cancel(reason)) {
@@ -618,27 +661,36 @@ public class InteractionJankMonitor {
         }
         return true;
     }
+
+    private void putTracker(@CujType int cuj, @NonNull FrameTracker tracker) {
+        synchronized (mLock) {
+            mRunningTrackers.put(cuj, tracker);
+        }
     }
 
     private FrameTracker getTracker(@CujType int cuj) {
+        synchronized (mLock) {
             return mRunningTrackers.get(cuj);
         }
+    }
 
     private void removeTracker(@CujType int cuj) {
+        synchronized (mLock) {
             mRunningTrackers.remove(cuj);
         }
+    }
 
+    @WorkerThread
     private void updateProperties(DeviceConfig.Properties properties) {
-        synchronized (mLock) {
         mSamplingInterval = properties.getInt(SETTINGS_SAMPLING_INTERVAL_KEY,
                 DEFAULT_SAMPLING_INTERVAL);
-            mEnabled = properties.getBoolean(SETTINGS_ENABLED_KEY, DEFAULT_ENABLED);
         mTraceThresholdMissedFrames = properties.getInt(SETTINGS_THRESHOLD_MISSED_FRAMES_KEY,
                 DEFAULT_TRACE_THRESHOLD_MISSED_FRAMES);
         mTraceThresholdFrameTimeMillis = properties.getInt(
                 SETTINGS_THRESHOLD_FRAME_TIME_MILLIS_KEY,
                 DEFAULT_TRACE_THRESHOLD_FRAME_TIME_MILLIS);
-        }
+        // The memory visibility is powered by the volatile field, mEnabled.
+        mEnabled = properties.getBoolean(SETTINGS_ENABLED_KEY, DEFAULT_ENABLED);
     }
 
     @VisibleForTesting
@@ -814,6 +866,10 @@ public class InteractionJankMonitor {
         return "UNKNOWN";
     }
 
+    private static class TrackerResult {
+        private boolean mResult;
+    }
+
     /**
      * Configurations used while instrumenting the CUJ. <br/>
      * <b>It may refer to an attached view, don't use static reference for any purpose.</b>
@@ -827,6 +883,7 @@ public class InteractionJankMonitor {
         private final SurfaceControl mSurfaceControl;
         private final @CujType int mCujType;
         private final boolean mDeferMonitor;
+        private final Handler mHandler;
 
         /**
          * A builder for building Configuration. {@link #setView(View)} is essential
@@ -970,6 +1027,7 @@ public class InteractionJankMonitor {
             mSurfaceControl = surfaceControl;
             mDeferMonitor = deferMonitor;
             validate();
+            mHandler = mSurfaceOnly ? mContext.getMainThreadHandler() : mView.getHandler();
         }
 
         private void validate() {
@@ -1018,20 +1076,25 @@ public class InteractionJankMonitor {
             return mSurfaceControl;
         }
 
-        View getView() {
+        @VisibleForTesting
+        /**
+         * @return a view which is attached to the view tree.
+         */
+        public View getView() {
             return mView;
         }
 
-        Context getContext() {
-            return mContext;
-        }
-
         /**
          * @return true if the monitoring should be deferred to the next frame, false otherwise.
          */
         public boolean shouldDeferMonitor() {
             return mDeferMonitor;
         }
+
+        @VisibleForTesting
+        public Handler getHandler() {
+            return mHandler;
+        }
     }
 
     /**
@@ -1084,7 +1147,8 @@ public class InteractionJankMonitor {
             mReason = reason;
         }
 
-        public @Reasons int getReason() {
+        @Reasons
+        public int getReason() {
             return mReason;
         }
     }

core/tests/coretests/src/com/android/internal/jank/FrameTrackerTest.java

@@ -36,6 +36,7 @@ import static org.mockito.Mockito.doReturn;
 import static org.mockito.Mockito.mock;
 import static org.mockito.Mockito.never;
 import static org.mockito.Mockito.only;
+import static org.mockito.Mockito.spy;
 import static org.mockito.Mockito.verify;
 import static org.mockito.Mockito.when;
 
@@ -83,6 +84,7 @@ public class FrameTrackerTest {
     private StatsLogWrapper mStatsLog;
     private ArgumentCaptor<OnJankDataListener> mListenerCapture;
     private SurfaceControl mSurfaceControl;
+    private ArgumentCaptor<Runnable> mRunnableArgumentCaptor;
 
     @Before
     public void setup() {
@@ -99,6 +101,8 @@ public class FrameTrackerTest {
         mSurfaceControl = new SurfaceControl.Builder().setName("Surface").build();
         mViewRootWrapper = mock(ViewRootWrapper.class);
         when(mViewRootWrapper.getSurfaceControl()).thenReturn(mSurfaceControl);
+        doNothing().when(mViewRootWrapper).addSurfaceChangedCallback(any());
+        doNothing().when(mViewRootWrapper).removeSurfaceChangedCallback(any());
         mSurfaceControlWrapper = mock(SurfaceControlWrapper.class);
 
         mListenerCapture = ArgumentCaptor.forClass(OnJankDataListener.class);
@@ -109,23 +113,29 @@ public class FrameTrackerTest {
 
         mChoreographer = mock(ChoreographerWrapper.class);
         mStatsLog = mock(StatsLogWrapper.class);
+        mRunnableArgumentCaptor = ArgumentCaptor.forClass(Runnable.class);
     }
 
     private FrameTracker spyFrameTracker(int cuj, String postfix, boolean surfaceOnly) {
+        InteractionJankMonitor monitor = mock(InteractionJankMonitor.class);
         Handler handler = mRule.getActivity().getMainThreadHandler();
         Session session = new Session(cuj, postfix);
         Configuration config = mock(Configuration.class);
         when(config.isSurfaceOnly()).thenReturn(surfaceOnly);
         when(config.getSurfaceControl()).thenReturn(mSurfaceControl);
         when(config.shouldDeferMonitor()).thenReturn(true);
+        View view = mRule.getActivity().getWindow().getDecorView();
+        Handler spyHandler = spy(new Handler(handler.getLooper()));
+        when(config.getView()).thenReturn(surfaceOnly ? null : view);
+        when(config.getHandler()).thenReturn(spyHandler);
         FrameTracker frameTracker = Mockito.spy(
-                new FrameTracker(session, handler, mRenderer, mViewRootWrapper,
+                new FrameTracker(monitor, session, spyHandler, mRenderer, mViewRootWrapper,
                         mSurfaceControlWrapper, mChoreographer, mWrapper, mStatsLog,
                         /* traceThresholdMissedFrames= */ 1,
                         /* traceThresholdFrameTimeMillis= */ -1,
                         /* FrameTrackerListener= */ null, config));
         doNothing().when(frameTracker).triggerPerfetto();
-        doNothing().when(frameTracker).postTraceStartMarker();
+        doNothing().when(frameTracker).postTraceStartMarker(mRunnableArgumentCaptor.capture());
         return frameTracker;
     }
 
@@ -140,6 +150,7 @@ public class FrameTrackerTest {
 
         when(mChoreographer.getVsyncId()).thenReturn(100L);
         tracker.begin();
+        mRunnableArgumentCaptor.getValue().run();
         verify(mRenderer, only()).addObserver(any());
 
         // send first frame with a long duration - should not be taken into account
@@ -173,6 +184,7 @@ public class FrameTrackerTest {
 
         when(mChoreographer.getVsyncId()).thenReturn(100L);
         tracker.begin();
+        mRunnableArgumentCaptor.getValue().run();
         verify(mRenderer, only()).addObserver(any());
 
         // send first frame - not janky
@@ -208,6 +220,7 @@ public class FrameTrackerTest {
 
         when(mChoreographer.getVsyncId()).thenReturn(100L);
         tracker.begin();
+        mRunnableArgumentCaptor.getValue().run();
         verify(mRenderer, only()).addObserver(any());
 
         // send first frame - janky
@@ -243,6 +256,7 @@ public class FrameTrackerTest {
 
         when(mChoreographer.getVsyncId()).thenReturn(100L);
         tracker.begin();
+        mRunnableArgumentCaptor.getValue().run();
         verify(mRenderer, only()).addObserver(any());
 
         // send first frame - not janky
@@ -278,6 +292,7 @@ public class FrameTrackerTest {
 
         when(mChoreographer.getVsyncId()).thenReturn(100L);
         tracker.begin();
+        mRunnableArgumentCaptor.getValue().run();
         verify(mRenderer, only()).addObserver(any());
 
         // send first frame - not janky
@@ -319,6 +334,7 @@ public class FrameTrackerTest {
 
         when(mChoreographer.getVsyncId()).thenReturn(100L);
         tracker.begin();
+        mRunnableArgumentCaptor.getValue().run();
         verify(mRenderer, only()).addObserver(any());
 
         // send first frame - not janky
@@ -332,7 +348,7 @@ public class FrameTrackerTest {
         tracker.end(FrameTracker.REASON_END_NORMAL);
 
         // Send incomplete callback for 102L
-        sendSfFrame(102L, JANK_NONE);
+        sendSfFrame(tracker, 102L, JANK_NONE);
 
         // Send janky but complete callbck fo 103L
         sendFrame(tracker, 50, JANK_APP_DEADLINE_MISSED, 103L);
@@ -356,6 +372,7 @@ public class FrameTrackerTest {
 
         when(mChoreographer.getVsyncId()).thenReturn(100L);
         tracker.begin();
+        mRunnableArgumentCaptor.getValue().run();
         verify(mRenderer).addObserver(any());
 
         // First frame - not janky
@@ -380,6 +397,7 @@ public class FrameTrackerTest {
 
         when(mChoreographer.getVsyncId()).thenReturn(100L);
         tracker.begin();
+        mRunnableArgumentCaptor.getValue().run();
         verify(mRenderer, only()).addObserver(any());
 
         // end the trace session
@@ -403,6 +421,7 @@ public class FrameTrackerTest {
 
         when(mChoreographer.getVsyncId()).thenReturn(100L);
         tracker.begin();
+        mRunnableArgumentCaptor.getValue().run();
         verify(mRenderer, only()).addObserver(any());
 
         // end the trace session at the same vsync id, end vsync id will less than the begin one.
@@ -444,6 +463,7 @@ public class FrameTrackerTest {
 
         when(mChoreographer.getVsyncId()).thenReturn(100L);
         tracker.begin();
+        mRunnableArgumentCaptor.getValue().run();
         verify(mSurfaceControlWrapper).addJankStatsListener(any(), any());
 
         // First frame - not janky
@@ -479,6 +499,7 @@ public class FrameTrackerTest {
 
         when(mChoreographer.getVsyncId()).thenReturn(100L);
         tracker.begin();
+        mRunnableArgumentCaptor.getValue().run();
         verify(mSurfaceControlWrapper).addJankStatsListener(any(), any());
 
         // First frame - janky
@@ -514,6 +535,7 @@ public class FrameTrackerTest {
 
         when(mChoreographer.getVsyncId()).thenReturn(100L);
         tracker.begin();
+        mRunnableArgumentCaptor.getValue().run();
         verify(mSurfaceControlWrapper).addJankStatsListener(any(), any());
 
         // First frame - not janky
@@ -548,6 +570,7 @@ public class FrameTrackerTest {
                 CUJ_WALLPAPER_TRANSITION, CUJ_POSTFIX, /* surfaceOnly= */ true);
         when(mChoreographer.getVsyncId()).thenReturn(100L);
         tracker.begin();
+        mRunnableArgumentCaptor.getValue().run();
         verify(mSurfaceControlWrapper).addJankStatsListener(any(), any());
         sendFrame(tracker, JANK_SURFACEFLINGER_DEADLINE_MISSED, 100L);
         sendFrame(tracker, JANK_SURFACEFLINGER_DEADLINE_MISSED, 101L);
@@ -594,7 +617,7 @@ public class FrameTrackerTest {
         if (!tracker.mSurfaceOnly) {
             sendHwuiFrame(tracker, durationMillis, vsyncId, firstWindowFrame);
         }
-        sendSfFrame(vsyncId, jankType);
+        sendSfFrame(tracker, vsyncId, jankType);
     }
 
     private void sendHwuiFrame(FrameTracker tracker, long durationMillis, long vsyncId,
@@ -604,12 +627,18 @@ public class FrameTrackerTest {
                 .getMetric(FrameMetrics.FIRST_DRAW_FRAME);
         doReturn(TimeUnit.MILLISECONDS.toNanos(durationMillis))
                 .when(mWrapper).getMetric(FrameMetrics.TOTAL_DURATION);
+        final ArgumentCaptor<Runnable> captor = ArgumentCaptor.forClass(Runnable.class);
+        doNothing().when(tracker).postCallback(captor.capture());
         tracker.onFrameMetricsAvailable(0);
+        captor.getValue().run();
     }
 
-    private void sendSfFrame(long vsyncId, @JankType int jankType) {
+    private void sendSfFrame(FrameTracker tracker, long vsyncId, @JankType int jankType) {
+        final ArgumentCaptor<Runnable> captor = ArgumentCaptor.forClass(Runnable.class);
+        doNothing().when(tracker).postCallback(captor.capture());
         mListenerCapture.getValue().onJankDataAvailable(new JankData[] {
                 new JankData(vsyncId, jankType)
         });
+        captor.getValue().run();
     }
 }

core/tests/coretests/src/com/android/internal/jank/InteractionJankMonitorTest.java

@@ -93,7 +93,7 @@ public class InteractionJankMonitorTest {
     @Test
     public void testBeginEnd() {
         InteractionJankMonitor monitor = createMockedInteractionJankMonitor();
-        FrameTracker tracker = createMockedFrameTracker(null);
+        FrameTracker tracker = createMockedFrameTracker(monitor, null);
         doReturn(tracker).when(monitor).createFrameTracker(any(), any());
         doNothing().when(tracker).begin();
         doReturn(true).when(tracker).end(anyInt());
@@ -134,7 +134,7 @@ public class InteractionJankMonitorTest {
     public void testBeginTimeout() {
         ArgumentCaptor<Runnable> captor = ArgumentCaptor.forClass(Runnable.class);
         InteractionJankMonitor monitor = createMockedInteractionJankMonitor();
-        FrameTracker tracker = createMockedFrameTracker(null);
+        FrameTracker tracker = createMockedFrameTracker(monitor, null);
         doReturn(tracker).when(monitor).createFrameTracker(any(), any());
         doNothing().when(tracker).begin();
         doReturn(true).when(tracker).cancel(anyInt());
@@ -180,7 +180,8 @@ public class InteractionJankMonitorTest {
         return monitor;
     }
 
-    private FrameTracker createMockedFrameTracker(FrameTracker.FrameTrackerListener listener) {
+    private FrameTracker createMockedFrameTracker(InteractionJankMonitor monitor,
+            FrameTracker.FrameTrackerListener listener) {
         Session session = spy(new Session(CUJ_NOTIFICATION_SHADE_EXPAND_COLLAPSE, CUJ_POSTFIX));
         doReturn(false).when(session).logToStatsd();
 
@@ -190,6 +191,7 @@ public class InteractionJankMonitorTest {
 
         ViewRootWrapper viewRoot = spy(new ViewRootWrapper(mView.getViewRootImpl()));
         doNothing().when(viewRoot).addSurfaceChangedCallback(any());
+        doNothing().when(viewRoot).removeSurfaceChangedCallback(any());
 
         SurfaceControlWrapper surfaceControl = mock(SurfaceControlWrapper.class);
         doNothing().when(surfaceControl).addJankStatsListener(any(), any());
@@ -200,15 +202,18 @@ public class InteractionJankMonitorTest {
 
         Configuration configuration = mock(Configuration.class);
         when(configuration.isSurfaceOnly()).thenReturn(false);
+        when(configuration.getView()).thenReturn(mView);
+        when(configuration.getHandler()).thenReturn(mView.getHandler());
 
-        FrameTracker tracker = spy(new FrameTracker(session, mWorker.getThreadHandler(),
+        FrameTracker tracker = spy(new FrameTracker(monitor, session, mWorker.getThreadHandler(),
                 threadedRenderer, viewRoot, surfaceControl, choreographer,
                 new FrameMetricsWrapper(), new StatsLogWrapper(),
                 /* traceThresholdMissedFrames= */ 1,
                 /* traceThresholdFrameTimeMillis= */ -1, listener, configuration));
 
-        doNothing().when(tracker).postTraceStartMarker();
+        doNothing().when(tracker).postTraceStartMarker(any());
         doNothing().when(tracker).triggerPerfetto();
+        doReturn(configuration.getHandler()).when(tracker).getHandler();
 
         return tracker;
     }