Android/frameworks_base
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

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

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

Change-Id: I6fed511a8c1e9c87622f20fbf13f37f5d59559a6
Signed-off-by: Automerger Merge Worker <android-build-automerger-merge-worker@system.gserviceaccount.com>
This commit is contained in:
TreeHugger Robot
2022-07-14 20:52:02 +00:00
committed by Automerger Merge Worker
parent a0376284a4 de8e7777c8
commit ff66e490bf
4 changed files with 375 additions and 210 deletions
Download Patch File Download Diff File Expand all files Collapse all files

307
core/java/com/android/internal/jank/FrameTracker.java
View File

@@ -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,
@Nullable ThreadedRendererWrapper renderer, @Nullable ViewRootWrapper viewRootWrapper,
public FrameTracker(@NonNull InteractionJankMonitor monitor, @NonNull Session session,
@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(
FrameTracker.this, mSurfaceControl);
markEvent("FT#deferMonitoring");
postTraceStartMarker();
// Previous begin invocation is not successfully, begin it again.
begin();
}
}
}
}, EXECUTOR_TASK_TIMEOUT);
}
@Override
@@ -208,18 +245,16 @@ 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(() -> {
synchronized (mLock) {
if (DEBUG) {
Log.d(TAG, "surfaceDestroyed: " + mSession.getName()
+ ", finalized=" + mMetricsFinalized
+ ", info=" + mJankInfos.size()
+ ", vsync=" + mBeginVsyncId);
}
if (!mMetricsFinalized) {
end(REASON_END_SURFACE_DESTROYED);
finish();
}
getHandler().postDelayed(() -> {
if (DEBUG) {
Log.d(TAG, "surfaceDestroyed: " + mSession.getName()
+ ", finalized=" + mMetricsFinalized
+ ", info=" + mJankInfos.size()
+ ", vsync=" + mBeginVsyncId);
}
if (!mMetricsFinalized) {
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.
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 (mSurfaceControl != null) {
if (DEBUG) {
Log.d(TAG, "begin: " + mSession.getName() + ", begin=" + mBeginVsyncId
+ ", defer=" + mDeferMonitoring);
+ ", defer=" + mDeferMonitoring + ", current=" + currentVsync);
}
if (mSurfaceControl != null) {
if (mDeferMonitoring) {
markEvent("FT#deferMonitoring");
// Normal case, we begin the instrument from the very beginning,
// will exclude the first frame.
postTraceStartMarker();
} 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);
if (mDeferMonitoring && currentVsync < mBeginVsyncId) {
markEvent("FT#deferMonitoring");
// Normal case, we begin the instrument from the very beginning,
// will exclude the first frame.
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();
}
if (!mSurfaceOnly) {
mRendererWrapper.addObserver(mObserver);
} else {
if (DEBUG) {
Log.d(TAG, "begin: defer beginning since the surface is not ready for CUJ="
+ mSession.getName());
}
}
}
@@ -267,89 +309,89 @@ public class FrameTracker extends SurfaceControl.OnJankDataListener
* Start trace section at appropriate time.
*/
@VisibleForTesting
public void postTraceStartMarker() {
mChoreographer.mChoreographer.postCallback(
Choreographer.CALLBACK_INPUT, this::beginInternal, null);
public void postTraceStartMarker(Runnable action) {
mChoreographer.mChoreographer.postCallback(Choreographer.CALLBACK_INPUT, action, null);
}
@UiThread
private void beginInternal() {
synchronized (mLock) {
if (mCancelled || mEndVsyncId != INVALID_ID) {
return;
}
mTracingStarted = true;
markEvent("FT#begin");
Trace.beginAsyncSection(mSession.getName(), (int) mBeginVsyncId);
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:
// 1. The session begins and ends at the same vsync id.
// 2. The session never begun.
if (mBeginVsyncId == INVALID_ID) {
return cancel(REASON_CANCEL_NOT_BEGUN);
} else if (mEndVsyncId <= mBeginVsyncId) {
return cancel(REASON_CANCEL_SAME_VSYNC);
} else {
if (DEBUG) {
Log.d(TAG, "end: " + mSession.getName()
+ ", end=" + mEndVsyncId + ", reason=" + reason);
}
markEvent("FT#end#" + reason);
Trace.endAsyncSection(mSession.getName(), (int) mBeginVsyncId);
mSession.setReason(reason);
// We don't remove observer here,
// will remove it when all the frame metrics in this duration are called back.
// See onFrameMetricsAvailable for the logic of removing the observer.
// Waiting at most 10 seconds for all callbacks to finish.
mWaitForFinishTimedOut = () -> {
Log.e(TAG, "force finish cuj because of time out:" + mSession.getName());
finish();
};
mHandler.postDelayed(mWaitForFinishTimedOut, TimeUnit.SECONDS.toMillis(10));
notifyCujEvent(ACTION_SESSION_END);
return true;
if (mCancelled || mEndVsyncId != INVALID_ID) return false;
mEndVsyncId = mChoreographer.getVsyncId();
// Cancel the session if:
// 1. The session begins and ends at the same vsync id.
// 2. The session never begun.
if (mBeginVsyncId == INVALID_ID) {
return cancel(REASON_CANCEL_NOT_BEGUN);
} else if (mEndVsyncId <= mBeginVsyncId) {
return cancel(REASON_CANCEL_SAME_VSYNC);
} else {
if (DEBUG) {
Log.d(TAG, "end: " + mSession.getName()
+ ", end=" + mEndVsyncId + ", reason=" + reason);
}
markEvent("FT#end#" + reason);
Trace.endAsyncSection(mSession.getName(), (int) mBeginVsyncId);
mSession.setReason(reason);
// We don't remove observer here,
// will remove it when all the frame metrics in this duration are called back.
// See onFrameMetricsAvailable for the logic of removing the observer.
// Waiting at most 10 seconds for all callbacks to finish.
mWaitForFinishTimedOut = () -> {
Log.e(TAG, "force finish cuj because of time out:" + mSession.getName());
finish();
};
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.
if (mTracingStarted) {
Trace.endAsyncSection(mSession.getName(), (int) mBeginVsyncId);
}
// Always remove the observers in cancel call to avoid leakage.
removeObservers();
if (DEBUG) {
Log.d(TAG, "cancel: " + mSession.getName() + ", begin=" + mBeginVsyncId
+ ", end=" + mEndVsyncId + ", reason=" + reason);
}
mSession.setReason(reason);
// Notify the listener the session has been cancelled.
// We don't notify the listeners if the session never begun.
notifyCujEvent(ACTION_SESSION_CANCEL);
return true;
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 has never begun.
if (mTracingStarted) {
Trace.endAsyncSection(mSession.getName(), (int) mBeginVsyncId);
}
// Always remove the observers in cancel call to avoid leakage.
removeObservers();
if (DEBUG) {
Log.d(TAG, "cancel: " + mSession.getName() + ", begin=" + mBeginVsyncId
+ ", end=" + mEndVsyncId + ", reason=" + reason);
}
mSession.setReason(reason);
// Notify the listener the session has been cancelled.
// We don't notify the listeners if the session never begun.
notifyCujEvent(ACTION_SESSION_CANCEL);
return true;
}
private void markEvent(String desc) {
@@ -364,8 +406,8 @@ public class FrameTracker extends SurfaceControl.OnJankDataListener
@Override
public void onJankDataAvailable(SurfaceControl.JankData[] jankData) {
synchronized (mLock) {
if (mCancelled) {
postCallback(() -> {
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) {
if (mCancelled) {
postCallback(() -> {
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);
}

224
core/java/com/android/internal/jank/InteractionJankMonitor.java
View File

@@ -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);
}
Object getLock() {
return mLock;
mEnabled = DEFAULT_ENABLED;
}
/**
@@ -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) {
FrameTrackerListener eventsListener = (s, act) -> handleCujEvents(act, s);
return new FrameTracker(session, mWorker.getThreadHandler(),
threadedRenderer, viewRoot, surfaceControl, choreographer,
mMetrics, new FrameTracker.StatsLogWrapper(),
mTraceThresholdMissedFrames, mTraceThresholdFrameTimeMillis,
eventsListener, config);
}
return new FrameTracker(this, session, config.getHandler(), threadedRenderer, viewRoot,
surfaceControl, choreographer, frameMetrics, 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)) {
removeTimeout(session.getCuj());
removeTracker(session.getCuj());
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(
Configuration.Builder.withView(cujType, v)
.build());
return begin(Configuration.Builder.withView(cujType, v));
} catch (IllegalArgumentException ex) {
Log.d(TAG, "Build configuration failed!", ex);
return false;
@@ -508,35 +507,42 @@ 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);
// Skip subsequent calls if we already have an ongoing tracing.
if (tracker != null) return false;
int cujType = conf.mCujType;
if (!shouldMonitor(cujType)) 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(conf, new Session(cujType, conf.mTag));
mRunningTrackers.put(cujType, tracker);
tracker.begin();
// begin a new trace session.
tracker = createFrameTracker(conf, new Session(cujType, conf.mTag));
putTracker(cujType, tracker);
tracker.begin();
// Cancel the trace if we don't get an end() call in specified duration.
scheduleTimeoutAction(
cujType, conf.mTimeout, () -> cancel(cujType, REASON_CANCEL_TIMEOUT));
return true;
}
// Cancel the trace if we don't get an end() call in specified duration.
scheduleTimeoutAction(
cujType, conf.mTimeout, () -> cancel(cujType, REASON_CANCEL_TIMEOUT));
return true;
}
/**
@@ -565,8 +571,10 @@ public class InteractionJankMonitor {
*/
@VisibleForTesting
public void scheduleTimeoutAction(@CujType int cuj, long timeout, Runnable action) {
mTimeoutActions.put(cuj, action);
mWorker.getThreadHandler().postDelayed(action, timeout);
synchronized (mLock) {
mTimeoutActions.put(cuj, action);
getTracker(cuj).getHandler().postDelayed(action, timeout);
}
}
/**
@@ -576,20 +584,37 @@ public class InteractionJankMonitor {
* @return boolean true if the tracker is ended successfully, false otherwise.
*/
public boolean end(@CujType int cujType) {
synchronized (mLock) {
// 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)) {
removeTracker(cujType);
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 true;
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);
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)) {
removeTracker(cujType);
}
return true;
}
/**
* Cancels the trace session.
*
@@ -606,39 +631,66 @@ public class InteractionJankMonitor {
*/
@VisibleForTesting
public boolean cancel(@CujType int cujType, @Reasons int reason) {
synchronized (mLock) {
// 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)) {
removeTracker(cujType);
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 true;
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);
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)) {
removeTracker(cujType);
}
return true;
}
private void putTracker(@CujType int cuj, @NonNull FrameTracker tracker) {
synchronized (mLock) {
mRunningTrackers.put(cuj, tracker);
}
}
private FrameTracker getTracker(@CujType int cuj) {
return mRunningTrackers.get(cuj);
synchronized (mLock) {
return mRunningTrackers.get(cuj);
}
}
private void removeTracker(@CujType int cuj) {
mRunningTrackers.remove(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);
}
mSamplingInterval = properties.getInt(SETTINGS_SAMPLING_INTERVAL_KEY,
DEFAULT_SAMPLING_INTERVAL);
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;
}
}

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

@@ -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();
}
}

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

@@ -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;
}