Merge "End the trace section while the surface has destroyed" into sc-dev

This commit is contained in:
Wu Ahan
2021-04-06 13:36:37 +00:00
committed by Android (Google) Code Review
4 changed files with 100 additions and 33 deletions

View File

@@ -26,7 +26,9 @@ import static android.view.SurfaceControl.JankData.SURFACE_FLINGER_SCHEDULING;
import static com.android.internal.jank.InteractionJankMonitor.ACTION_METRICS_LOGGED;
import static com.android.internal.jank.InteractionJankMonitor.ACTION_SESSION_BEGIN;
import static com.android.internal.jank.InteractionJankMonitor.ACTION_SESSION_CANCEL;
import android.annotation.IntDef;
import android.annotation.NonNull;
import android.annotation.Nullable;
import android.graphics.HardwareRendererObserver;
@@ -45,6 +47,9 @@ import com.android.internal.annotations.VisibleForTesting;
import com.android.internal.jank.InteractionJankMonitor.Session;
import com.android.internal.util.FrameworkStatsLog;
import java.lang.annotation.Retention;
import java.lang.annotation.RetentionPolicy;
/**
* A class that allows the app to get the frame metrics from HardwareRendererObserver.
* @hide
@@ -57,6 +62,26 @@ public class FrameTracker extends SurfaceControl.OnJankDataListener
private static final long INVALID_ID = -1;
public static final int NANOS_IN_MILLISECOND = 1_000_000;
static final int REASON_END_UNKNOWN = -1;
static final int REASON_END_NORMAL = 0;
static final int REASON_END_SURFACE_DESTROYED = 1;
static final int REASON_CANCEL_NORMAL = 16;
static final int REASON_CANCEL_NOT_BEGUN = 17;
static final int REASON_CANCEL_SAME_VSYNC = 18;
/** @hide */
@IntDef({
REASON_END_UNKNOWN,
REASON_END_NORMAL,
REASON_END_SURFACE_DESTROYED,
REASON_CANCEL_NORMAL,
REASON_CANCEL_NOT_BEGUN,
REASON_CANCEL_SAME_VSYNC,
})
@Retention(RetentionPolicy.SOURCE)
public @interface Reasons {
}
private final HardwareRendererObserver mObserver;
private SurfaceControl mSurfaceControl;
private final int mTraceThresholdMissedFrames;
@@ -156,7 +181,14 @@ public class FrameTracker extends SurfaceControl.OnJankDataListener
// force finish the session.
mHandler.postDelayed(() -> {
synchronized (FrameTracker.this) {
if (DEBUG) {
Log.d(TAG, "surfaceDestroyed: " + mSession.getName()
+ ", finalized=" + mMetricsFinalized
+ ", info=" + mJankInfos.size()
+ ", vsync=" + mBeginVsyncId + "-" + mEndVsyncId);
}
if (!mMetricsFinalized) {
end(REASON_END_SURFACE_DESTROYED);
finish(mJankInfos.size() - 1);
}
}
@@ -176,6 +208,9 @@ public class FrameTracker extends SurfaceControl.OnJankDataListener
mSession.setTimeStamp(System.nanoTime());
Trace.beginAsyncSection(mSession.getName(), (int) mBeginVsyncId);
mRendererWrapper.addObserver(mObserver);
if (DEBUG) {
Log.d(TAG, "begin: " + mSession.getName() + ", begin=" + mBeginVsyncId);
}
if (mSurfaceControl != null) {
mSurfaceControlWrapper.addJankStatsListener(this, mSurfaceControl);
}
@@ -187,15 +222,25 @@ public class FrameTracker extends SurfaceControl.OnJankDataListener
/**
* End the trace session of the CUJ.
*/
public synchronized void end() {
public synchronized void end(@Reasons int reason) {
if (mEndVsyncId != INVALID_ID) return;
mEndVsyncId = mChoreographer.getVsyncId();
// Cancel the session if:
// 1. The session begins and ends at the same vsync id.
// 2. The session never begun.
if (mEndVsyncId == mBeginVsyncId || mBeginVsyncId == INVALID_ID) {
cancel();
if (mBeginVsyncId == INVALID_ID) {
cancel(REASON_CANCEL_NOT_BEGUN);
} else if (mEndVsyncId == mBeginVsyncId) {
cancel(REASON_CANCEL_SAME_VSYNC);
} else {
if (DEBUG) {
Log.d(TAG, "end: " + mSession.getName()
+ ", end=" + mEndVsyncId + ", reason=" + reason);
}
Trace.endAsyncSection(mSession.getName(), (int) mBeginVsyncId);
mSession.setReason(reason);
InteractionJankMonitor.getInstance().removeTimeout(mSession.getCuj());
}
// We don't remove observer here,
// will remove it when all the frame metrics in this duration are called back.
@@ -205,7 +250,7 @@ public class FrameTracker extends SurfaceControl.OnJankDataListener
/**
* Cancel the trace session of the CUJ.
*/
public synchronized void cancel() {
public synchronized void cancel(@Reasons int reason) {
// We don't need to end the trace section if it never begun.
if (mBeginVsyncId != INVALID_ID) {
Trace.endAsyncSection(mSession.getName(), (int) mBeginVsyncId);
@@ -215,10 +260,16 @@ public class FrameTracker extends SurfaceControl.OnJankDataListener
// 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.
if (mListener != null && mBeginVsyncId != INVALID_ID) {
mListener.onNotifyCujEvents(mSession, InteractionJankMonitor.ACTION_SESSION_CANCEL);
if (mListener != null) {
mListener.onNotifyCujEvents(mSession, ACTION_SESSION_CANCEL);
}
}
@@ -399,6 +450,7 @@ public class FrameTracker extends SurfaceControl.OnJankDataListener
}
if (DEBUG) {
Log.i(TAG, "FrameTracker: CUJ=" + mSession.getName()
+ " (" + mBeginVsyncId + "," + mEndVsyncId + ")"
+ " totalFrames=" + totalFramesCount
+ " missedAppFrames=" + missedAppFramesCount
+ " missedSfFrames=" + missedSfFramesCounts

View File

@@ -19,6 +19,7 @@ package com.android.internal.jank;
import static android.content.Intent.FLAG_RECEIVER_REGISTERED_ONLY;
import static com.android.internal.jank.FrameTracker.ChoreographerWrapper;
import static com.android.internal.jank.FrameTracker.REASON_CANCEL_NOT_BEGUN;
import static com.android.internal.jank.FrameTracker.SurfaceControlWrapper;
import static com.android.internal.util.FrameworkStatsLog.UIINTERACTION_FRAME_INFO_REPORTED__INTERACTION_TYPE__LAUNCHER_ALL_APPS_SCROLL;
import static com.android.internal.util.FrameworkStatsLog.UIINTERACTION_FRAME_INFO_REPORTED__INTERACTION_TYPE__LAUNCHER_APP_CLOSE_TO_HOME;
@@ -104,7 +105,7 @@ public class InteractionJankMonitor {
public static final String BUNDLE_KEY_CUJ_NAME = ACTION_PREFIX + ".CUJ_NAME";
public static final String BUNDLE_KEY_TIMESTAMP = ACTION_PREFIX + ".TIMESTAMP";
@VisibleForTesting
public static final String PROP_NOTIFY_CUJ_EVENT = "debug.notify_cuj_events";
public static final String PROP_NOTIFY_CUJ_EVENT = "debug.jank.notify_cuj_events";
// Every value must have a corresponding entry in CUJ_STATSD_INTERACTION_TYPE.
public static final int CUJ_NOTIFICATION_SHADE_EXPAND_COLLAPSE = 0;
@@ -287,6 +288,10 @@ public class InteractionJankMonitor {
}
private void notifyEvents(Context context, String action, Session session) {
if (action.equals(ACTION_SESSION_CANCEL)
&& session.getReason() == REASON_CANCEL_NOT_BEGUN) {
return;
}
Intent intent = new Intent(action);
intent.putExtra(BUNDLE_KEY_CUJ_NAME, getNameOfCuj(session.getCuj()));
intent.putExtra(BUNDLE_KEY_TIMESTAMP, session.getTimeStamp());
@@ -294,6 +299,16 @@ public class InteractionJankMonitor {
context.sendBroadcast(intent);
}
void removeTimeout(@CujType int cujType) {
synchronized (this) {
Runnable timeout = mTimeoutActions.get(cujType);
if (timeout != null) {
mWorker.getThreadHandler().removeCallbacks(timeout);
mTimeoutActions.remove(cujType);
}
}
}
/**
* Begin a trace session.
*
@@ -351,16 +366,11 @@ public class InteractionJankMonitor {
synchronized (this) {
// remove the timeout action first.
Runnable timeout = mTimeoutActions.get(cujType);
if (timeout != null) {
mWorker.getThreadHandler().removeCallbacks(timeout);
mTimeoutActions.remove(cujType);
}
removeTimeout(cujType);
FrameTracker tracker = getTracker(cujType);
// Skip this call since we haven't started a trace yet.
if (tracker == null) return false;
tracker.end();
tracker.end(FrameTracker.REASON_END_NORMAL);
mRunningTrackers.remove(cujType);
return true;
}
@@ -375,16 +385,11 @@ public class InteractionJankMonitor {
//TODO (163505250): This should be no-op if not in droid food rom.
synchronized (this) {
// remove the timeout action first.
Runnable timeout = mTimeoutActions.get(cujType);
if (timeout != null) {
mWorker.getThreadHandler().removeCallbacks(timeout);
mTimeoutActions.remove(cujType);
}
removeTimeout(cujType);
FrameTracker tracker = getTracker(cujType);
// Skip this call since we haven't started a trace yet.
if (tracker == null) return false;
tracker.cancel();
tracker.cancel(FrameTracker.REASON_CANCEL_NORMAL);
mRunningTrackers.remove(cujType);
return true;
}
@@ -509,6 +514,8 @@ public class InteractionJankMonitor {
@CujType
private int mCujType;
private long mTimeStamp;
@FrameTracker.Reasons
private int mReason = FrameTracker.REASON_END_UNKNOWN;
public Session(@CujType int cujType) {
mCujType = cujType;
@@ -543,5 +550,13 @@ public class InteractionJankMonitor {
public long getTimeStamp() {
return mTimeStamp;
}
public void setReason(@FrameTracker.Reasons int reason) {
mReason = reason;
}
public int getReason() {
return mReason;
}
}
}

View File

@@ -129,7 +129,7 @@ public class FrameTrackerTest {
// end the trace session, the last janky frame is after the end() so is discarded.
when(mChoreographer.getVsyncId()).thenReturn(102L);
mTracker.end();
mTracker.end(FrameTracker.REASON_END_NORMAL);
sendFrame(5, JANK_NONE, 102L);
sendFrame(500, JANK_APP_DEADLINE_MISSED, 103L);
@@ -151,7 +151,7 @@ public class FrameTrackerTest {
// end the trace session
when(mChoreographer.getVsyncId()).thenReturn(102L);
mTracker.end();
mTracker.end(FrameTracker.REASON_END_NORMAL);
sendFrame(4, JANK_NONE, 102L);
verify(mTracker).removeObservers();
@@ -174,7 +174,7 @@ public class FrameTrackerTest {
// end the trace session
when(mChoreographer.getVsyncId()).thenReturn(102L);
mTracker.end();
mTracker.end(FrameTracker.REASON_END_NORMAL);
sendFrame(4, JANK_NONE, 102L);
verify(mTracker).removeObservers();
@@ -197,7 +197,7 @@ public class FrameTrackerTest {
// end the trace session
when(mChoreographer.getVsyncId()).thenReturn(102L);
mTracker.end();
mTracker.end(FrameTracker.REASON_END_NORMAL);
sendFrame(4, JANK_NONE, 102L);
verify(mTracker).removeObservers();
@@ -220,7 +220,7 @@ public class FrameTrackerTest {
// end the trace session, simulate one more valid callback came after the end call.
when(mChoreographer.getVsyncId()).thenReturn(102L);
mTracker.end();
mTracker.end(FrameTracker.REASON_END_NORMAL);
sendFrame(50, JANK_APP_DEADLINE_MISSED, 102L);
// One more callback with VSYNC after the end() vsync id.
@@ -247,7 +247,7 @@ public class FrameTrackerTest {
// a janky frame
sendFrame(50, JANK_APP_DEADLINE_MISSED, 102L);
mTracker.cancel();
mTracker.cancel(FrameTracker.REASON_CANCEL_NORMAL);
verify(mTracker).removeObservers();
// Since the tracker has been cancelled, shouldn't trigger perfetto.
verify(mTracker, never()).triggerPerfetto();
@@ -267,11 +267,11 @@ public class FrameTrackerTest {
// end the trace session
when(mChoreographer.getVsyncId()).thenReturn(101L);
mTracker.end();
mTracker.end(FrameTracker.REASON_END_NORMAL);
sendFrame(4, JANK_NONE, 102L);
// Since the begin vsync id (101) equals to the end vsync id (101), will be treat as cancel.
verify(mTracker).cancel();
verify(mTracker).cancel(FrameTracker.REASON_CANCEL_SAME_VSYNC);
// Observers should be removed in this case, or FrameTracker object will be leaked.
verify(mTracker).removeObservers();
@@ -282,13 +282,13 @@ public class FrameTrackerTest {
@Test
public void testCancelWhenSessionNeverBegun() {
mTracker.cancel();
mTracker.cancel(FrameTracker.REASON_CANCEL_NORMAL);
verify(mTracker).removeObservers();
}
@Test
public void testEndWhenSessionNeverBegun() {
mTracker.end();
mTracker.end(FrameTracker.REASON_END_NORMAL);
verify(mTracker).removeObservers();
}

View File

@@ -103,7 +103,7 @@ public class InteractionJankMonitorTest {
assertThat(monitor.begin(mView, session.getCuj())).isTrue();
verify(tracker).begin();
assertThat(monitor.end(session.getCuj())).isTrue();
verify(tracker).end();
verify(tracker).end(FrameTracker.REASON_END_NORMAL);
}
@Test
@@ -154,7 +154,7 @@ public class InteractionJankMonitorTest {
assertThat(runnable).isNotNull();
mWorker.getThreadHandler().removeCallbacks(runnable);
runnable.run();
verify(tracker).cancel();
verify(tracker).cancel(FrameTracker.REASON_CANCEL_NORMAL);
}
@Test