Improve SurfaceControlRegistry logging for applied transactions (1f1b280e) · Commits · e / os / android_frameworks_base

core/java/android/view/SurfaceControl.java

+40 −4

Original line number	Diff line number	Diff line
		@@ -2812,6 +2812,10 @@ public final class SurfaceControl implements Parcelable {
		private final ArrayMap<SurfaceControl, Point> mResizedSurfaces = new ArrayMap<>();
		private final ArrayMap<SurfaceControl, SurfaceControl> mReparentedSurfaces =
		new ArrayMap<>();
		// Only non-null if the SurfaceControlRegistry is enabled. This list tracks the set of calls
		// made through this transaction object, and is dumped (and cleared) when the transaction is
		// later applied.
		ArrayList<String> mCalls;

		Runnable mFreeNativeResources;
		private static final float[] INVALID_COLOR = {-1, -1, -1};
		@@ -2837,13 +2841,28 @@ public final class SurfaceControl implements Parcelable {
		private Transaction(long nativeObject) {
		mNativeObject = nativeObject;
		mFreeNativeResources = sRegistry.registerNativeAllocation(this, mNativeObject);
		if (!SurfaceControlRegistry.sCallStackDebuggingInitialized) {
		SurfaceControlRegistry.initializeCallStackDebugging();
		}
		setUpForSurfaceControlRegistry();
		}

		private Transaction(Parcel in) {
		readFromParcel(in);
		setUpForSurfaceControlRegistry();
		}

		/**
		* Sets up this transaction for the SurfaceControlRegistry.
		*/
		private void setUpForSurfaceControlRegistry() {
		if (!SurfaceControlRegistry.sCallStackDebuggingInitialized) {
		SurfaceControlRegistry.initializeCallStackDebugging();
		}
		mCalls = SurfaceControlRegistry.sLogAllTxCallsOnApply
		? new ArrayList<>()
		: null;
		if (SurfaceControlRegistry.sCallStackDebuggingEnabled) {
		SurfaceControlRegistry.getProcessInstance().checkCallStackDebugging(
		"ctor", this, null, null);
		}
		}

		/**
		@@ -2893,6 +2912,9 @@ public final class SurfaceControl implements Parcelable {
		if (mNativeObject != 0) {
		nativeClearTransaction(mNativeObject);
		}
		if (mCalls != null) {
		mCalls.clear();
		}
		}

		/**
		@@ -2904,6 +2926,9 @@ public final class SurfaceControl implements Parcelable {
		mReparentedSurfaces.clear();
		mFreeNativeResources.run();
		mNativeObject = 0;
		if (mCalls != null) {
		mCalls.clear();
		}
		}

		/**
		@@ -2921,7 +2946,10 @@ public final class SurfaceControl implements Parcelable {

		if (SurfaceControlRegistry.sCallStackDebuggingEnabled) {
		SurfaceControlRegistry.getProcessInstance().checkCallStackDebugging(
		"apply", this, null, null);
		SurfaceControlRegistry.APPLY, this, null, null);
		}
		if (mCalls != null) {
		mCalls.clear();
		}
		}

		@@ -4421,6 +4449,14 @@ public final class SurfaceControl implements Parcelable {
		if (this == other) {
		return this;
		}
		if (SurfaceControlRegistry.sCallStackDebuggingEnabled) {
		SurfaceControlRegistry.getProcessInstance().checkCallStackDebugging(
		"merge", this, null, "otherTx=" + other.getId());
		if (mCalls != null) {
		mCalls.addAll(other.mCalls);
		other.mCalls.clear();
		}
		}
		mResizedSurfaces.putAll(other.mResizedSurfaces);
		other.mResizedSurfaces.clear();
		mReparentedSurfaces.putAll(other.mReparentedSurfaces);

core/java/android/view/SurfaceControlRegistry.java

+35 −9

Original line number	Diff line number	Diff line
		@@ -44,6 +44,8 @@ import java.util.WeakHashMap;
		*/
		public class SurfaceControlRegistry {
		private static final String TAG = "SurfaceControlRegistry";
		// Special constant for identifying the Transaction#apply() calls
		static final String APPLY = "apply";

		/**
		* An interface for processing the registered SurfaceControls when the threshold is exceeded.
		@@ -134,6 +136,10 @@ public class SurfaceControlRegistry {
		// sCallStackDebuggingEnabled is true. Can be combined with the match name.
		private static String sCallStackDebuggingMatchCall;

		// When set, all calls on a SurfaceControl.Transaction will be stored and logged when the
		// transaction is applied.
		static boolean sLogAllTxCallsOnApply;

		// Mapping of the active SurfaceControls to the elapsed time when they were registered
		@GuardedBy("sLock")
		private final WeakHashMap<SurfaceControl, Long> mSurfaceControls;
		@@ -185,6 +191,7 @@ public class SurfaceControlRegistry {
		public void setCallStackDebuggingParams(String matchName, String matchCall) {
		sCallStackDebuggingMatchName = matchName.toLowerCase();
		sCallStackDebuggingMatchCall = matchCall.toLowerCase();
		sLogAllTxCallsOnApply = sCallStackDebuggingMatchCall.contains("apply");
		}

		/**
		@@ -294,13 +301,15 @@ public class SurfaceControlRegistry {
		sCallStackDebuggingMatchName =
		SystemProperties.get("persist.wm.debug.sc.tx.log_match_name", null)
		.toLowerCase();
		sLogAllTxCallsOnApply = sCallStackDebuggingMatchCall.contains("apply");
		// Only enable stack debugging if any of the match filters are set
		sCallStackDebuggingEnabled = (!sCallStackDebuggingMatchCall.isEmpty()
		\|\| !sCallStackDebuggingMatchName.isEmpty());
		sCallStackDebuggingEnabled = !sCallStackDebuggingMatchCall.isEmpty()
		\|\| !sCallStackDebuggingMatchName.isEmpty();
		if (sCallStackDebuggingEnabled) {
		Log.d(TAG, "Enabling transaction call stack debugging:"
		+ " matchCall=" + sCallStackDebuggingMatchCall
		+ " matchName=" + sCallStackDebuggingMatchName);
		+ " matchName=" + sCallStackDebuggingMatchName
		+ " logCallsWithApply=" + sLogAllTxCallsOnApply);
		}
		}

		@@ -319,15 +328,31 @@ public class SurfaceControlRegistry {
		if (!sCallStackDebuggingEnabled) {
		return;
		}
		if (!matchesForCallStackDebugging(sc != null ? sc.getName() : null, call)) {
		return;
		}

		final String txMsg = tx != null ? "tx=" + tx.getId() + " " : "";
		final String scMsg = sc != null ? " sc=" + sc.getName() + "" : "";
		final String msg = details != null
		? call + " (" + txMsg + scMsg + ") " + details
		: call + " (" + txMsg + scMsg + ")";
		if (sLogAllTxCallsOnApply && tx != null) {
		if (call == APPLY) {
		// Log the apply and dump the calls on that transaction
		Log.e(TAG, msg, new Throwable());
		for (int i = 0; i < tx.mCalls.size(); i++) {
		Log.d(TAG, " " + tx.mCalls.get(i));
		}
		} else if (matchesForCallStackDebugging(sc != null ? sc.getName() : null, call)) {
		// Otherwise log this call to the transaction if it matches the tracked calls
		Log.e(TAG, msg, new Throwable());
		tx.mCalls.add(msg);
		}
		} else {
		// Log this call if it matches the tracked calls
		if (!matchesForCallStackDebugging(sc != null ? sc.getName() : null, call)) {
		return;
		}
		Log.e(TAG, msg, new Throwable());
		}
		}

		/**
		@@ -388,6 +413,7 @@ public class SurfaceControlRegistry {
		pw.println("sCallStackDebuggingEnabled=" + sCallStackDebuggingEnabled);
		pw.println("sCallStackDebuggingMatchName=" + sCallStackDebuggingMatchName);
		pw.println("sCallStackDebuggingMatchCall=" + sCallStackDebuggingMatchCall);
		pw.println("sLogAllTxCallsOnApply=" + sLogAllTxCallsOnApply);
		}
		}
		}

libs/WindowManager/Shell/src/com/android/wm/shell/docs/debugging.md

+11 −1

Original line number	Diff line number	Diff line
		@@ -73,7 +73,7 @@ stack traces when specific surface transaction calls are made, which is possible
		following system properties for example:
		```shell
		# Enabling
		adb shell setprop persist.wm.debug.sc.tx.log_match_call setAlpha # matches the name of the SurfaceControlTransaction method
		adb shell setprop persist.wm.debug.sc.tx.log_match_call setAlpha,setPosition # matches the name of the SurfaceControlTransaction methods
		adb shell setprop persist.wm.debug.sc.tx.log_match_name com.android.systemui # matches the name of the surface
		adb reboot
		adb logcat -s "SurfaceControlRegistry"
		@@ -87,6 +87,16 @@ adb reboot
		It is not necessary to set both `log_match_call` and `log_match_name`, but note logs can be quite
		noisy if unfiltered.

		It can sometimes be useful to trace specific logs and when they are applied (sometimes we build
		transactions that can be applied later). You can do this by adding the "merge" and "apply" calls to
		the set of requested calls:
		```shell
		# Enabling
		adb shell setprop persist.wm.debug.sc.tx.log_match_call setAlpha,merge,apply # apply will dump logs of each setAlpha or merge call on that tx
		adb reboot
		adb logcat -s "SurfaceControlRegistry"
		```

		## Tracing activity starts in the app process

		It's sometimes useful to know when to see a stack trace of when an activity starts in the app code