From 3b462716ceb60e22a0d1563a9e84ff510743d431 Mon Sep 17 00:00:00 2001 From: Marcin Oczeretko Date: Fri, 16 Oct 2020 14:31:44 +0100 Subject: [PATCH] Add configuration options to InteractionJankMonitor Test: UTs + manual Bug: 162927074 Change-Id: I3edf8d2ce3d2b3b7410fa56d46db0833ac23366d --- core/java/android/provider/DeviceConfig.java | 7 + .../android/internal/jank/FrameTracker.java | 37 ++--- .../internal/jank/InteractionJankMonitor.java | 131 +++++++++++------- .../internal/jank/FrameTrackerTest.java | 2 +- .../jank/InteractionJankMonitorTest.java | 27 +++- 5 files changed, 133 insertions(+), 71 deletions(-) diff --git a/core/java/android/provider/DeviceConfig.java b/core/java/android/provider/DeviceConfig.java index 0c4f8de449e65..714bcea9c01f6 100644 --- a/core/java/android/provider/DeviceConfig.java +++ b/core/java/android/provider/DeviceConfig.java @@ -464,6 +464,13 @@ public final class DeviceConfig { */ public static final String NAMESPACE_LATENCY_TRACKER = "latency_tracker"; + /** + * InteractionJankMonitor properties definitions. + * + * @hide + */ + public static final String NAMESPACE_INTERACTION_JANK_MONITOR = "interaction_jank_monitor"; + private static final Object sLock = new Object(); @GuardedBy("sLock") private static ArrayMap> sListeners = diff --git a/core/java/com/android/internal/jank/FrameTracker.java b/core/java/com/android/internal/jank/FrameTracker.java index c0d46f6325001..571ac1bbeac65 100644 --- a/core/java/com/android/internal/jank/FrameTracker.java +++ b/core/java/com/android/internal/jank/FrameTracker.java @@ -37,34 +37,33 @@ public class FrameTracker implements HardwareRendererObserver.OnFrameMetricsAvai //TODO (163431584): need also consider other refresh rates. private static final long JANK_THRESHOLD_NANOS = 1000000000 / 60; private static final long UNKNOWN_TIMESTAMP = -1; + public static final int NANOS_IN_MILLISECOND = 1_000_000; private final HardwareRendererObserver mObserver; + private final int mTraceThresholdMissedFrames; + private final int mTraceThresholdFrameTimeMillis; private final ThreadedRendererWrapper mRendererWrapper; private final FrameMetricsWrapper mMetricsWrapper; private long mBeginTime = UNKNOWN_TIMESTAMP; private long mEndTime = UNKNOWN_TIMESTAMP; - private boolean mShouldTriggerTrace; private boolean mSessionEnd; + private boolean mCancelled = false; private int mTotalFramesCount = 0; private int mMissedFramesCount = 0; private long mMaxFrameTimeNanos = 0; private Session mSession; - /** - * Constructor of FrameTracker. - * @param session a trace session. - * @param handler a handler for handling callbacks. - * @param renderer a ThreadedRendererWrapper instance. - * @param metrics a FrameMetricsWrapper instance. - */ public FrameTracker(@NonNull Session session, @NonNull Handler handler, - @NonNull ThreadedRendererWrapper renderer, @NonNull FrameMetricsWrapper metrics) { + @NonNull ThreadedRendererWrapper renderer, @NonNull FrameMetricsWrapper metrics, + int traceThresholdMissedFrames, int traceThresholdFrameTimeMillis) { mSession = session; mRendererWrapper = renderer; mMetricsWrapper = metrics; mObserver = new HardwareRendererObserver(this, mMetricsWrapper.getTiming(), handler); + mTraceThresholdMissedFrames = traceThresholdMissedFrames; + mTraceThresholdFrameTimeMillis = traceThresholdFrameTimeMillis; } /** @@ -109,13 +108,15 @@ public class FrameTracker implements HardwareRendererObserver.OnFrameMetricsAvai } Trace.endAsyncSection(mSession.getName(), (int) mBeginTime); mRendererWrapper.removeObserver(mObserver); - mBeginTime = UNKNOWN_TIMESTAMP; - mEndTime = UNKNOWN_TIMESTAMP; - mShouldTriggerTrace = false; + mCancelled = true; } @Override public synchronized void onFrameMetricsAvailable(int dropCountSinceLastInvocation) { + if (mCancelled) { + return; + } + // 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. @@ -136,13 +137,14 @@ public class FrameTracker implements HardwareRendererObserver.OnFrameMetricsAvai Trace.traceCounter(Trace.TRACE_TAG_APP, mSession.getName() + "#totalFrames", mTotalFramesCount); Trace.traceCounter(Trace.TRACE_TAG_APP, mSession.getName() + "#maxFrameTimeMillis", - (int) (mMaxFrameTimeNanos / 1_000_000)); + (int) (mMaxFrameTimeNanos / NANOS_IN_MILLISECOND)); // Trigger perfetto if necessary. - if (mShouldTriggerTrace) { - if (DEBUG) { - Log.v(TAG, "Found janky frame, triggering perfetto."); - } + boolean overMissedFramesThreshold = mTraceThresholdMissedFrames != -1 + && mMissedFramesCount >= mTraceThresholdMissedFrames; + boolean overFrameTimeThreshold = mTraceThresholdFrameTimeMillis != -1 + && mMaxFrameTimeNanos >= mTraceThresholdFrameTimeMillis * NANOS_IN_MILLISECOND; + if (overMissedFramesThreshold || overFrameTimeThreshold) { triggerPerfetto(); } if (mSession.logToStatsd()) { @@ -168,7 +170,6 @@ public class FrameTracker implements HardwareRendererObserver.OnFrameMetricsAvai if (isJankyFrame) { mMissedFramesCount += 1; - mShouldTriggerTrace = true; } } diff --git a/core/java/com/android/internal/jank/InteractionJankMonitor.java b/core/java/com/android/internal/jank/InteractionJankMonitor.java index fcaa963feda2c..771a72c98a7aa 100644 --- a/core/java/com/android/internal/jank/InteractionJankMonitor.java +++ b/core/java/com/android/internal/jank/InteractionJankMonitor.java @@ -36,7 +36,10 @@ import static com.android.internal.util.FrameworkStatsLog.UIINTERACTION_FRAME_IN import android.annotation.IntDef; import android.annotation.NonNull; +import android.os.Build; +import android.os.HandlerExecutor; import android.os.HandlerThread; +import android.provider.DeviceConfig; import android.util.Log; import android.util.SparseArray; import android.view.View; @@ -47,6 +50,7 @@ import com.android.internal.jank.FrameTracker.ThreadedRendererWrapper; import java.lang.annotation.Retention; import java.lang.annotation.RetentionPolicy; +import java.util.concurrent.ThreadLocalRandom; import java.util.concurrent.TimeUnit; /** @@ -55,9 +59,21 @@ import java.util.concurrent.TimeUnit; */ public class InteractionJankMonitor { private static final String TAG = InteractionJankMonitor.class.getSimpleName(); - private static final boolean DEBUG = false; private static final String DEFAULT_WORKER_NAME = TAG + "-Worker"; private static final long DEFAULT_TIMEOUT_MS = TimeUnit.SECONDS.toMillis(5L); + 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 = + "trace_threshold_missed_frames"; + private static final String SETTINGS_THRESHOLD_FRAME_TIME_MILLIS_KEY = + "trace_threshold_frame_time_millis"; + /** Default to being enabled on debug builds. */ + private static final boolean DEFAULT_ENABLED = Build.IS_DEBUGGABLE; + /** Default to collecting data for all CUJs. */ + private static final int DEFAULT_SAMPLING_INTERVAL = 1; + /** Default to triggering trace if 3 frames are missed OR a frame takes at least 64ms */ + private static final int DEFAULT_TRACE_THRESHOLD_MISSED_FRAMES = 3; + private static final int DEFAULT_TRACE_THRESHOLD_FRAME_TIME_MILLIS = 64; // Every value must have a corresponding entry in CUJ_STATSD_INTERACTION_TYPE. public static final int CUJ_NOTIFICATION_SHADE_EXPAND_COLLAPSE = 0; @@ -106,12 +122,20 @@ public class InteractionJankMonitor { private static volatile InteractionJankMonitor sInstance; + private final DeviceConfig.OnPropertiesChangedListener mPropertiesChangedListener = + this::updateProperties; + private ThreadedRendererWrapper mRenderer; private FrameMetricsWrapper mMetrics; private SparseArray mRunningTrackers; private SparseArray mTimeoutActions; private HandlerThread mWorker; + private boolean mInitialized; + private 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; /** @hide */ @IntDef({ @@ -134,10 +158,12 @@ public class InteractionJankMonitor { CUJ_NOTIFICATION_APP_START, }) @Retention(RetentionPolicy.SOURCE) - public @interface CujType {} + public @interface CujType { + } /** * Get the singleton of InteractionJankMonitor. + * * @return instance of InteractionJankMonitor */ public static InteractionJankMonitor getInstance() { @@ -154,6 +180,7 @@ public class InteractionJankMonitor { /** * This constructor should be only public to tests. + * * @param worker the worker thread for the callbacks */ @VisibleForTesting @@ -165,11 +192,11 @@ public class InteractionJankMonitor { /** * Init InteractionJankMonitor for later instrumentation. + * * @param view Any view in the view tree to get context and ThreadedRenderer. * @return boolean true if the instance has been initialized successfully. */ public boolean init(@NonNull View view) { - //TODO (163505250): This should be no-op if not in droid food rom. if (!mInitialized) { synchronized (this) { if (!mInitialized) { @@ -180,7 +207,20 @@ public class InteractionJankMonitor { mRenderer = new ThreadedRendererWrapper(view.getThreadedRenderer()); mMetrics = new FrameMetricsWrapper(); mWorker.start(); + mEnabled = DEFAULT_ENABLED; + mSamplingInterval = DEFAULT_SAMPLING_INTERVAL; mInitialized = true; + + // Post initialization to the background in case we're running on the main + // thread. + mWorker.getThreadHandler().post( + () -> mPropertiesChangedListener.onPropertiesChanged( + DeviceConfig.getProperties( + DeviceConfig.NAMESPACE_INTERACTION_JANK_MONITOR))); + DeviceConfig.addOnPropertiesChangedListener( + DeviceConfig.NAMESPACE_INTERACTION_JANK_MONITOR, + new HandlerExecutor(mWorker.getThreadHandler()), + mPropertiesChangedListener); } } } @@ -189,6 +229,7 @@ public class InteractionJankMonitor { /** * Create a {@link FrameTracker} instance. + * * @param session the session associates with this tracker * @return instance of the FrameTracker */ @@ -196,47 +237,50 @@ public class InteractionJankMonitor { public FrameTracker createFrameTracker(Session session) { synchronized (this) { if (!mInitialized) return null; - return new FrameTracker(session, mWorker.getThreadHandler(), mRenderer, mMetrics); + return new FrameTracker(session, mWorker.getThreadHandler(), mRenderer, mMetrics, + mTraceThresholdMissedFrames, mTraceThresholdFrameTimeMillis); } } /** * Begin a trace session, must invoke {@link #init(View)} before invoking this method. + * * @param cujType the specific {@link InteractionJankMonitor.CujType}. * @return boolean true if the tracker is started successfully, false otherwise. */ public boolean begin(@CujType int cujType) { - //TODO (163505250): This should be no-op if not in droid food rom. synchronized (this) { - return begin(cujType, 0L /* timeout */); + return begin(cujType, DEFAULT_TIMEOUT_MS); } } /** * Begin a trace session, must invoke {@link #init(View)} before invoking this method. + * * @param cujType the specific {@link InteractionJankMonitor.CujType}. * @param timeout the elapsed time in ms until firing the timeout action. * @return boolean true if the tracker is started successfully, false otherwise. */ public boolean begin(@CujType int cujType, long timeout) { - //TODO (163505250): This should be no-op if not in droid food rom. synchronized (this) { if (!mInitialized) { Log.d(TAG, "Not initialized!", new Throwable()); return false; } - Session session = new Session(cujType); - FrameTracker tracker = getTracker(session); + boolean shouldSample = ThreadLocalRandom.current().nextInt() % mSamplingInterval == 0; + if (!mEnabled || !shouldSample) { + return false; + } + FrameTracker tracker = getTracker(cujType); // Skip subsequent calls if we already have an ongoing tracing. if (tracker != null) return false; // begin a new trace session. - tracker = createFrameTracker(session); + tracker = createFrameTracker(new Session(cujType)); mRunningTrackers.put(cujType, tracker); tracker.begin(); // Cancel the trace if we don't get an end() call in specified duration. - timeout = timeout > 0L ? timeout : DEFAULT_TIMEOUT_MS; Runnable timeoutAction = () -> cancel(cujType); mTimeoutActions.put(cujType, timeoutAction); mWorker.getThreadHandler().postDelayed(timeoutAction, timeout); @@ -246,6 +290,7 @@ public class InteractionJankMonitor { /** * End a trace session, must invoke {@link #init(View)} before invoking this method. + * * @param cujType the specific {@link InteractionJankMonitor.CujType}. * @return boolean true if the tracker is ended successfully, false otherwise. */ @@ -263,18 +308,18 @@ public class InteractionJankMonitor { mTimeoutActions.remove(cujType); } - Session session = new Session(cujType); - FrameTracker tracker = getTracker(session); + FrameTracker tracker = getTracker(cujType); // Skip this call since we haven't started a trace yet. if (tracker == null) return false; tracker.end(); - mRunningTrackers.remove(session.getCuj()); + mRunningTrackers.remove(cujType); return true; } } /** * Cancel the trace session, must invoke {@link #init(View)} before invoking this method. + * * @return boolean true if the tracker is cancelled successfully, false otherwise. */ public boolean cancel(@CujType int cujType) { @@ -291,50 +336,40 @@ public class InteractionJankMonitor { mTimeoutActions.remove(cujType); } - Session session = new Session(cujType); - FrameTracker tracker = getTracker(session); + FrameTracker tracker = getTracker(cujType); // Skip this call since we haven't started a trace yet. if (tracker == null) return false; tracker.cancel(); - mRunningTrackers.remove(session.getCuj()); + mRunningTrackers.remove(cujType); return true; } } - private void destroy() { - synchronized (this) { - int trackers = mRunningTrackers.size(); - for (int i = 0; i < trackers; i++) { - mRunningTrackers.valueAt(i).cancel(); - } - mRunningTrackers = null; - mTimeoutActions.clear(); - mTimeoutActions = null; - mWorker.quit(); - mWorker = null; - } - } - - /** - * Abandon current instance. - */ - @VisibleForTesting - public static void abandon() { - if (sInstance == null) return; - synchronized (InteractionJankMonitor.class) { - if (sInstance == null) return; - sInstance.destroy(); - sInstance = null; - } - } - - private FrameTracker getTracker(Session session) { + private FrameTracker getTracker(@CujType int cuj) { synchronized (this) { if (!mInitialized) return null; - return mRunningTrackers.get(session.getCuj()); + return mRunningTrackers.get(cuj); } } + private void updateProperties(DeviceConfig.Properties properties) { + synchronized (this) { + 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); + } + } + + @VisibleForTesting + public DeviceConfig.OnPropertiesChangedListener getPropertiesChangedListener() { + return mPropertiesChangedListener; + } + /** * Trigger the perfetto daemon to collect and upload data. */ @@ -402,12 +437,14 @@ public class InteractionJankMonitor { * A class to represent a session. */ public static class Session { - private @CujType int mCujType; + @CujType + private int mCujType; public Session(@CujType int cujType) { mCujType = cujType; } + @CujType public int getCuj() { return mCujType; } diff --git a/core/tests/coretests/src/com/android/internal/jank/FrameTrackerTest.java b/core/tests/coretests/src/com/android/internal/jank/FrameTrackerTest.java index e17800f7b6fdb..2402420e1bc1a 100644 --- a/core/tests/coretests/src/com/android/internal/jank/FrameTrackerTest.java +++ b/core/tests/coretests/src/com/android/internal/jank/FrameTrackerTest.java @@ -77,7 +77,7 @@ public class FrameTrackerTest { Session session = new Session(CUJ_NOTIFICATION_SHADE_EXPAND_COLLAPSE); mTracker = Mockito.spy( - new FrameTracker(session, handler, mRenderer, mWrapper)); + new FrameTracker(session, handler, mRenderer, mWrapper, 1, -1)); doNothing().when(mTracker).triggerPerfetto(); } diff --git a/core/tests/coretests/src/com/android/internal/jank/InteractionJankMonitorTest.java b/core/tests/coretests/src/com/android/internal/jank/InteractionJankMonitorTest.java index a9cfd286688b5..474cb1d7ed967 100644 --- a/core/tests/coretests/src/com/android/internal/jank/InteractionJankMonitorTest.java +++ b/core/tests/coretests/src/com/android/internal/jank/InteractionJankMonitorTest.java @@ -24,6 +24,7 @@ import static com.google.common.truth.Truth.assertWithMessage; import static org.mockito.ArgumentMatchers.any; import static org.mockito.ArgumentMatchers.anyLong; +import static org.mockito.Mockito.atLeastOnce; import static org.mockito.Mockito.doNothing; import static org.mockito.Mockito.doReturn; import static org.mockito.Mockito.spy; @@ -32,6 +33,7 @@ import static org.mockito.Mockito.verify; import android.os.Handler; import android.os.HandlerThread; import android.os.Message; +import android.provider.DeviceConfig; import android.view.View; import android.view.ViewAttachTestActivity; @@ -50,6 +52,7 @@ import org.mockito.ArgumentCaptor; import java.lang.reflect.Field; import java.lang.reflect.Modifier; import java.util.Arrays; +import java.util.HashMap; import java.util.HashSet; import java.util.List; import java.util.stream.Collectors; @@ -71,8 +74,6 @@ public class InteractionJankMonitorTest { mView = mActivity.getWindow().getDecorView(); assertThat(mView.isAttachedToWindow()).isTrue(); - InteractionJankMonitor.abandon(); - Handler handler = spy(new Handler(mActivity.getMainLooper())); doReturn(true).when(handler).sendMessageAtTime(any(), anyLong()); mWorker = spy(new HandlerThread("Interaction-jank-monitor-test")); @@ -93,7 +94,7 @@ public class InteractionJankMonitorTest { Session session = new Session(CUJ_NOTIFICATION_SHADE_EXPAND_COLLAPSE); FrameTracker tracker = spy(new FrameTracker(session, mWorker.getThreadHandler(), new ThreadedRendererWrapper(mView.getThreadedRenderer()), - new FrameMetricsWrapper())); + new FrameMetricsWrapper(), 1, -1)); doReturn(tracker).when(monitor).createFrameTracker(any()); // Simulate a trace session and see if begin / end are invoked. @@ -103,6 +104,21 @@ public class InteractionJankMonitorTest { verify(tracker).end(); } + @Test + public void testDisabledThroughDeviceConfig() { + InteractionJankMonitor monitor = new InteractionJankMonitor(mWorker); + monitor.init(mView); + + HashMap propertiesValues = new HashMap<>(); + propertiesValues.put("enabled", "false"); + DeviceConfig.Properties properties = new DeviceConfig.Properties( + DeviceConfig.NAMESPACE_INTERACTION_JANK_MONITOR, propertiesValues); + monitor.getPropertiesChangedListener().onPropertiesChanged(properties); + + assertThat(monitor.begin(CUJ_NOTIFICATION_SHADE_EXPAND_COLLAPSE)).isFalse(); + assertThat(monitor.end(CUJ_NOTIFICATION_SHADE_EXPAND_COLLAPSE)).isFalse(); + } + @Test public void testCheckInitState() { InteractionJankMonitor monitor = new InteractionJankMonitor(mWorker); @@ -134,12 +150,13 @@ public class InteractionJankMonitorTest { Session session = new Session(CUJ_NOTIFICATION_SHADE_EXPAND_COLLAPSE); FrameTracker tracker = spy(new FrameTracker(session, mWorker.getThreadHandler(), new ThreadedRendererWrapper(mView.getThreadedRenderer()), - new FrameMetricsWrapper())); + new FrameMetricsWrapper(), 1, -1)); doReturn(tracker).when(monitor).createFrameTracker(any()); assertThat(monitor.begin(session.getCuj())).isTrue(); verify(tracker).begin(); - verify(mWorker.getThreadHandler()).sendMessageAtTime(captor.capture(), anyLong()); + verify(mWorker.getThreadHandler(), atLeastOnce()).sendMessageAtTime(captor.capture(), + anyLong()); Runnable runnable = captor.getValue().getCallback(); assertThat(runnable).isNotNull(); mWorker.getThreadHandler().removeCallbacks(runnable);