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

Commit fad425f2 authored by Winson Chung's avatar Winson Chung
Browse files

Add additional logs for blast sync timeout 

- Add more logs to identify whether the sync timeout is due to Shell
  not receiving the ready event, Shell not handling the ready event,
  or system not handling the callback

Bug: 328109064
Test: Just adding logs
Change-Id: I8c318e8388065d0650577cc792f16882586a1d1b
parent 91a2c2fc

libs/WindowManager/Shell/src/com/android/wm/shell/common/SyncTransactionQueue.java

+6 −0
Original line number Diff line number Diff line
@@ -16,6 +16,8 @@ 


package com.android.wm.shell.common;



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



import android.annotation.BinderThread;

import android.annotation.NonNull;

import android.os.RemoteException;
@@ -26,6 +28,7 @@ import android.window.WindowContainerTransaction; 
import android.window.WindowContainerTransactionCallback;

import android.window.WindowOrganizer;



import com.android.internal.protolog.common.ProtoLog;

import com.android.wm.shell.transition.LegacyTransitions;



import java.util.ArrayList;
@@ -204,6 +207,7 @@ public final class SyncTransactionQueue { 
        @Override

        public void onTransactionReady(int id,

                @NonNull SurfaceControl.Transaction t) {

            ProtoLog.v(WM_SHELL, "SyncTransactionQueue.onTransactionReady(): syncId=%d", id);

            mMainExecutor.execute(() -> {

                synchronized (mQueue) {

                    if (mId != id) {
@@ -223,6 +227,8 @@ public final class SyncTransactionQueue { 
                            Slog.e(TAG, "Error sending callback to legacy transition: " + mId, e);

                        }

                    } else {

                        ProtoLog.v(WM_SHELL,

                                "SyncTransactionQueue.onTransactionReady(): syncId=%d apply", id);

                        t.apply();

                        t.close();

                    }

libs/WindowManager/Shell/src/com/android/wm/shell/recents/RecentsTransitionHandler.java

+4 −0
Original line number Diff line number Diff line
@@ -418,6 +418,8 @@ public class RecentsTransitionHandler implements Transitions.TransitionHandler { 
            ProtoLog.v(ShellProtoLogGroup.WM_SHELL_RECENTS_TRANSITION,

                    "[%d] RecentsController.start", mInstanceId);

            if (mListener == null || mTransition == null) {

                Slog.e(TAG, "Missing listener or transition, hasListener=" + (mListener != null) +

                        " hasTransition=" + (mTransition != null));

                cleanUp();

                return false;

            }
@@ -539,6 +541,8 @@ public class RecentsTransitionHandler implements Transitions.TransitionHandler { 
                    apps.add(target);

                }

            }

            ProtoLog.v(ShellProtoLogGroup.WM_SHELL_RECENTS_TRANSITION,

                    "Applying transaction=%d", t.getId());

            t.apply();

            Bundle b = new Bundle(1 /*capacity*/);

            b.putParcelable(KEY_EXTRA_SPLIT_BOUNDS,

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

+20 −5
Original line number Diff line number Diff line
@@ -16,6 +16,8 @@ 


package com.android.wm.shell.transition;



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



import android.annotation.NonNull;

import android.os.RemoteException;

import android.view.IRemoteAnimationFinishedCallback;
@@ -26,6 +28,8 @@ import android.view.SurfaceControl; 
import android.view.WindowManager;

import android.window.IWindowContainerTransactionCallback;



import com.android.internal.protolog.common.ProtoLog;



/**

 * Utilities and interfaces for transition-like usage on top of the legacy app-transition and

 * synctransaction tools.
@@ -87,9 +91,11 @@ public class LegacyTransitions { 
            @Override

            public void onTransactionReady(int id, SurfaceControl.Transaction t)

                    throws RemoteException {

                ProtoLog.v(WM_SHELL_TRANSITIONS,

                        "LegacyTransitions.onTransactionReady(): syncId=%d", id);

                mSyncId = id;

                mTransaction = t;

                checkApply();

                checkApply(true /* log */);

            }

        }
@@ -103,20 +109,29 @@ public class LegacyTransitions { 
                mWallpapers = wallpapers;

                mNonApps = nonApps;

                mFinishCallback = finishedCallback;

                checkApply();

                checkApply(false /* log */);

            }



            @Override

            public void onAnimationCancelled() throws RemoteException {

                mCancelled = true;

                mApps = mWallpapers = mNonApps = null;

                checkApply();

                checkApply(false /* log */);

            }

        }





        private void checkApply() throws RemoteException {

            if (mSyncId < 0 || (mFinishCallback == null && !mCancelled)) return;

        private void checkApply(boolean log) throws RemoteException {

            if (mSyncId < 0 || (mFinishCallback == null && !mCancelled)) {

                if (log) {

                    ProtoLog.v(WM_SHELL_TRANSITIONS, "\tSkipping hasFinishedCb=%b canceled=%b",

                            mFinishCallback != null, mCancelled);

                }

                return;

            }

            if (log) {

                ProtoLog.v(WM_SHELL_TRANSITIONS, "\tapply");

            }

            mLegacyTransition.onAnimationStart(mTransit, mApps, mWallpapers,

                    mNonApps, mFinishCallback, mTransaction);

        }

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

+2 −0
Original line number Diff line number Diff line
@@ -1409,6 +1409,8 @@ 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)",

                    t.getId());

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

                    iBinder, transitionInfo, t, finishT));

        }

