From e2c31ef391e6ff46314fbdfff7971ff72020a917 Mon Sep 17 00:00:00 2001 From: Chavi Weingarten Date: Thu, 2 Mar 2023 21:25:00 +0000 Subject: [PATCH] Add timeouts for SurfaceSyncGroup Ensure there are timeouts in case something goes wrong with each level of the SurfaceSyncGroup. It's better to timeout and not blocking all dependant SSGs. The timeouts are the following: 1. VRI has a timeout when it has mPausedForSync > 0. If the timeout is invoked, that means someone was holding the SurfaceSyncGroup for VRI without adding it to any SurfaceSyncGroup. 2. If a SurfaceSyncGroup has been added as a child or a parent of another SurfaceSyncGroup, it will get a timeout set. This is because it can now affect other SSG and we don't want them blocking others. If they are a standalone SSG, we don't care if they don't complete since it only affects itself. Test: SurfaceSyncGroupTest Bug: 237804605 Change-Id: I1a7886f8d51764b82d8eb0408433f5d77d2299cc --- core/java/android/view/ViewRootImpl.java | 22 +++++-- .../java/android/window/SurfaceSyncGroup.java | 59 +++++++++++++++++++ .../server/wm/SurfaceSyncGroupTest.java | 52 +++++++++++----- 3 files changed, 114 insertions(+), 19 deletions(-) diff --git a/core/java/android/view/ViewRootImpl.java b/core/java/android/view/ViewRootImpl.java index f430ec300b5bf..ebde80f601697 100644 --- a/core/java/android/view/ViewRootImpl.java +++ b/core/java/android/view/ViewRootImpl.java @@ -5698,7 +5698,7 @@ public final class ViewRootImpl implements ViewParent, private static final int MSG_WINDOW_TOUCH_MODE_CHANGED = 34; private static final int MSG_KEEP_CLEAR_RECTS_CHANGED = 35; private static final int MSG_REPORT_KEEP_CLEAR_RECTS = 36; - + private static final int MSG_PAUSED_FOR_SYNC_TIMEOUT = 37; final class ViewRootHandler extends Handler { @Override @@ -5986,6 +5986,11 @@ public final class ViewRootImpl implements ViewParent, case MSG_REQUEST_SCROLL_CAPTURE: handleScrollCaptureRequest((IScrollCaptureResponseListener) msg.obj); break; + case MSG_PAUSED_FOR_SYNC_TIMEOUT: + Log.e(mTag, "Timedout waiting to unpause for sync"); + mNumPausedForSync = 0; + scheduleTraversals(); + break; } } } @@ -11490,9 +11495,16 @@ public final class ViewRootImpl implements ViewParent, mActiveSurfaceSyncGroup = new SurfaceSyncGroup(mTag); mActiveSurfaceSyncGroup.setAddedToSyncListener(() -> { Runnable runnable = () -> { - mNumPausedForSync--; - if (!mIsInTraversal && mNumPausedForSync == 0) { - scheduleTraversals(); + // Check if it's already 0 because the timeout could have reset the count to + // 0 and we don't want to go negative. + if (mNumPausedForSync > 0) { + mNumPausedForSync--; + } + if (mNumPausedForSync == 0) { + mHandler.removeMessages(MSG_PAUSED_FOR_SYNC_TIMEOUT); + if (!mIsInTraversal) { + scheduleTraversals(); + } } }; @@ -11519,6 +11531,8 @@ public final class ViewRootImpl implements ViewParent, } mNumPausedForSync++; + mHandler.removeMessages(MSG_PAUSED_FOR_SYNC_TIMEOUT); + mHandler.sendEmptyMessageDelayed(MSG_PAUSED_FOR_SYNC_TIMEOUT, 1000); return mActiveSurfaceSyncGroup; }; diff --git a/core/java/android/window/SurfaceSyncGroup.java b/core/java/android/window/SurfaceSyncGroup.java index 78de9544b59bb..0672d6318212f 100644 --- a/core/java/android/window/SurfaceSyncGroup.java +++ b/core/java/android/window/SurfaceSyncGroup.java @@ -22,6 +22,8 @@ import android.annotation.UiThread; import android.os.Binder; import android.os.BinderProxy; import android.os.Debug; +import android.os.Handler; +import android.os.HandlerThread; import android.os.IBinder; import android.os.RemoteException; import android.os.Trace; @@ -60,6 +62,7 @@ public final class SurfaceSyncGroup { private static final int MAX_COUNT = 100; private static final AtomicInteger sCounter = new AtomicInteger(0); + private static final int TRANSACTION_READY_TIMEOUT = 1000; private static Supplier sTransactionFactory = Transaction::new; @@ -111,6 +114,13 @@ public final class SurfaceSyncGroup { */ private final Binder mToken = new Binder(); + private static final Object sHandlerThreadLock = new Object(); + @GuardedBy("sHandlerThreadLock") + private static HandlerThread sHandlerThread; + private Handler mHandler; + + private boolean mTimeoutAdded; + private static boolean isLocalBinder(IBinder binder) { return !(binder instanceof BinderProxy); } @@ -538,6 +548,11 @@ public final class SurfaceSyncGroup { + transactionReadyCallback.hashCode()); } + // Start the timeout when this SurfaceSyncGroup has been added to a parent SurfaceSyncGroup. + // This is because if the other SurfaceSyncGroup has bugs and doesn't complete, this SSG + // will get stuck. It's better to complete this SSG even if the parent SSG is broken. + addTimeout(); + boolean finished = false; Runnable addedToSyncListener = null; synchronized (mLock) { @@ -641,6 +656,9 @@ public final class SurfaceSyncGroup { } mTransactionReadyConsumer.accept(mTransaction); mFinished = true; + if (mTimeoutAdded) { + mHandler.removeCallbacksAndMessages(this); + } } /** @@ -701,6 +719,12 @@ public final class SurfaceSyncGroup { } } + // Start the timeout when another SSG has been added to this SurfaceSyncGroup. This is + // because if the other SurfaceSyncGroup has bugs and doesn't complete, it will affect this + // SSGs. So it's better to just add a timeout in case the other SSG doesn't invoke the + // callback and complete this SSG. + addTimeout(); + return transactionReadyCallback; } @@ -731,6 +755,41 @@ public final class SurfaceSyncGroup { } } + private void addTimeout() { + synchronized (sHandlerThreadLock) { + if (sHandlerThread == null) { + sHandlerThread = new HandlerThread("SurfaceSyncGroupTimer"); + sHandlerThread.start(); + } + } + + synchronized (mLock) { + if (mTimeoutAdded) { + // We only need one timeout for the entire SurfaceSyncGroup since we just want to + // ensure it doesn't stay stuck forever. + return; + } + + if (mHandler == null) { + mHandler = new Handler(sHandlerThread.getLooper()); + } + + mTimeoutAdded = true; + } + + Runnable runnable = () -> { + Log.e(TAG, "Failed to receive transaction ready in " + TRANSACTION_READY_TIMEOUT + + "ms. Marking SurfaceSyncGroup as ready " + mName); + // Clear out any pending syncs in case the other syncs can't complete or timeout due to + // a crash. + synchronized (mLock) { + mPendingSyncs.clear(); + } + markSyncReady(); + }; + mHandler.postDelayed(runnable, this, TRANSACTION_READY_TIMEOUT); + } + /** * A frame callback that is used to synchronize SurfaceViews. The owner of the SurfaceView must * implement onFrameStarted when trying to sync the SurfaceView. This is to ensure the sync diff --git a/services/tests/wmtests/src/com/android/server/wm/SurfaceSyncGroupTest.java b/services/tests/wmtests/src/com/android/server/wm/SurfaceSyncGroupTest.java index c5387272f0bf8..e30206ee0a645 100644 --- a/services/tests/wmtests/src/com/android/server/wm/SurfaceSyncGroupTest.java +++ b/services/tests/wmtests/src/com/android/server/wm/SurfaceSyncGroupTest.java @@ -41,6 +41,7 @@ import java.util.concurrent.TimeUnit; @Presubmit public class SurfaceSyncGroupTest { private static final String TAG = "SurfaceSyncGroupTest"; + private static final int TIMEOUT_MS = 100; private final Executor mExecutor = Runnable::run; @@ -86,7 +87,7 @@ public class SurfaceSyncGroupTest { syncTarget2.markSyncReady(); - finishedLatch.await(5, TimeUnit.SECONDS); + finishedLatch.await(TIMEOUT_MS, TimeUnit.MILLISECONDS); assertEquals(0, finishedLatch.getCount()); } @@ -124,13 +125,13 @@ public class SurfaceSyncGroupTest { syncTarget1.markSyncReady(); - finishedLatch1.await(5, TimeUnit.SECONDS); + finishedLatch1.await(TIMEOUT_MS, TimeUnit.MILLISECONDS); assertEquals(0, finishedLatch1.getCount()); assertNotEquals(0, finishedLatch2.getCount()); syncTarget2.markSyncReady(); - finishedLatch2.await(5, TimeUnit.SECONDS); + finishedLatch2.await(TIMEOUT_MS, TimeUnit.MILLISECONDS); assertEquals(0, finishedLatch2.getCount()); } @@ -156,17 +157,17 @@ public class SurfaceSyncGroupTest { // Finish syncTarget2 first to test that the syncGroup is not complete until the merged sync // is also done. syncTarget2.markSyncReady(); - finishedLatch2.await(1, TimeUnit.SECONDS); + finishedLatch2.await(TIMEOUT_MS, TimeUnit.MILLISECONDS); // Sync did not complete yet assertNotEquals(0, finishedLatch2.getCount()); syncTarget1.markSyncReady(); // The first sync will still get a callback when it's sync requirements are done. - finishedLatch1.await(5, TimeUnit.SECONDS); + finishedLatch1.await(TIMEOUT_MS, TimeUnit.MILLISECONDS); assertEquals(0, finishedLatch1.getCount()); - finishedLatch2.await(5, TimeUnit.SECONDS); + finishedLatch2.await(TIMEOUT_MS, TimeUnit.MILLISECONDS); assertEquals(0, finishedLatch2.getCount()); } @@ -189,7 +190,7 @@ public class SurfaceSyncGroupTest { syncTarget1.markSyncReady(); // The first sync will still get a callback when it's sync requirements are done. - finishedLatch1.await(5, TimeUnit.SECONDS); + finishedLatch1.await(TIMEOUT_MS, TimeUnit.MILLISECONDS); assertEquals(0, finishedLatch1.getCount()); syncGroup2.add(syncGroup1, null /* runnable */); @@ -198,7 +199,7 @@ public class SurfaceSyncGroupTest { // Verify that the second sync will receive complete since the merged sync was already // completed before the merge. - finishedLatch2.await(5, TimeUnit.SECONDS); + finishedLatch2.await(TIMEOUT_MS, TimeUnit.MILLISECONDS); assertEquals(0, finishedLatch2.getCount()); } @@ -232,8 +233,8 @@ public class SurfaceSyncGroupTest { syncTarget3.markSyncReady(); // Neither SyncGroup will be ready. - finishedLatch1.await(1, TimeUnit.SECONDS); - finishedLatch2.await(1, TimeUnit.SECONDS); + finishedLatch1.await(TIMEOUT_MS, TimeUnit.MILLISECONDS); + finishedLatch2.await(TIMEOUT_MS, TimeUnit.MILLISECONDS); assertEquals(1, finishedLatch1.getCount()); assertEquals(1, finishedLatch2.getCount()); @@ -241,8 +242,8 @@ public class SurfaceSyncGroupTest { syncTarget2.markSyncReady(); // Both sync groups should be ready after target2 completed. - finishedLatch1.await(5, TimeUnit.SECONDS); - finishedLatch2.await(5, TimeUnit.SECONDS); + finishedLatch1.await(TIMEOUT_MS, TimeUnit.MILLISECONDS); + finishedLatch2.await(TIMEOUT_MS, TimeUnit.MILLISECONDS); assertEquals(0, finishedLatch1.getCount()); assertEquals(0, finishedLatch2.getCount()); } @@ -275,8 +276,8 @@ public class SurfaceSyncGroupTest { syncTarget1.markSyncReady(); // Only SyncGroup1 will be ready, but SyncGroup2 still needs its own targets to be ready. - finishedLatch1.await(1, TimeUnit.SECONDS); - finishedLatch2.await(1, TimeUnit.SECONDS); + finishedLatch1.await(TIMEOUT_MS, TimeUnit.MILLISECONDS); + finishedLatch2.await(TIMEOUT_MS, TimeUnit.MILLISECONDS); assertEquals(0, finishedLatch1.getCount()); assertEquals(1, finishedLatch2.getCount()); @@ -284,7 +285,7 @@ public class SurfaceSyncGroupTest { syncTarget3.markSyncReady(); // SyncGroup2 is finished after target3 completed. - finishedLatch2.await(1, TimeUnit.SECONDS); + finishedLatch2.await(TIMEOUT_MS, TimeUnit.MILLISECONDS); assertEquals(0, finishedLatch2.getCount()); } @@ -357,6 +358,27 @@ public class SurfaceSyncGroupTest { } catch (InterruptedException e) { throw new RuntimeException(e); } + + assertEquals(0, finishedLatch.getCount()); + } + + public void testSurfaceSyncGroupTimeout() throws InterruptedException { + final CountDownLatch finishedLatch = new CountDownLatch(1); + SurfaceSyncGroup syncGroup = new SurfaceSyncGroup(TAG); + syncGroup.addSyncCompleteCallback(mExecutor, finishedLatch::countDown); + SurfaceSyncGroup syncTarget1 = new SurfaceSyncGroup("FakeSyncTarget1"); + SurfaceSyncGroup syncTarget2 = new SurfaceSyncGroup("FakeSyncTarget2"); + + syncGroup.add(syncTarget1, null /* runnable */); + syncGroup.add(syncTarget2, null /* runnable */); + syncGroup.markSyncReady(); + + syncTarget1.markSyncReady(); + assertNotEquals(0, finishedLatch.getCount()); + + // Never finish syncTarget2 so it forces the timeout. Timeout is 1 second so wait a little + // over 1 second to make sure it completes. + finishedLatch.await(1100, TimeUnit.MILLISECONDS); assertEquals(0, finishedLatch.getCount()); } }