Add some client side logging for interrupted draws to the dump

In particular, these are to try and narrow down why the app window isn't
drawing in b/235463625 where the draw state for launcher is stuck in
DRAW_PENDING.

- mLastReportNextDrawReason: the reason the last draw was requested,
  maybe useful in telling if wm is not requesting a draw if not set
- mLastPerformTraversalsSkipDrawReason: the reason perform traversals
  returned without drawing (includes wm/predraw cancel reasons)
- mLastPerformDrawSkippedReason: the reason perform draw returned
  without drawing
- mLocalSyncState: extra logging to confirm that the last sync actually
  completes

Bug: 235463625
Test: dumpsys -T 60000 activity -v all
Test: dumpsys activity activities
Change-Id: I10118470fe62075920e9ce29fe449b0cfc8570c9
Merged-In: I10118470fe62075920e9ce29fe449b0cfc8570c9

3 files changed, 79 insertions, 11 deletions

diff --git a/core/java/android/view/SurfaceControlViewHost.java b/core/java/android/view/SurfaceControlViewHost.java
index d75ff2fc7dc2..5721fa6dd11a 100644
--- a/core/java/android/view/SurfaceControlViewHost.java
+++ b/core/java/android/view/SurfaceControlViewHost.java
@@ -422,7 +422,7 @@ public class SurfaceControlViewHost {
     public void relayout(WindowManager.LayoutParams attrs,
             WindowlessWindowManager.ResizeCompleteCallback callback) {
         mViewRoot.setLayoutParams(attrs, false);
-        mViewRoot.setReportNextDraw(true /* syncBuffer */);
+        mViewRoot.setReportNextDraw(true /* syncBuffer */, "scvh_relayout");
         mWm.setCompletionCallback(mViewRoot.mWindow.asBinder(), callback);
     }
 
diff --git a/core/java/android/view/ViewRootImpl.java b/core/java/android/view/ViewRootImpl.java
index 7690af693148..500d92b0831b 100644
--- a/core/java/android/view/ViewRootImpl.java
+++ b/core/java/android/view/ViewRootImpl.java
@@ -586,8 +586,21 @@ public final class ViewRootImpl implements ViewParent,
     int mContentCaptureEnabled = CONTENT_CAPTURE_ENABLED_NOT_CHECKED;
     boolean mPerformContentCapture;
 
-
     boolean mReportNextDraw;
+    /** Set only while mReportNextDraw=true, indicating the last reason that was triggered */
+    String mLastReportNextDrawReason;
+    /** The reaason the last call to performDraw() returned false */
+    String mLastPerformDrawSkippedReason;
+    /** The reason the last call to performTraversals() returned without drawing */
+    String mLastPerformTraversalsSkipDrawReason;
+    /** The state of the local sync, if one is in progress. Can be one of the states below. */
+    int mLocalSyncState;
+
+    // The possible states of the local sync, see createSyncIfNeeded()
+    private final int LOCAL_SYNC_NONE = 0;
+    private final int LOCAL_SYNC_PENDING = 1;
+    private final int LOCAL_SYNC_RETURNED = 2;
+    private final int LOCAL_SYNC_MERGED = 3;
 
     /**
      * Set whether the draw should send the buffer to system server. When set to true, VRI will
@@ -1811,7 +1824,7 @@ public final class ViewRootImpl implements ViewParent,
         mSyncSeqId = args.argi4 > mSyncSeqId ? args.argi4 : mSyncSeqId;
 
         if (msg == MSG_RESIZED_REPORT) {
-            reportNextDraw();
+            reportNextDraw("resized");
         }
 
         if (mView != null && (frameChanged || configChanged)) {
@@ -2716,6 +2729,8 @@ public final class ViewRootImpl implements ViewParent,
     }
 
     private void performTraversals() {
+        mLastPerformTraversalsSkipDrawReason = null;
+
         // cache mView since it is used so much below...
         final View host = mView;
         if (DBG) {
@@ -2725,12 +2740,14 @@ public final class ViewRootImpl implements ViewParent,
         }
 
         if (host == null || !mAdded) {
+            mLastPerformTraversalsSkipDrawReason = host == null ? "no_host" : "not_added";
             return;
         }
 
         mIsInTraversal = true;
         mWillDrawSoon = true;
         boolean cancelDraw = false;
+        String cancelReason = null;
         boolean isSyncRequest = false;
 
         boolean windowSizeMayChange = false;
@@ -3013,13 +3030,14 @@ public final class ViewRootImpl implements ViewParent,
                 relayoutResult = relayoutWindow(params, viewVisibility, insetsPending);
                 cancelDraw = (relayoutResult & RELAYOUT_RES_CANCEL_AND_REDRAW)
                         == RELAYOUT_RES_CANCEL_AND_REDRAW;
+                cancelReason = "relayout";
                 final boolean dragResizing = mPendingDragResizing;
                 if (mSyncSeqId > mLastSyncSeqId) {
                     mLastSyncSeqId = mSyncSeqId;
                     if (DEBUG_BLAST) {
                         Log.d(mTag, "Relayout called with blastSync");
                     }
-                    reportNextDraw();
+                    reportNextDraw("relayout");
                     mSyncBuffer = true;
                     isSyncRequest = true;
                     if (!cancelDraw) {
@@ -3117,6 +3135,7 @@ public final class ViewRootImpl implements ViewParent,
                             }
                         } catch (OutOfResourcesException e) {
                             handleOutOfResourcesException(e);
+                            mLastPerformTraversalsSkipDrawReason = "oom_initialize_renderer";
                             return;
                         }
                     }
@@ -3154,6 +3173,7 @@ public final class ViewRootImpl implements ViewParent,
                         mAttachInfo.mThreadedRenderer.updateSurface(mSurface);
                     } catch (OutOfResourcesException e) {
                         handleOutOfResourcesException(e);
+                        mLastPerformTraversalsSkipDrawReason = "oom_update_surface";
                         return;
                     }
                 }
@@ -3319,6 +3339,7 @@ public final class ViewRootImpl implements ViewParent,
             if (mCheckIfCanDraw) {
                 try {
                     cancelDraw = mWindowSession.cancelDraw(mWindow);
+                    cancelReason = "wm_sync";
                     if (DEBUG_BLAST) {
                         Log.d(mTag, "cancelDraw returned " + cancelDraw);
                     }
@@ -3541,19 +3562,21 @@ public final class ViewRootImpl implements ViewParent,
         mImeFocusController.onTraversal(hasWindowFocus, mWindowAttributes);
 
         if ((relayoutResult & WindowManagerGlobal.RELAYOUT_RES_FIRST_TIME) != 0) {
-            reportNextDraw();
+            reportNextDraw("first_relayout");
         }
 
         mCheckIfCanDraw = isSyncRequest || cancelDraw;
 
-        boolean cancelAndRedraw =
-                mAttachInfo.mTreeObserver.dispatchOnPreDraw() || (cancelDraw && mDrewOnceForSync);
+        boolean cancelDueToPreDrawListener = mAttachInfo.mTreeObserver.dispatchOnPreDraw();
+        boolean cancelAndRedraw = cancelDueToPreDrawListener
+                 || (cancelDraw && mDrewOnceForSync);
         if (!cancelAndRedraw) {
             createSyncIfNeeded();
             mDrewOnceForSync = true;
         }
 
         if (!isViewVisible) {
+            mLastPerformTraversalsSkipDrawReason = "view_not_visible";
             if (mPendingTransitions != null && mPendingTransitions.size() > 0) {
                 for (int i = 0; i < mPendingTransitions.size(); ++i) {
                     mPendingTransitions.get(i).endChangingAnimations();
@@ -3565,6 +3588,9 @@ public final class ViewRootImpl implements ViewParent,
                 mSyncBufferCallback.onBufferReady(null);
             }
         } else if (cancelAndRedraw) {
+            mLastPerformTraversalsSkipDrawReason = cancelDueToPreDrawListener
+                ? "predraw_" + mAttachInfo.mTreeObserver.getLastDispatchOnPreDrawCanceledReason()
+                : "cancel_" + cancelReason;
             // Try again
             scheduleTraversals();
         } else {
@@ -3588,11 +3614,13 @@ public final class ViewRootImpl implements ViewParent,
 
         if (!cancelAndRedraw) {
             mReportNextDraw = false;
+            mLastReportNextDrawReason = null;
             mSyncBufferCallback = null;
             mSyncBuffer = false;
             if (isInLocalSync()) {
                 mSurfaceSyncer.markSyncReady(mSyncId);
                 mSyncId = UNSET_SYNC_ID;
+                mLocalSyncState = LOCAL_SYNC_NONE;
             }
         }
     }
@@ -3604,9 +3632,12 @@ public final class ViewRootImpl implements ViewParent,
         }
 
         final int seqId = mSyncSeqId;
+        mLocalSyncState = LOCAL_SYNC_PENDING;
         mSyncId = mSurfaceSyncer.setupSync(transaction -> {
+            mLocalSyncState = LOCAL_SYNC_RETURNED;
             // Callback will be invoked on executor thread so post to main thread.
             mHandler.postAtFrontOfQueue(() -> {
+                mLocalSyncState = LOCAL_SYNC_MERGED;
                 mSurfaceChangedTransaction.merge(transaction);
                 reportDrawFinished(seqId);
             });
@@ -4321,9 +4352,12 @@ public final class ViewRootImpl implements ViewParent,
     }
 
     private boolean performDraw() {
+        mLastPerformDrawSkippedReason = null;
         if (mAttachInfo.mDisplayState == Display.STATE_OFF && !mReportNextDraw) {
+            mLastPerformDrawSkippedReason = "screen_off";
             return false;
         } else if (mView == null) {
+            mLastPerformDrawSkippedReason = "no_root_view";
             return false;
         }
 
@@ -8390,6 +8424,21 @@ public final class ViewRootImpl implements ViewParent,
         if (mTraversalScheduled) {
             writer.println(innerPrefix + " (barrier=" + mTraversalBarrier + ")");
         }
+        writer.println(innerPrefix + "mReportNextDraw=" + mReportNextDraw);
+        if (mReportNextDraw) {
+            writer.println(innerPrefix + " (reason=" + mLastReportNextDrawReason + ")");
+        }
+        if (mLastPerformTraversalsSkipDrawReason != null) {
+            writer.println(innerPrefix + "mLastPerformTraversalsFailedReason="
+                + mLastPerformTraversalsSkipDrawReason);
+        }
+        if (mLastPerformDrawSkippedReason != null) {
+            writer.println(innerPrefix + "mLastPerformDrawFailedReason="
+                + mLastPerformDrawSkippedReason);
+        }
+        if (mLocalSyncState != LOCAL_SYNC_NONE) {
+            writer.println(innerPrefix + "mLocalSyncState=" + mLocalSyncState);
+        }
         writer.println(innerPrefix + "mIsAmbientMode="  + mIsAmbientMode);
         writer.println(innerPrefix + "mUnbufferedInputSource="
                 + Integer.toHexString(mUnbufferedInputSource));
@@ -9890,11 +9939,12 @@ public final class ViewRootImpl implements ViewParent,
         }
     }
 
-    private void reportNextDraw() {
+    private void reportNextDraw(String reason) {
         if (DEBUG_BLAST) {
             Log.d(mTag, "reportNextDraw " + Debug.getCallers(5));
         }
         mReportNextDraw = true;
+        mLastReportNextDrawReason = reason;
     }
 
     /**
@@ -9907,11 +9957,12 @@ public final class ViewRootImpl implements ViewParent,
      * @param syncBuffer If true, the transaction that contains the buffer from the draw should be
      *                   sent to system to be synced. If false, VRI will not try to sync the buffer,
      *                   but only report back that a buffer was drawn.
+     * @param reason A debug string indicating the reason for reporting the next draw
      * @hide
      */
-    public void setReportNextDraw(boolean syncBuffer) {
+    public void setReportNextDraw(boolean syncBuffer, String reason) {
         mSyncBuffer = syncBuffer;
-        reportNextDraw();
+        reportNextDraw(reason);
         invalidate();
     }
 
diff --git a/core/java/android/view/ViewTreeObserver.java b/core/java/android/view/ViewTreeObserver.java
index ed8350afc109..fd62ecd11e13 100644
--- a/core/java/android/view/ViewTreeObserver.java
+++ b/core/java/android/view/ViewTreeObserver.java
@@ -74,6 +74,9 @@ public final class ViewTreeObserver {
      * that the listener will be immediately called. */
     private boolean mWindowShown;
 
+    // The reason that the last call to dispatchOnPreDraw() returned true to cancel and redraw
+    private String mLastDispatchOnPreDrawCanceledReason;
+
     private boolean mAlive = true;
 
     /**
@@ -1167,6 +1170,7 @@ public final class ViewTreeObserver {
      */
     @SuppressWarnings("unchecked")
     public final boolean dispatchOnPreDraw() {
+        mLastDispatchOnPreDrawCanceledReason = null;
         boolean cancelDraw = false;
         final CopyOnWriteArray<OnPreDrawListener> listeners = mOnPreDrawListeners;
         if (listeners != null && listeners.size() > 0) {
@@ -1174,7 +1178,11 @@ public final class ViewTreeObserver {
             try {
                 int count = access.size();
                 for (int i = 0; i < count; i++) {
-                    cancelDraw |= !(access.get(i).onPreDraw());
+                    final OnPreDrawListener preDrawListener = access.get(i);
+                    cancelDraw |= !(preDrawListener.onPreDraw());
+                    if (cancelDraw) {
+                        mLastDispatchOnPreDrawCanceledReason = preDrawListener.getClass().getName();
+                    }
                 }
             } finally {
                 listeners.end();
@@ -1184,6 +1192,15 @@ public final class ViewTreeObserver {
     }
 
     /**
+     * @return the reason that the last call to dispatchOnPreDraw() returned true to cancel the
+     *         current draw, or null if the last call did not cancel.
+     * @hide
+     */
+    final String getLastDispatchOnPreDrawCanceledReason() {
+        return mLastDispatchOnPreDrawCanceledReason;
+    }
+
+    /**
      * Notifies registered listeners that the window is now shown
      * @hide
      */