services/core/java/com/android/server/wm/BLASTSyncEngine.java

+11 −3
Original line number Diff line number Diff line
@@ -116,6 +116,7 @@ class BLASTSyncEngine { 
     */

    class SyncGroup {

        final int mSyncId;

        final String mSyncName;

        int mSyncMethod = METHOD_BLAST;

        final TransactionReadyListener mListener;

        final Runnable mOnTimeout;
@@ -138,6 +139,7 @@ class BLASTSyncEngine { 


        private SyncGroup(TransactionReadyListener listener, int id, String name) {

            mSyncId = id;

            mSyncName = name;

            mListener = listener;

            mOnTimeout = () -> {

                Slog.w(TAG, "Sync group " + mSyncId + " timeout");
@@ -221,15 +223,20 @@ class BLASTSyncEngine { 
            for (WindowContainer wc : mRootMembers) {

                wc.waitForSyncTransactionCommit(wcAwaitingCommit);

            }



            final int syncId = mSyncId;

            final long mergedTxId = merged.getId();

            final String syncName = mSyncName;

            class CommitCallback implements Runnable {

                // Can run a second time if the action completes after the timeout.

                boolean ran = false;

                public void onCommitted(SurfaceControl.Transaction t) {

                    // Don't wait to hold the global lock to remove the timeout runnable

                    mHandler.removeCallbacks(this);

                    synchronized (mWm.mGlobalLock) {

                        if (ran) {

                            return;

                        }

                        mHandler.removeCallbacks(this);

                        ran = true;

                        for (WindowContainer wc : wcAwaitingCommit) {

                            wc.onSyncTransactionCommitted(t);
@@ -246,8 +253,9 @@ class BLASTSyncEngine { 
                    // a trace. Since these kind of ANRs can trigger such an issue,

                    // try and ensure we will have some visibility in both cases.

                    Trace.traceBegin(TRACE_TAG_WINDOW_MANAGER, "onTransactionCommitTimeout");

                    Slog.e(TAG, "WM sent Transaction to organized, but never received" +

                           " commit callback. Application ANR likely to follow.");

                    Slog.e(TAG, "WM sent Transaction (#" + syncId + ", " + syncName + ", tx="

                            + mergedTxId + ") to organizer, but never received commit callback."

                            + " Application ANR likely to follow.");

                    Trace.traceEnd(TRACE_TAG_WINDOW_MANAGER);

                    synchronized (mWm.mGlobalLock) {

                        mListener.onTransactionCommitTimeout();