Tweak transition logs to make them a bit easier to follow
- Break out sent TransitionInfo changes into their own line to make them
easier to parse
- Send the transition id with the TransitionRequestInfo so we can log it
on both ends
- Print transition ids in the same way "(#id)" in both shell and core
- Add dump method to shell transitions to dump active/pending
Bug: 305873102
Test: logcat | grep WindowManager
Test: dumpsys activity service SystemUIService
Change-Id: Ifecd6d9c022f193184a751f6a2eed8b9405b1049
diff --git a/core/java/android/window/TransitionInfo.java b/core/java/android/window/TransitionInfo.java
index 61f340a..1a2d202 100644
--- a/core/java/android/window/TransitionInfo.java
+++ b/core/java/android/window/TransitionInfo.java
@@ -402,6 +402,18 @@
@Override
public String toString() {
+ return toString("");
+ }
+
+ /**
+ * Returns a string representation of this transition info.
+ * @hide
+ */
+ public String toString(@NonNull String prefix) {
+ final boolean shouldPrettyPrint = !prefix.isEmpty() && !mChanges.isEmpty();
+ final String innerPrefix = shouldPrettyPrint ? prefix + " " : "";
+ final String changesLineStart = shouldPrettyPrint ? "\n" + prefix : "";
+ final String perChangeLineStart = shouldPrettyPrint ? "\n" + innerPrefix : "";
StringBuilder sb = new StringBuilder();
sb.append("{id=").append(mDebugId).append(" t=").append(transitTypeToString(mType))
.append(" f=0x").append(Integer.toHexString(mFlags)).append(" trk=").append(mTrack)
@@ -413,12 +425,15 @@
sb.append(mRoots.get(i).mDisplayId).append("@").append(mRoots.get(i).mOffset);
}
sb.append("] c=[");
+ sb.append(perChangeLineStart);
for (int i = 0; i < mChanges.size(); ++i) {
if (i > 0) {
sb.append(',');
+ sb.append(perChangeLineStart);
}
sb.append(mChanges.get(i));
}
+ sb.append(changesLineStart);
sb.append("]}");
return sb.toString();
}
diff --git a/core/java/android/window/TransitionRequestInfo.java b/core/java/android/window/TransitionRequestInfo.java
index 932608a3..bd54e14 100644
--- a/core/java/android/window/TransitionRequestInfo.java
+++ b/core/java/android/window/TransitionRequestInfo.java
@@ -62,13 +62,16 @@
/** The transition flags known at the time of the request. These may not be complete. */
private final int mFlags;
+ /** This is only a BEST-EFFORT id used for log correlation. DO NOT USE for any real work! */
+ private final int mDebugId;
+
/** constructor override */
public TransitionRequestInfo(
@WindowManager.TransitionType int type,
@Nullable ActivityManager.RunningTaskInfo triggerTask,
@Nullable RemoteTransition remoteTransition) {
this(type, triggerTask, null /* pipTask */,
- remoteTransition, null /* displayChange */, 0 /* flags */);
+ remoteTransition, null /* displayChange */, 0 /* flags */, -1 /* debugId */);
}
/** constructor override */
@@ -78,16 +81,29 @@
@Nullable RemoteTransition remoteTransition,
int flags) {
this(type, triggerTask, null /* pipTask */,
- remoteTransition, null /* displayChange */, flags);
+ remoteTransition, null /* displayChange */, flags, -1 /* debugId */);
}
+ /** constructor override */
public TransitionRequestInfo(
@WindowManager.TransitionType int type,
@Nullable ActivityManager.RunningTaskInfo triggerTask,
@Nullable RemoteTransition remoteTransition,
@Nullable TransitionRequestInfo.DisplayChange displayChange,
int flags) {
- this(type, triggerTask, null /* pipTask */, remoteTransition, displayChange, flags);
+ this(type, triggerTask, null /* pipTask */, remoteTransition, displayChange, flags,
+ -1 /* debugId */);
+ }
+
+ /** constructor override */
+ public TransitionRequestInfo(
+ @WindowManager.TransitionType int type,
+ @Nullable ActivityManager.RunningTaskInfo triggerTask,
+ @Nullable ActivityManager.RunningTaskInfo pipTask,
+ @Nullable RemoteTransition remoteTransition,
+ @Nullable TransitionRequestInfo.DisplayChange displayChange,
+ int flags) {
+ this(type, triggerTask, pipTask, remoteTransition, displayChange, flags, -1 /* debugId */);
}
/** @hide */
@@ -270,7 +286,7 @@
};
@DataClass.Generated(
- time = 1695667226050L,
+ time = 1697564781403L,
codegenVersion = "1.0.23",
sourceFile = "frameworks/base/core/java/android/window/TransitionRequestInfo.java",
inputSignatures = "private final int mDisplayId\nprivate @android.annotation.Nullable android.graphics.Rect mStartAbsBounds\nprivate @android.annotation.Nullable android.graphics.Rect mEndAbsBounds\nprivate int mStartRotation\nprivate int mEndRotation\nprivate boolean mPhysicalDisplayChanged\nclass DisplayChange extends java.lang.Object implements [android.os.Parcelable]\n@com.android.internal.util.DataClass(genToString=true, genSetters=true, genBuilder=false, genConstructor=false)")
@@ -318,6 +334,8 @@
* (if size is changing).
* @param flags
* The transition flags known at the time of the request. These may not be complete.
+ * @param debugId
+ * This is only a BEST-EFFORT id used for log correlation. DO NOT USE for any real work!
*/
@DataClass.Generated.Member
public TransitionRequestInfo(
@@ -326,7 +344,8 @@
@Nullable ActivityManager.RunningTaskInfo pipTask,
@Nullable RemoteTransition remoteTransition,
@Nullable TransitionRequestInfo.DisplayChange displayChange,
- int flags) {
+ int flags,
+ int debugId) {
this.mType = type;
com.android.internal.util.AnnotationValidations.validate(
WindowManager.TransitionType.class, null, mType);
@@ -335,6 +354,7 @@
this.mRemoteTransition = remoteTransition;
this.mDisplayChange = displayChange;
this.mFlags = flags;
+ this.mDebugId = debugId;
// onConstructed(); // You can define this method to get a callback
}
@@ -392,6 +412,14 @@
}
/**
+ * This is only a BEST-EFFORT id used for log correlation. DO NOT USE for any real work!
+ */
+ @DataClass.Generated.Member
+ public int getDebugId() {
+ return mDebugId;
+ }
+
+ /**
* If non-null, the task containing the activity whose lifecycle change (start or
* finish) has caused this transition to occur.
*/
@@ -443,7 +471,8 @@
"pipTask = " + mPipTask + ", " +
"remoteTransition = " + mRemoteTransition + ", " +
"displayChange = " + mDisplayChange + ", " +
- "flags = " + mFlags +
+ "flags = " + mFlags + ", " +
+ "debugId = " + mDebugId +
" }";
}
@@ -465,6 +494,7 @@
if (mRemoteTransition != null) dest.writeTypedObject(mRemoteTransition, flags);
if (mDisplayChange != null) dest.writeTypedObject(mDisplayChange, flags);
dest.writeInt(mFlags);
+ dest.writeInt(mDebugId);
}
@Override
@@ -485,6 +515,7 @@
RemoteTransition remoteTransition = (flg & 0x8) == 0 ? null : (RemoteTransition) in.readTypedObject(RemoteTransition.CREATOR);
TransitionRequestInfo.DisplayChange displayChange = (flg & 0x10) == 0 ? null : (TransitionRequestInfo.DisplayChange) in.readTypedObject(TransitionRequestInfo.DisplayChange.CREATOR);
int flags = in.readInt();
+ int debugId = in.readInt();
this.mType = type;
com.android.internal.util.AnnotationValidations.validate(
@@ -494,6 +525,7 @@
this.mRemoteTransition = remoteTransition;
this.mDisplayChange = displayChange;
this.mFlags = flags;
+ this.mDebugId = debugId;
// onConstructed(); // You can define this method to get a callback
}
@@ -513,10 +545,10 @@
};
@DataClass.Generated(
- time = 1695667226088L,
+ time = 1697564781438L,
codegenVersion = "1.0.23",
sourceFile = "frameworks/base/core/java/android/window/TransitionRequestInfo.java",
- inputSignatures = "private final @android.view.WindowManager.TransitionType int mType\nprivate @android.annotation.Nullable android.app.ActivityManager.RunningTaskInfo mTriggerTask\nprivate @android.annotation.Nullable android.app.ActivityManager.RunningTaskInfo mPipTask\nprivate @android.annotation.Nullable android.window.RemoteTransition mRemoteTransition\nprivate @android.annotation.Nullable android.window.TransitionRequestInfo.DisplayChange mDisplayChange\nprivate final int mFlags\n java.lang.String typeToString()\nclass TransitionRequestInfo extends java.lang.Object implements [android.os.Parcelable]\n@com.android.internal.util.DataClass(genToString=true, genSetters=true, genAidl=true)")
+ inputSignatures = "private final @android.view.WindowManager.TransitionType int mType\nprivate @android.annotation.Nullable android.app.ActivityManager.RunningTaskInfo mTriggerTask\nprivate @android.annotation.Nullable android.app.ActivityManager.RunningTaskInfo mPipTask\nprivate @android.annotation.Nullable android.window.RemoteTransition mRemoteTransition\nprivate @android.annotation.Nullable android.window.TransitionRequestInfo.DisplayChange mDisplayChange\nprivate final int mFlags\nprivate final int mDebugId\n java.lang.String typeToString()\nclass TransitionRequestInfo extends java.lang.Object implements [android.os.Parcelable]\n@com.android.internal.util.DataClass(genToString=true, genSetters=true, genAidl=true)")
@Deprecated
private void __metadata() {}
diff --git a/libs/WindowManager/Shell/src/com/android/wm/shell/dagger/WMShellBaseModule.java b/libs/WindowManager/Shell/src/com/android/wm/shell/dagger/WMShellBaseModule.java
index c51af46..ea7b2e9 100644
--- a/libs/WindowManager/Shell/src/com/android/wm/shell/dagger/WMShellBaseModule.java
+++ b/libs/WindowManager/Shell/src/com/android/wm/shell/dagger/WMShellBaseModule.java
@@ -605,6 +605,7 @@
@Provides
static Transitions provideTransitions(Context context,
ShellInit shellInit,
+ ShellCommandHandler shellCommandHandler,
ShellController shellController,
ShellTaskOrganizer organizer,
TransactionPool pool,
@@ -612,14 +613,13 @@
@ShellMainThread ShellExecutor mainExecutor,
@ShellMainThread Handler mainHandler,
@ShellAnimationThread ShellExecutor animExecutor,
- ShellCommandHandler shellCommandHandler,
RootTaskDisplayAreaOrganizer rootTaskDisplayAreaOrganizer) {
if (!context.getResources().getBoolean(R.bool.config_registerShellTransitionsOnInit)) {
// TODO(b/238217847): Force override shell init if registration is disabled
shellInit = new ShellInit(mainExecutor);
}
- return new Transitions(context, shellInit, shellController, organizer, pool,
- displayController, mainExecutor, mainHandler, animExecutor, shellCommandHandler,
+ return new Transitions(context, shellInit, shellCommandHandler, shellController, organizer,
+ pool, displayController, mainExecutor, mainHandler, animExecutor,
rootTaskDisplayAreaOrganizer);
}
diff --git a/libs/WindowManager/Shell/src/com/android/wm/shell/transition/OneShotRemoteHandler.java b/libs/WindowManager/Shell/src/com/android/wm/shell/transition/OneShotRemoteHandler.java
index 8b050e5..b1fc16d 100644
--- a/libs/WindowManager/Shell/src/com/android/wm/shell/transition/OneShotRemoteHandler.java
+++ b/libs/WindowManager/Shell/src/com/android/wm/shell/transition/OneShotRemoteHandler.java
@@ -63,7 +63,7 @@
@NonNull Transitions.TransitionFinishCallback finishCallback) {
if (mTransition != transition) return false;
ProtoLog.v(ShellProtoLogGroup.WM_SHELL_TRANSITIONS, "Using registered One-shot remote"
- + " transition %s for #%d.", mRemote, info.getDebugId());
+ + " transition %s for (#%d).", mRemote, info.getDebugId());
final IBinder.DeathRecipient remoteDied = () -> {
Log.e(Transitions.TAG, "Remote transition died, finishing");
diff --git a/libs/WindowManager/Shell/src/com/android/wm/shell/transition/RemoteTransitionHandler.java b/libs/WindowManager/Shell/src/com/android/wm/shell/transition/RemoteTransitionHandler.java
index 592b22a..ca2c3b4 100644
--- a/libs/WindowManager/Shell/src/com/android/wm/shell/transition/RemoteTransitionHandler.java
+++ b/libs/WindowManager/Shell/src/com/android/wm/shell/transition/RemoteTransitionHandler.java
@@ -126,7 +126,7 @@
}
}
}
- ProtoLog.v(ShellProtoLogGroup.WM_SHELL_TRANSITIONS, " Delegate animation for #%d to %s",
+ ProtoLog.v(ShellProtoLogGroup.WM_SHELL_TRANSITIONS, " Delegate animation for (#%d) to %s",
info.getDebugId(), pendingRemote);
if (pendingRemote == null) return false;
@@ -241,7 +241,7 @@
if (remote == null) return null;
mRequestedRemotes.put(transition, remote);
ProtoLog.v(ShellProtoLogGroup.WM_SHELL_TRANSITIONS, "RemoteTransition directly requested"
- + " for %s: %s", transition, remote);
+ + " for (#%d) %s: %s", request.getDebugId(), transition, remote);
return new WindowContainerTransaction();
}
diff --git a/libs/WindowManager/Shell/src/com/android/wm/shell/transition/Transitions.java b/libs/WindowManager/Shell/src/com/android/wm/shell/transition/Transitions.java
index 0d9a9e9..576bba96 100644
--- a/libs/WindowManager/Shell/src/com/android/wm/shell/transition/Transitions.java
+++ b/libs/WindowManager/Shell/src/com/android/wm/shell/transition/Transitions.java
@@ -179,6 +179,7 @@
private final DefaultTransitionHandler mDefaultTransitionHandler;
private final RemoteTransitionHandler mRemoteTransitionHandler;
private final DisplayController mDisplayController;
+ private final ShellCommandHandler mShellCommandHandler;
private final ShellController mShellController;
private final ShellTransitionImpl mImpl = new ShellTransitionImpl();
private final SleepHandler mSleepHandler = new SleepHandler();
@@ -188,9 +189,6 @@
/** List of possible handlers. Ordered by specificity (eg. tapped back to front). */
private final ArrayList<TransitionHandler> mHandlers = new ArrayList<>();
- @Nullable
- private final ShellCommandHandler mShellCommandHandler;
-
private final ArrayList<TransitionObserver> mObservers = new ArrayList<>();
/** List of {@link Runnable} instances to run when the last active transition has finished. */
@@ -237,7 +235,7 @@
@Override
public String toString() {
if (mInfo != null && mInfo.getDebugId() >= 0) {
- return "(#" + mInfo.getDebugId() + ")" + mToken + "@" + getTrack();
+ return "(#" + mInfo.getDebugId() + ") " + mToken + "@" + getTrack();
}
return mToken.toString() + "@" + getTrack();
}
@@ -275,13 +273,14 @@
@NonNull ShellExecutor mainExecutor,
@NonNull Handler mainHandler,
@NonNull ShellExecutor animExecutor) {
- this(context, shellInit, shellController, organizer, pool, displayController, mainExecutor,
- mainHandler, animExecutor, null,
+ this(context, shellInit, new ShellCommandHandler(), shellController, organizer, pool,
+ displayController, mainExecutor, mainHandler, animExecutor,
new RootTaskDisplayAreaOrganizer(mainExecutor, context, shellInit));
}
public Transitions(@NonNull Context context,
@NonNull ShellInit shellInit,
+ @Nullable ShellCommandHandler shellCommandHandler,
@NonNull ShellController shellController,
@NonNull WindowOrganizer organizer,
@NonNull TransactionPool pool,
@@ -289,7 +288,6 @@
@NonNull ShellExecutor mainExecutor,
@NonNull Handler mainHandler,
@NonNull ShellExecutor animExecutor,
- @Nullable ShellCommandHandler shellCommandHandler,
@NonNull RootTaskDisplayAreaOrganizer rootTDAOrganizer) {
mOrganizer = organizer;
mContext = context;
@@ -300,13 +298,13 @@
mDefaultTransitionHandler = new DefaultTransitionHandler(context, shellInit,
displayController, pool, mainExecutor, mainHandler, animExecutor, rootTDAOrganizer);
mRemoteTransitionHandler = new RemoteTransitionHandler(mMainExecutor);
+ mShellCommandHandler = shellCommandHandler;
mShellController = shellController;
// The very last handler (0 in the list) should be the default one.
mHandlers.add(mDefaultTransitionHandler);
ProtoLog.v(ShellProtoLogGroup.WM_SHELL_TRANSITIONS, "addHandler: Default");
// Next lowest priority is remote transitions.
mHandlers.add(mRemoteTransitionHandler);
- mShellCommandHandler = shellCommandHandler;
ProtoLog.v(ShellProtoLogGroup.WM_SHELL_TRANSITIONS, "addHandler: Remote");
shellInit.addInitCallback(this::onInit, this);
}
@@ -339,9 +337,8 @@
TransitionMetrics.getInstance();
}
- if (mShellCommandHandler != null) {
- mShellCommandHandler.addCommandCallback("transitions", this, this);
- }
+ mShellCommandHandler.addCommandCallback("transitions", this, this);
+ mShellCommandHandler.addDumpCallback(this::dump, this);
}
public boolean isRegistered() {
@@ -655,8 +652,8 @@
void onTransitionReady(@NonNull IBinder transitionToken, @NonNull TransitionInfo info,
@NonNull SurfaceControl.Transaction t, @NonNull SurfaceControl.Transaction finishT) {
info.setUnreleasedWarningCallSiteForAllSurfaces("Transitions.onTransitionReady");
- ProtoLog.v(ShellProtoLogGroup.WM_SHELL_TRANSITIONS, "onTransitionReady %s: %s",
- transitionToken, info);
+ ProtoLog.v(ShellProtoLogGroup.WM_SHELL_TRANSITIONS, "onTransitionReady (#%d) %s: %s",
+ info.getDebugId(), transitionToken, info);
final int activeIdx = findByToken(mPendingTransitions, transitionToken);
if (activeIdx < 0) {
throw new IllegalStateException("Got transitionReady for non-pending transition "
@@ -1073,8 +1070,8 @@
void requestStartTransition(@NonNull IBinder transitionToken,
@Nullable TransitionRequestInfo request) {
- ProtoLog.v(ShellProtoLogGroup.WM_SHELL_TRANSITIONS, "Transition requested: %s %s",
- transitionToken, request);
+ ProtoLog.v(ShellProtoLogGroup.WM_SHELL_TRANSITIONS, "Transition requested (#%d): %s %s",
+ request.getDebugId(), transitionToken, request);
if (isTransitionKnown(transitionToken)) {
throw new RuntimeException("Transition already started " + transitionToken);
}
@@ -1475,4 +1472,68 @@
pw.println(prefix + "tracing");
mTracer.printShellCommandHelp(pw, prefix + " ");
}
+
+ private void dump(@NonNull PrintWriter pw, String prefix) {
+ pw.println(prefix + TAG);
+
+ final String innerPrefix = prefix + " ";
+ pw.println(prefix + "Handlers:");
+ for (TransitionHandler handler : mHandlers) {
+ pw.print(innerPrefix);
+ pw.print(handler.getClass().getSimpleName());
+ pw.println(" (" + Integer.toHexString(System.identityHashCode(handler)) + ")");
+ }
+
+ pw.println(prefix + "Observers:");
+ for (TransitionObserver observer : mObservers) {
+ pw.print(innerPrefix);
+ pw.println(observer.getClass().getSimpleName());
+ }
+
+ pw.println(prefix + "Pending Transitions:");
+ for (ActiveTransition transition : mPendingTransitions) {
+ pw.print(innerPrefix + "token=");
+ pw.println(transition.mToken);
+ pw.print(innerPrefix + "id=");
+ pw.println(transition.mInfo != null
+ ? transition.mInfo.getDebugId()
+ : -1);
+ pw.print(innerPrefix + "handler=");
+ pw.println(transition.mHandler != null
+ ? transition.mHandler.getClass().getSimpleName()
+ : null);
+ }
+ if (mPendingTransitions.isEmpty()) {
+ pw.println(innerPrefix + "none");
+ }
+
+ pw.println(prefix + "Ready-during-sync Transitions:");
+ for (ActiveTransition transition : mReadyDuringSync) {
+ pw.print(innerPrefix + "token=");
+ pw.println(transition.mToken);
+ pw.print(innerPrefix + "id=");
+ pw.println(transition.mInfo != null
+ ? transition.mInfo.getDebugId()
+ : -1);
+ pw.print(innerPrefix + "handler=");
+ pw.println(transition.mHandler != null
+ ? transition.mHandler.getClass().getSimpleName()
+ : null);
+ }
+ if (mReadyDuringSync.isEmpty()) {
+ pw.println(innerPrefix + "none");
+ }
+
+ pw.println(prefix + "Tracks:");
+ for (int i = 0; i < mTracks.size(); i++) {
+ final ActiveTransition transition = mTracks.get(i).mActiveTransition;
+ pw.println(innerPrefix + "Track #" + i);
+ pw.print(innerPrefix + "active=");
+ pw.println(transition);
+ if (transition != null) {
+ pw.print(innerPrefix + "hander=");
+ pw.println(transition.mHandler);
+ }
+ }
+ }
}
diff --git a/services/core/java/com/android/server/wm/TransitionController.java b/services/core/java/com/android/server/wm/TransitionController.java
index de7871e..8ac21e4 100644
--- a/services/core/java/com/android/server/wm/TransitionController.java
+++ b/services/core/java/com/android/server/wm/TransitionController.java
@@ -757,7 +757,7 @@
final TransitionRequestInfo request = new TransitionRequestInfo(transition.mType,
startTaskInfo, pipTaskInfo, remoteTransition, displayChange,
- transition.getFlags());
+ transition.getFlags(), transition.getSyncId());
transition.mLogger.mRequestTimeNs = SystemClock.elapsedRealtimeNanos();
transition.mLogger.mRequest = request;
@@ -1592,8 +1592,8 @@
TransitionInfo mInfo;
private String buildOnSendLog() {
- StringBuilder sb = new StringBuilder("Sent Transition #").append(mSyncId)
- .append(" createdAt=").append(TimeUtils.logTimeOfDay(mCreateWallTimeMs));
+ StringBuilder sb = new StringBuilder("Sent Transition (#").append(mSyncId)
+ .append(") createdAt=").append(TimeUtils.logTimeOfDay(mCreateWallTimeMs));
if (mRequest != null) {
sb.append(" via request=").append(mRequest);
}
@@ -1617,7 +1617,8 @@
void logOnSend() {
ProtoLog.v(ProtoLogGroup.WM_DEBUG_WINDOW_TRANSITIONS_MIN, "%s", buildOnSendLog());
ProtoLog.v(ProtoLogGroup.WM_DEBUG_WINDOW_TRANSITIONS_MIN, " startWCT=%s", mStartWCT);
- ProtoLog.v(ProtoLogGroup.WM_DEBUG_WINDOW_TRANSITIONS_MIN, " info=%s", mInfo);
+ ProtoLog.v(ProtoLogGroup.WM_DEBUG_WINDOW_TRANSITIONS_MIN, " info=%s",
+ mInfo.toString(" " /* prefix */));
}
private static String toMsString(long nanos) {
@@ -1625,8 +1626,8 @@
}
private String buildOnFinishLog() {
- StringBuilder sb = new StringBuilder("Finish Transition #").append(mSyncId)
- .append(": created at ").append(TimeUtils.logTimeOfDay(mCreateWallTimeMs));
+ StringBuilder sb = new StringBuilder("Finish Transition (#").append(mSyncId)
+ .append("): created at ").append(TimeUtils.logTimeOfDay(mCreateWallTimeMs));
sb.append(" collect-started=").append(toMsString(mCollectTimeNs - mCreateTimeNs));
if (mRequestTimeNs != 0) {
sb.append(" request-sent=").append(toMsString(mRequestTimeNs - mCreateTimeNs));