From 50262f50f26bc7bbf26581819e73afc8bba931f1 Mon Sep 17 00:00:00 2001 From: András Kurucz Date: Tue, 15 Oct 2024 13:33:28 +0000 Subject: Log ENR appear animation events The linked bug might be caused by concurrent appear animations started for the same row, and one of them not being finalized. Log the start, finish, cancel and skip events for the appear animations of the row, to help investigate. Bug: 356958336 Test: enable the NotifLog buffer, and check the logs Flag: EXEMPT changing dumps only Change-Id: I29a29e18776ca6da7dbd9654dde5334daa788403 --- .../row/ActivatableNotificationView.java | 13 ++- .../row/ExpandableNotificationRow.java | 54 ++++++++++- .../row/ExpandableNotificationRowController.java | 26 ++++++ .../notification/row/NotificationRowLogger.kt | 103 ++++++++++++++++----- .../row/ExpandableNotificationRowTest.java | 4 +- 5 files changed, 172 insertions(+), 28 deletions(-) diff --git a/packages/SystemUI/src/com/android/systemui/statusbar/notification/row/ActivatableNotificationView.java b/packages/SystemUI/src/com/android/systemui/statusbar/notification/row/ActivatableNotificationView.java index 4c7d90c12839..d538f52fd637 100644 --- a/packages/SystemUI/src/com/android/systemui/statusbar/notification/row/ActivatableNotificationView.java +++ b/packages/SystemUI/src/com/android/systemui/statusbar/notification/row/ActivatableNotificationView.java @@ -449,7 +449,7 @@ public abstract class ActivatableNotificationView extends ExpandableOutlineView } // We need to reset the View state, even if the animation was cancelled - onAppearAnimationFinished(isAppearing); + onAppearAnimationFinished(isAppearing, /* cancelled = */ !mRunWithoutInterruptions); if (mRunWithoutInterruptions) { InteractionJankMonitor.getInstance().end(getCujType(isAppearing)); @@ -463,6 +463,7 @@ public abstract class ActivatableNotificationView extends ExpandableOutlineView if (onStartedRunnable != null) { onStartedRunnable.run(); } + onAppearAnimationStarted(isAppearing); mRunWithoutInterruptions = true; Configuration.Builder builder = Configuration.Builder .withView(getCujType(isAppearing), ActivatableNotificationView.this); @@ -486,6 +487,8 @@ public abstract class ActivatableNotificationView extends ExpandableOutlineView frameTimeNanos -> { if (mAppearAnimator == cachedAnimator) { mAppearAnimator.start(); + } else { + onAppearAnimationSkipped(isAppearing); } }, delay); } @@ -502,7 +505,13 @@ public abstract class ActivatableNotificationView extends ExpandableOutlineView } } - protected void onAppearAnimationFinished(boolean wasAppearing) { + protected void onAppearAnimationStarted(boolean isAppear) { + } + + protected void onAppearAnimationSkipped(boolean isAppear) { + } + + protected void onAppearAnimationFinished(boolean wasAppearing, boolean cancelled) { } private void cancelAppearAnimation() { diff --git a/packages/SystemUI/src/com/android/systemui/statusbar/notification/row/ExpandableNotificationRow.java b/packages/SystemUI/src/com/android/systemui/statusbar/notification/row/ExpandableNotificationRow.java index 33dbbc233fa9..38e66099022c 100644 --- a/packages/SystemUI/src/com/android/systemui/statusbar/notification/row/ExpandableNotificationRow.java +++ b/packages/SystemUI/src/com/android/systemui/statusbar/notification/row/ExpandableNotificationRow.java @@ -1835,6 +1835,25 @@ public class ExpandableNotificationRow extends ActivatableNotificationView void logSkipResetAllContentAlphas( NotificationEntry entry ); + + /** Called when we start an appear animation. */ + void logStartAppearAnimation(NotificationEntry entry, boolean isAppear); + + /** Called when we cancel the running appear animation. */ + void logCancelAppearDrawing(NotificationEntry entry, boolean wasDrawing); + + /** Called when the animator of the appear animation is started. */ + void logAppearAnimationStarted(NotificationEntry entry, boolean isAppear); + + /** Called when we prepared an appear animation, but the animator was never started. */ + void logAppearAnimationSkipped(NotificationEntry entry, boolean isAppear); + + /** Called when the animator of the appear animation is finished. */ + void logAppearAnimationFinished( + NotificationEntry entry, + boolean isAppear, + boolean cancelled + ); } /** @@ -3164,6 +3183,13 @@ public class ExpandableNotificationRow extends ActivatableNotificationView return getShowingLayout(); } + @Override + public void performAddAnimation(long delay, long duration, boolean isHeadsUpAppear, + Runnable onFinishRunnable) { + mLogger.logStartAppearAnimation(getEntry(), /* isAppear = */ true); + super.performAddAnimation(delay, duration, isHeadsUpAppear, onFinishRunnable); + } + @Override public long performRemoveAnimation( long duration, @@ -3173,6 +3199,7 @@ public class ExpandableNotificationRow extends ActivatableNotificationView Runnable onStartedRunnable, Runnable onFinishedRunnable, AnimatorListenerAdapter animationListener, ClipSide clipSide) { + mLogger.logStartAppearAnimation(getEntry(), /* isAppear = */ false); if (mMenuRow != null && mMenuRow.isMenuVisible()) { Animator anim = getTranslateViewAnimator(0f, null /* listener */); if (anim != null) { @@ -3201,8 +3228,25 @@ public class ExpandableNotificationRow extends ActivatableNotificationView } @Override - protected void onAppearAnimationFinished(boolean wasAppearing) { - super.onAppearAnimationFinished(wasAppearing); + protected void onAppearAnimationStarted(boolean isAppear) { + mLogger.logAppearAnimationStarted(getEntry(), /* isAppear = */ isAppear); + super.onAppearAnimationStarted(isAppear); + } + + @Override + protected void onAppearAnimationSkipped(boolean isAppear) { + mLogger.logAppearAnimationSkipped(getEntry(), /* isAppear = */ isAppear); + super.onAppearAnimationSkipped(isAppear); + } + + @Override + protected void onAppearAnimationFinished(boolean wasAppearing, boolean cancelled) { + mLogger.logAppearAnimationFinished( + /* entry = */ getEntry(), + /* isAppear = */ wasAppearing, + /* cancelled = */ cancelled + ); + super.onAppearAnimationFinished(wasAppearing, cancelled); if (wasAppearing) { // During the animation the visible view might have changed, so let's make sure all // alphas are reset @@ -3217,6 +3261,12 @@ public class ExpandableNotificationRow extends ActivatableNotificationView } } + @Override + public void cancelAppearDrawing() { + mLogger.logCancelAppearDrawing(getEntry(), isDrawingAppearAnimation()); + super.cancelAppearDrawing(); + } + @Override public void resetAllContentAlphas() { mLogger.logResetAllContentAlphas(getEntry()); diff --git a/packages/SystemUI/src/com/android/systemui/statusbar/notification/row/ExpandableNotificationRowController.java b/packages/SystemUI/src/com/android/systemui/statusbar/notification/row/ExpandableNotificationRowController.java index c31a2cb8908b..23a2facf4c5a 100644 --- a/packages/SystemUI/src/com/android/systemui/statusbar/notification/row/ExpandableNotificationRowController.java +++ b/packages/SystemUI/src/com/android/systemui/statusbar/notification/row/ExpandableNotificationRowController.java @@ -209,6 +209,32 @@ public class ExpandableNotificationRowController implements NotifViewController ) { mLogBufferLogger.logSkipResetAllContentAlphas(entry); } + + @Override + public void logStartAppearAnimation(NotificationEntry entry, boolean isAppear) { + mLogBufferLogger.logStartAppearAnimation(entry, isAppear); + } + + @Override + public void logCancelAppearDrawing(NotificationEntry entry, boolean wasDrawing) { + mLogBufferLogger.logCancelAppearDrawing(entry, wasDrawing); + } + + @Override + public void logAppearAnimationStarted(NotificationEntry entry, boolean isAppear) { + mLogBufferLogger.logAppearAnimationStarted(entry, isAppear); + } + + @Override + public void logAppearAnimationSkipped(NotificationEntry entry, boolean isAppear) { + mLogBufferLogger.logAppearAnimationSkipped(entry, isAppear); + } + + @Override + public void logAppearAnimationFinished(NotificationEntry entry, boolean isAppear, + boolean cancelled) { + mLogBufferLogger.logAppearAnimationFinished(entry, isAppear, cancelled); + } }; diff --git a/packages/SystemUI/src/com/android/systemui/statusbar/notification/row/NotificationRowLogger.kt b/packages/SystemUI/src/com/android/systemui/statusbar/notification/row/NotificationRowLogger.kt index b1e90329e01a..6e78f561cfc1 100644 --- a/packages/SystemUI/src/com/android/systemui/statusbar/notification/row/NotificationRowLogger.kt +++ b/packages/SystemUI/src/com/android/systemui/statusbar/notification/row/NotificationRowLogger.kt @@ -30,7 +30,7 @@ class NotificationRowLogger @Inject constructor( @NotificationLog private val buffer: LogBuffer, - @NotificationRenderLog private val notificationRenderBuffer: LogBuffer + @NotificationRenderLog private val notificationRenderBuffer: LogBuffer, ) { fun logKeepInParentChildDetached(child: NotificationEntry, oldParent: NotificationEntry?) { buffer.log( @@ -40,7 +40,7 @@ constructor( str1 = child.logKey str2 = oldParent.logKey }, - { "Detach child $str1 kept in parent $str2" } + { "Detach child $str1 kept in parent $str2" }, ) } @@ -52,13 +52,13 @@ constructor( str1 = child.logKey str2 = newParent.logKey }, - { "Skipping to attach $str1 to $str2, because it still flagged to keep in parent" } + { "Skipping to attach $str1 to $str2, because it still flagged to keep in parent" }, ) } fun logRemoveTransientFromContainer( childEntry: NotificationEntry, - containerEntry: NotificationEntry + containerEntry: NotificationEntry, ) { notificationRenderBuffer.log( TAG, @@ -67,25 +67,20 @@ constructor( str1 = childEntry.logKey str2 = containerEntry.logKey }, - { "RemoveTransientRow from ChildrenContainer: childKey: $str1 -- containerKey: $str2" } + { "RemoveTransientRow from ChildrenContainer: childKey: $str1 -- containerKey: $str2" }, ) } - fun logRemoveTransientFromNssl( - childEntry: NotificationEntry, - ) { + fun logRemoveTransientFromNssl(childEntry: NotificationEntry) { notificationRenderBuffer.log( TAG, LogLevel.INFO, { str1 = childEntry.logKey }, - { "RemoveTransientRow from Nssl: childKey: $str1" } + { "RemoveTransientRow from Nssl: childKey: $str1" }, ) } - fun logRemoveTransientFromViewGroup( - childEntry: NotificationEntry, - containerView: ViewGroup, - ) { + fun logRemoveTransientFromViewGroup(childEntry: NotificationEntry, containerView: ViewGroup) { notificationRenderBuffer.log( TAG, LogLevel.WARNING, @@ -93,14 +88,14 @@ constructor( str1 = childEntry.logKey str2 = containerView.toString() }, - { "RemoveTransientRow from other ViewGroup: childKey: $str1 -- ViewGroup: $str2" } + { "RemoveTransientRow from other ViewGroup: childKey: $str1 -- ViewGroup: $str2" }, ) } fun logAddTransientRow( childEntry: NotificationEntry, containerEntry: NotificationEntry, - index: Int + index: Int, ) { notificationRenderBuffer.log( TAG, @@ -110,14 +105,11 @@ constructor( str2 = containerEntry.logKey int1 = index }, - { "addTransientRow to row: childKey: $str1 -- containerKey: $str2 -- index: $int1" } + { "addTransientRow to row: childKey: $str1 -- containerKey: $str2 -- index: $int1" }, ) } - fun logRemoveTransientRow( - childEntry: NotificationEntry, - containerEntry: NotificationEntry, - ) { + fun logRemoveTransientRow(childEntry: NotificationEntry, containerEntry: NotificationEntry) { notificationRenderBuffer.log( TAG, LogLevel.ERROR, @@ -125,7 +117,7 @@ constructor( str1 = childEntry.logKey str2 = containerEntry.logKey }, - { "removeTransientRow from row: childKey: $str1 -- containerKey: $str2" } + { "removeTransientRow from row: childKey: $str1 -- containerKey: $str2" }, ) } @@ -134,7 +126,7 @@ constructor( TAG, LogLevel.INFO, { str1 = entry.logKey }, - { "resetAllContentAlphas: $str1" } + { "resetAllContentAlphas: $str1" }, ) } @@ -143,7 +135,72 @@ constructor( TAG, LogLevel.INFO, { str1 = entry.logKey }, - { "Skip resetAllContentAlphas: $str1" } + { "Skip resetAllContentAlphas: $str1" }, + ) + } + + fun logStartAppearAnimation(entry: NotificationEntry, isAppear: Boolean) { + notificationRenderBuffer.log( + TAG, + LogLevel.DEBUG, + { + str1 = entry.logKey + bool1 = isAppear + }, + { "startAppearAnimation childKey: $str1 isAppear:$bool1" }, + ) + } + + fun logCancelAppearDrawing(entry: NotificationEntry, wasDrawing: Boolean) { + notificationRenderBuffer.log( + TAG, + LogLevel.WARNING, + { + str1 = entry.logKey + bool1 = wasDrawing + }, + { "cancelAppearDrawing childKey: $str1 wasDrawing:$bool1" }, + ) + } + + fun logAppearAnimationStarted(entry: NotificationEntry, isAppear: Boolean) { + notificationRenderBuffer.log( + TAG, + LogLevel.DEBUG, + { + str1 = entry.logKey + bool1 = isAppear + }, + { "onAppearAnimationStarted childKey: $str1 isAppear:$bool1" }, + ) + } + + fun logAppearAnimationSkipped(entry: NotificationEntry, isAppear: Boolean) { + notificationRenderBuffer.log( + TAG, + LogLevel.WARNING, + { + str1 = entry.logKey + bool1 = isAppear + }, + { "Skipped an appear animation childKey: $str1 isAppear:$bool1" }, + ) + } + + fun logAppearAnimationFinished( + entry: NotificationEntry, + isAppear: Boolean, + cancelled: Boolean, + ) { + notificationRenderBuffer.log( + TAG, + LogLevel.DEBUG, + { + str1 = entry.logKey + bool1 = isAppear + bool2 = cancelled + }, + { "onAppearAnimationFinished childKey: $str1 isAppear:$bool1 cancelled:$bool2" }, ) } } diff --git a/packages/SystemUI/tests/src/com/android/systemui/statusbar/notification/row/ExpandableNotificationRowTest.java b/packages/SystemUI/tests/src/com/android/systemui/statusbar/notification/row/ExpandableNotificationRowTest.java index ed7383cacd29..e3e2491e5d52 100644 --- a/packages/SystemUI/tests/src/com/android/systemui/statusbar/notification/row/ExpandableNotificationRowTest.java +++ b/packages/SystemUI/tests/src/com/android/systemui/statusbar/notification/row/ExpandableNotificationRowTest.java @@ -612,6 +612,8 @@ public class ExpandableNotificationRowTest extends SysuiTestCase { Assert.assertNull(child.getParent()); Assert.assertNull(child.getNotificationParent()); Assert.assertFalse(child.keepInParentForDismissAnimation()); + verify(mNotificationTestHelper.getMockLogger()) + .logCancelAppearDrawing(child.getEntry(), false); verifyNoMoreInteractions(mNotificationTestHelper.getMockLogger()); } @@ -1013,7 +1015,7 @@ public class ExpandableNotificationRowTest extends SysuiTestCase { assertThat(row.isHeadsUpAnimatingAway()).isTrue(); // on disappear animation ends - row.onAppearAnimationFinished(/* wasAppearing = */ false); + row.onAppearAnimationFinished(/* wasAppearing = */ false, /* cancelled = */ false); assertThat(row.isHeadsUpAnimatingAway()).isFalse(); } -- cgit v1.2.3-59-g8ed1b