Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 5f74853b authored by Winson Chung's avatar Winson Chung
Browse files

Update some more logs 

- Add WCT activity starts under the existing start-activity debug prop
- And add a prop for debugging where shell transitions are requested as
  well
- Update the transitions dump to list handlers in dispatch order
- Add a transition log for which handle handles a request

Bug: 378565144
Flag: EXEMPT adding logs
Test: adb shell setprop persist.wm.debug.start_shell_transition true
      adb logcat -s "ShellTransitions"
Change-Id: I255922f87cf526687f1b639fa8a8b7cc13dc0c78
parent 4d2a2953

core/java/android/app/Instrumentation.java

+9 −3
Original line number Diff line number Diff line
@@ -101,14 +101,20 @@ public class Instrumentation { 
     */

    public static final String REPORT_KEY_STREAMRESULT = "stream";



    static final String TAG = "Instrumentation";

    /**

     * @hide

     */

    public static final String TAG = "Instrumentation";



    private static final long CONNECT_TIMEOUT_MILLIS = 60_000;



    private static final boolean VERBOSE = Log.isLoggable(TAG, Log.VERBOSE);



    // If set, will print the stack trace for activity starts within the process

    static final boolean DEBUG_START_ACTIVITY = Build.IS_DEBUGGABLE &&

    /**

     * If set, will print the stack trace for activity starts within the process

     * @hide

     */

    public static final boolean DEBUG_START_ACTIVITY = Build.IS_DEBUGGABLE &&

            SystemProperties.getBoolean("persist.wm.debug.start_activity", false);

    static final boolean DEBUG_FINISH_ACTIVITY = Build.IS_DEBUGGABLE &&

            SystemProperties.getBoolean("persist.wm.debug.finish_activity", false);

core/java/android/window/WindowContainerTransaction.java

+17 −2
Original line number Diff line number Diff line
@@ -16,6 +16,7 @@ 


package android.window;



import static android.app.Instrumentation.DEBUG_START_ACTIVITY;

import static android.app.WindowConfiguration.WINDOWING_MODE_UNDEFINED;

import static android.window.TaskFragmentOperation.OP_TYPE_CLEAR_ADJACENT_TASK_FRAGMENTS;

import static android.window.TaskFragmentOperation.OP_TYPE_CREATE_TASK_FRAGMENT;
@@ -32,6 +33,7 @@ import android.annotation.NonNull; 
import android.annotation.Nullable;

import android.annotation.SuppressLint;

import android.annotation.TestApi;

import android.app.Instrumentation;

import android.app.PendingIntent;

import android.app.WindowConfiguration;

import android.app.WindowConfiguration.WindowingMode;
@@ -45,6 +47,7 @@ import android.os.IBinder; 
import android.os.Parcel;

import android.os.Parcelable;

import android.util.ArrayMap;

import android.util.Log;

import android.view.InsetsFrameProvider;

import android.view.InsetsSource;

import android.view.SurfaceControl;
@@ -621,6 +624,10 @@ public final class WindowContainerTransaction implements Parcelable { 
     */

    @NonNull

    public WindowContainerTransaction startTask(int taskId, @Nullable Bundle options) {

        if (DEBUG_START_ACTIVITY) {

            Log.d(Instrumentation.TAG, "WCT.startTask: taskId=" + taskId

                    + " options=" + options, new Throwable());

        }

        mHierarchyOps.add(HierarchyOp.createForTaskLaunch(taskId, options));

        return this;

    }
@@ -634,11 +641,15 @@ public final class WindowContainerTransaction implements Parcelable { 
     */

    @NonNull

    public WindowContainerTransaction sendPendingIntent(@Nullable PendingIntent sender,

            @Nullable Intent intent, @Nullable Bundle options) {

            @Nullable Intent fillInIntent, @Nullable Bundle options) {

        if (DEBUG_START_ACTIVITY) {

            Log.d(Instrumentation.TAG, "WCT.sendPendingIntent: sender=" + sender.getIntent()

                    + " fillInIntent=" + fillInIntent + " options=" + options, new Throwable());

        }

        mHierarchyOps.add(new HierarchyOp.Builder(HierarchyOp.HIERARCHY_OP_TYPE_PENDING_INTENT)

                .setLaunchOptions(options)

                .setPendingIntent(sender)

                .setActivityIntent(intent)

                .setActivityIntent(fillInIntent)

                .build());

        return this;

    }
@@ -653,6 +664,10 @@ public final class WindowContainerTransaction implements Parcelable { 
    @NonNull

    public WindowContainerTransaction startShortcut(@NonNull String callingPackage,

            @NonNull ShortcutInfo shortcutInfo, @Nullable Bundle options) {

        if (DEBUG_START_ACTIVITY) {

            Log.d(Instrumentation.TAG, "WCT.startShortcut: shortcutInfo=" + shortcutInfo

                    + " options=" + options, new Throwable());

        }

        mHierarchyOps.add(HierarchyOp.createForStartShortcut(

                callingPackage, shortcutInfo, options));

        return this;

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

+17 −2
Original line number Diff line number Diff line
@@ -142,8 +142,8 @@ transaction which is applied. 
## Tracing activity starts & finishes 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

(ie. if you are repro'ing a bug related to activity starts). You can enable this system property to

get this trace:

or via a `WindowContainerTransaction` (ie. if you are repro'ing a bug related to activity starts).

You can enable this system property to get this trace:

```shell

# Enabling

adb shell setprop persist.wm.debug.start_activity true
@@ -168,6 +168,21 @@ adb shell setprop persist.wm.debug.finish_activity \"\" 
adb reboot

```



## Tracing transition requests in the Shell



To trace where a new WM transition is started in the Shell, you can enable this system property:

```shell

# Enabling

adb shell setprop persist.wm.debug.start_shell_transition true

adb reboot

adb logcat -s "ShellTransitions"



# Disabling

adb shell setprop persist.wm.debug.start_shell_transition \"\"

adb reboot

```





## Dumps



Because the Shell library is built as a part of SystemUI, dumping the state is currently done as a

libs/WindowManager/Shell/src/com/android/wm/shell/transition/Transitions.java

+36 −23
Original line number Diff line number Diff line
@@ -39,6 +39,7 @@ import static android.window.TransitionInfo.FLAG_STARTING_WINDOW_TRANSFER_RECIPI 


import static com.android.systemui.shared.Flags.returnAnimationFrameworkLongLived;

import static com.android.window.flags.Flags.ensureWallpaperInTransitions;

import static com.android.wm.shell.protolog.ShellProtoLogGroup.WM_SHELL_TRANSITIONS;

import static com.android.wm.shell.shared.TransitionUtil.FLAG_IS_DESKTOP_WALLPAPER_ACTIVITY;

import static com.android.wm.shell.shared.TransitionUtil.isClosingType;

import static com.android.wm.shell.shared.TransitionUtil.isOpeningType;
@@ -52,6 +53,7 @@ import android.content.ContentResolver; 
import android.content.Context;

import android.content.pm.PackageManager;

import android.database.ContentObserver;

import android.os.Build;

import android.os.Handler;

import android.os.IBinder;

import android.os.RemoteException;
@@ -138,6 +140,10 @@ public class Transitions implements RemoteCallable<Transitions>, 
        ShellCommandHandler.ShellCommandActionHandler {

    static final String TAG = "ShellTransitions";



    // If set, will print the stack trace for transition starts within the process

    static final boolean DEBUG_START_TRANSITION = Build.IS_DEBUGGABLE &&

            SystemProperties.getBoolean("persist.wm.debug.start_shell_transition", false);



    /** Set to {@code true} to enable shell transitions. */

    public static final boolean ENABLE_SHELL_TRANSITIONS = getShellTransitEnabled();

    public static final boolean SHELL_TRANSITIONS_ROTATION = ENABLE_SHELL_TRANSITIONS
@@ -346,10 +352,10 @@ public class Transitions implements RemoteCallable<Transitions>, 
        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");

        ProtoLog.v(WM_SHELL_TRANSITIONS, "addHandler: Default");

        // Next lowest priority is remote transitions.

        mHandlers.add(mRemoteTransitionHandler);

        ProtoLog.v(ShellProtoLogGroup.WM_SHELL_TRANSITIONS, "addHandler: Remote");

        ProtoLog.v(WM_SHELL_TRANSITIONS, "addHandler: Remote");

        shellInit.addInitCallback(this::onInit, this);

        mHomeTransitionObserver = homeTransitionObserver;

        mFocusTransitionObserver = focusTransitionObserver;
@@ -439,7 +445,7 @@ public class Transitions implements RemoteCallable<Transitions>, 
        mHandlers.add(handler);

        // Set initial scale settings.

        handler.setAnimScaleSetting(mTransitionAnimationScaleSetting);

        ProtoLog.v(ShellProtoLogGroup.WM_SHELL_TRANSITIONS, "addHandler: %s",

        ProtoLog.v(WM_SHELL_TRANSITIONS, "addHandler: %s",

                handler.getClass().getSimpleName());

    }
@@ -691,7 +697,7 @@ public class Transitions implements RemoteCallable<Transitions>, 
    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 (#%d) %s: %s",

        ProtoLog.v(WM_SHELL_TRANSITIONS, "onTransitionReady (#%d) %s: %s",

                info.getDebugId(), transitionToken, info.toString("    " /* prefix */));

        int activeIdx = findByToken(mPendingTransitions, transitionToken);

        if (activeIdx < 0) {
@@ -753,7 +759,7 @@ public class Transitions implements RemoteCallable<Transitions>, 
                if (tr.isIdle()) continue;

                hadPreceding = true;

                // Sleep starts a process of forcing all prior transitions to finish immediately

                ProtoLog.v(ShellProtoLogGroup.WM_SHELL_TRANSITIONS,

                ProtoLog.v(WM_SHELL_TRANSITIONS,

                        "Start finish-for-sync track %d", i);

                finishForSync(active.mToken, i, null /* forceFinish */);

            }
@@ -797,7 +803,7 @@ public class Transitions implements RemoteCallable<Transitions>, 
        if (info.getRootCount() == 0 && !KeyguardTransitionHandler.handles(info)) {

            // No root-leashes implies that the transition is empty/no-op, so just do

            // housekeeping and return.

            ProtoLog.v(ShellProtoLogGroup.WM_SHELL_TRANSITIONS, "No transition roots in %s so"

            ProtoLog.v(WM_SHELL_TRANSITIONS, "No transition roots in %s so"

                    + " abort", active);

            onAbort(active);

            return true;
@@ -839,7 +845,7 @@ public class Transitions implements RemoteCallable<Transitions>, 
                && allOccluded)) {

            // Treat this as an abort since we are bypassing any merge logic and effectively

            // finishing immediately.

            ProtoLog.v(ShellProtoLogGroup.WM_SHELL_TRANSITIONS,

            ProtoLog.v(WM_SHELL_TRANSITIONS,

                    "Non-visible anim so abort: %s", active);

            onAbort(active);

            return true;
@@ -873,7 +879,7 @@ public class Transitions implements RemoteCallable<Transitions>, 
    void processReadyQueue(Track track) {

        if (track.mReadyTransitions.isEmpty()) {

            if (track.mActiveTransition == null) {

                ProtoLog.v(ShellProtoLogGroup.WM_SHELL_TRANSITIONS, "Track %d became idle",

                ProtoLog.v(WM_SHELL_TRANSITIONS, "Track %d became idle",

                        mTracks.indexOf(track));

                if (areTracksIdle()) {

                    if (!mReadyDuringSync.isEmpty()) {
@@ -885,7 +891,7 @@ public class Transitions implements RemoteCallable<Transitions>, 
                            if (!success) break;

                        }

                    } else if (mPendingTransitions.isEmpty()) {

                        ProtoLog.v(ShellProtoLogGroup.WM_SHELL_TRANSITIONS, "All active transition "

                        ProtoLog.v(WM_SHELL_TRANSITIONS, "All active transition "

                                + "animations finished");

                        mKnownTransitions.clear();

                        // Run all runnables from the run-when-idle queue.
@@ -926,7 +932,7 @@ public class Transitions implements RemoteCallable<Transitions>, 
            onMerged(playingToken, readyToken);

            return;

        }

        ProtoLog.v(ShellProtoLogGroup.WM_SHELL_TRANSITIONS, "Transition %s ready while"

        ProtoLog.v(WM_SHELL_TRANSITIONS, "Transition %s ready while"

                + " %s is still animating. Notify the animating transition"

                + " in case they can be merged", ready, playing);

        mTransitionTracer.logMergeRequested(ready.mInfo.getDebugId(), playing.mInfo.getDebugId());
@@ -955,7 +961,7 @@ public class Transitions implements RemoteCallable<Transitions>, 
        }



        final Track track = mTracks.get(playing.getTrack());

        ProtoLog.v(ShellProtoLogGroup.WM_SHELL_TRANSITIONS, "Transition was merged: %s into %s",

        ProtoLog.v(WM_SHELL_TRANSITIONS, "Transition was merged: %s into %s",

                merged, playing);

        int readyIdx = 0;

        if (track.mReadyTransitions.isEmpty() || track.mReadyTransitions.get(0) != merged) {
@@ -996,7 +1002,7 @@ public class Transitions implements RemoteCallable<Transitions>, 
    }



    private void playTransition(@NonNull ActiveTransition active) {

        ProtoLog.v(ShellProtoLogGroup.WM_SHELL_TRANSITIONS, "Playing animation for %s", active);

        ProtoLog.v(WM_SHELL_TRANSITIONS, "Playing animation for %s", active);

        final var token = active.mToken;



        for (int i = 0; i < mObservers.size(); ++i) {
@@ -1007,12 +1013,12 @@ public class Transitions implements RemoteCallable<Transitions>, 


        // If a handler already chose to run this animation, try delegating to it first.

        if (active.mHandler != null) {

            ProtoLog.v(ShellProtoLogGroup.WM_SHELL_TRANSITIONS, " try firstHandler %s",

            ProtoLog.v(WM_SHELL_TRANSITIONS, " try firstHandler %s",

                    active.mHandler);

            boolean consumed = active.mHandler.startAnimation(token, active.mInfo,

                    active.mStartT, active.mFinishT, (wct) -> onFinish(token, wct));

            if (consumed) {

                ProtoLog.v(ShellProtoLogGroup.WM_SHELL_TRANSITIONS, " animated by firstHandler");

                ProtoLog.v(WM_SHELL_TRANSITIONS, " animated by firstHandler");

                mTransitionTracer.logDispatched(active.mInfo.getDebugId(), active.mHandler);

                if (Trace.isTagEnabled(TRACE_TAG_WINDOW_MANAGER)) {

                    Trace.instant(TRACE_TAG_WINDOW_MANAGER,
@@ -1042,14 +1048,14 @@ public class Transitions implements RemoteCallable<Transitions>, 
    ) {

        for (int i = mHandlers.size() - 1; i >= 0; --i) {

            if (mHandlers.get(i) == skip) {

                ProtoLog.v(ShellProtoLogGroup.WM_SHELL_TRANSITIONS, " skip handler %s",

                ProtoLog.v(WM_SHELL_TRANSITIONS, " skip handler %s",

                        mHandlers.get(i));

                continue;

            }

            boolean consumed = mHandlers.get(i).startAnimation(transition, info, startT, finishT,

                    finishCB);

            if (consumed) {

                ProtoLog.v(ShellProtoLogGroup.WM_SHELL_TRANSITIONS, " animated by %s",

                ProtoLog.v(WM_SHELL_TRANSITIONS, " animated by %s",

                        mHandlers.get(i));

                mTransitionTracer.logDispatched(info.getDebugId(), mHandlers.get(i));

                if (Trace.isTagEnabled(TRACE_TAG_WINDOW_MANAGER)) {
@@ -1155,7 +1161,7 @@ public class Transitions implements RemoteCallable<Transitions>, 
        for (int i = 0; i < mObservers.size(); ++i) {

            mObservers.get(i).onTransitionFinished(active.mToken, active.mAborted);

        }

        ProtoLog.v(ShellProtoLogGroup.WM_SHELL_TRANSITIONS, "Transition animation finished "

        ProtoLog.v(WM_SHELL_TRANSITIONS, "Transition animation finished "

                + "(aborted=%b), notifying core %s", active.mAborted, active);

        if (active.mStartT != null) {

            // Applied by now, so clear immediately to remove any references. Do not set to null
@@ -1209,7 +1215,7 @@ public class Transitions implements RemoteCallable<Transitions>, 


    void requestStartTransition(@NonNull IBinder transitionToken,

            @Nullable TransitionRequestInfo request) {

        ProtoLog.v(ShellProtoLogGroup.WM_SHELL_TRANSITIONS, "Transition requested (#%d): %s %s",

        ProtoLog.v(WM_SHELL_TRANSITIONS, "Transition requested (#%d): %s %s",

                request.getDebugId(), transitionToken, request);

        if (mKnownTransitions.containsKey(transitionToken)) {

            throw new RuntimeException("Transition already started " + transitionToken);
@@ -1228,6 +1234,8 @@ public class Transitions implements RemoteCallable<Transitions>, 
            if (requestResult != null) {

                active.mHandler = requestResult.first;

                wct = requestResult.second;

                ProtoLog.v(WM_SHELL_TRANSITIONS, "Transition (#%d): request handled by %s",

                        request.getDebugId(), active.mHandler.getClass().getSimpleName());

            }

            if (request.getDisplayChange() != null) {

                TransitionRequestInfo.DisplayChange change = request.getDisplayChange();
@@ -1273,8 +1281,12 @@ public class Transitions implements RemoteCallable<Transitions>, 
     */

    public IBinder startTransition(@WindowManager.TransitionType int type,

            @NonNull WindowContainerTransaction wct, @Nullable TransitionHandler handler) {

        ProtoLog.v(ShellProtoLogGroup.WM_SHELL_TRANSITIONS, "Directly starting a new transition "

        ProtoLog.v(WM_SHELL_TRANSITIONS, "Directly starting a new transition "

                + "type=%s wct=%s handler=%s", transitTypeToString(type), wct, handler);

        if (DEBUG_START_TRANSITION) {

            Log.d(TAG, "startTransition: type=" + transitTypeToString(type)

                    + " wct=" + wct + " handler=" + handler.getClass().getName(), new Throwable());

        }

        final ActiveTransition active =

                new ActiveTransition(mOrganizer.startNewTransition(type, wct));

        active.mHandler = handler;
@@ -1362,7 +1374,7 @@ public class Transitions implements RemoteCallable<Transitions>, 
            }

            // Attempt to merge a SLEEP info to signal that the playing transition needs to

            // fast-forward.

            ProtoLog.v(ShellProtoLogGroup.WM_SHELL_TRANSITIONS, " Attempt to merge sync %s"

            ProtoLog.v(WM_SHELL_TRANSITIONS, " Attempt to merge sync %s"

                    + " into %s via a SLEEP proxy", nextSync, playing);

            playing.mHandler.mergeAnimation(nextSync.mToken, dummyInfo, dummyT, dummyT,

                    playing.mToken, (wct) -> {});
@@ -1598,7 +1610,7 @@ public class Transitions implements RemoteCallable<Transitions>, 
        public void onTransitionReady(IBinder iBinder, TransitionInfo transitionInfo,

                SurfaceControl.Transaction t, SurfaceControl.Transaction finishT)

                throws RemoteException {

            ProtoLog.v(ShellProtoLogGroup.WM_SHELL_TRANSITIONS, "onTransitionReady(transaction=%d)",

            ProtoLog.v(WM_SHELL_TRANSITIONS, "onTransitionReady(transaction=%d)",

                    t.getId());

            mMainExecutor.execute(() -> Transitions.this.onTransitionReady(

                    iBinder, transitionInfo, t, finishT));
@@ -1784,8 +1796,9 @@ public class Transitions implements RemoteCallable<Transitions>, 
        pw.println(prefix + TAG);



        final String innerPrefix = prefix + "  ";

        pw.println(prefix + "Handlers:");

        for (TransitionHandler handler : mHandlers) {

        pw.println(prefix + "Handlers (ordered by priority):");

        for (int i = mHandlers.size() - 1; i >= 0; i--) {

            final TransitionHandler handler = mHandlers.get(i);

            pw.print(innerPrefix);

            pw.print(handler.getClass().getSimpleName());

            pw.println(" (" + Integer.toHexString(System.identityHashCode(handler)) + ")");