From 3d952d3514a7721b1cf662d16e524d4575a921cd Mon Sep 17 00:00:00 2001 From: Jeff DeCew Date: Mon, 27 Jun 2022 12:06:27 +0000 Subject: [PATCH] Subtle improvements to notification logging. * NotificationLog buffer is now 10x the size when dev-logging flag is enabled. * NotifCollection now passes a reason to buildList, which gets logged. * ShadeListBuilder (when dev-logging flag is enabled) now logs the rank of every notification in the list. All of these changes are targeted at better understanding whether the incorrect order of children in some situations is due to unexpected changes in the ranking provided to the ShadeListBuilder, or due to incorrect logic in that class. Bug: 237216329 Test: atest SystemUITests Test: dumpsysui NotifLog ShadeListBuilder Change-Id: I45be2cc3af4114fa4285491e8fd961c0fd548f3c --- .../systemui/log/dagger/LogModule.java | 12 +++++-- .../collection/NotifCollection.java | 22 ++++++------ .../collection/ShadeListBuilder.java | 7 ++-- .../listbuilder/ShadeListBuilderLogger.kt | 35 ++++++++++++++----- .../CollectionReadyForBuildListener.java | 2 +- .../collection/NotifCollectionTest.java | 6 ++-- .../collection/ShadeListBuilderTest.java | 4 +-- 7 files changed, 58 insertions(+), 30 deletions(-) diff --git a/packages/SystemUI/src/com/android/systemui/log/dagger/LogModule.java b/packages/SystemUI/src/com/android/systemui/log/dagger/LogModule.java index 90cca15ddf218..d0da18aaba056 100644 --- a/packages/SystemUI/src/com/android/systemui/log/dagger/LogModule.java +++ b/packages/SystemUI/src/com/android/systemui/log/dagger/LogModule.java @@ -27,6 +27,8 @@ import com.android.systemui.log.LogBufferFactory; import com.android.systemui.log.LogcatEchoTracker; import com.android.systemui.log.LogcatEchoTrackerDebug; import com.android.systemui.log.LogcatEchoTrackerProd; +import com.android.systemui.statusbar.notification.NotifPipelineFlags; +import com.android.systemui.util.Compile; import dagger.Module; import dagger.Provides; @@ -48,8 +50,14 @@ public class LogModule { @Provides @SysUISingleton @NotificationLog - public static LogBuffer provideNotificationsLogBuffer(LogBufferFactory factory) { - return factory.create("NotifLog", 1000 /* maxSize */, false /* systrace */); + public static LogBuffer provideNotificationsLogBuffer( + LogBufferFactory factory, + NotifPipelineFlags notifPipelineFlags) { + int maxSize = 1000; + if (Compile.IS_DEBUG && notifPipelineFlags.isDevLoggingEnabled()) { + maxSize *= 10; + } + return factory.create("NotifLog", maxSize, false /* systrace */); } /** Provides a logging buffer for logs related to heads up presentation of notifications. */ diff --git a/packages/SystemUI/src/com/android/systemui/statusbar/notification/collection/NotifCollection.java b/packages/SystemUI/src/com/android/systemui/statusbar/notification/collection/NotifCollection.java index e345aabc62158..d99b5f9df12a6 100644 --- a/packages/SystemUI/src/com/android/systemui/statusbar/notification/collection/NotifCollection.java +++ b/packages/SystemUI/src/com/android/systemui/statusbar/notification/collection/NotifCollection.java @@ -310,7 +310,7 @@ public class NotifCollection implements Dumpable { } locallyDismissNotifications(entriesToLocallyDismiss); - dispatchEventsAndRebuildList(); + dispatchEventsAndRebuildList("dismissNotifications"); } /** @@ -354,7 +354,7 @@ public class NotifCollection implements Dumpable { } locallyDismissNotifications(entries); - dispatchEventsAndRebuildList(); + dispatchEventsAndRebuildList("dismissAllNotifications"); } /** @@ -401,7 +401,7 @@ public class NotifCollection implements Dumpable { postNotification(sbn, requireRanking(rankingMap, sbn.getKey())); applyRanking(rankingMap); - dispatchEventsAndRebuildList(); + dispatchEventsAndRebuildList("onNotificationPosted"); } private void onNotificationGroupPosted(List batch) { @@ -412,7 +412,7 @@ public class NotifCollection implements Dumpable { for (CoalescedEvent event : batch) { postNotification(event.getSbn(), event.getRanking()); } - dispatchEventsAndRebuildList(); + dispatchEventsAndRebuildList("onNotificationGroupPosted"); } private void onNotificationRemoved( @@ -433,14 +433,14 @@ public class NotifCollection implements Dumpable { entry.mCancellationReason = reason; tryRemoveNotification(entry); applyRanking(rankingMap); - dispatchEventsAndRebuildList(); + dispatchEventsAndRebuildList("onNotificationRemoved"); } private void onNotificationRankingUpdate(RankingMap rankingMap) { Assert.isMainThread(); mEventQueue.add(new RankingUpdatedEvent(rankingMap)); applyRanking(rankingMap); - dispatchEventsAndRebuildList(); + dispatchEventsAndRebuildList("onNotificationRankingUpdate"); } private void onNotificationChannelModified( @@ -450,7 +450,7 @@ public class NotifCollection implements Dumpable { int modificationType) { Assert.isMainThread(); mEventQueue.add(new ChannelChangedEvent(pkgName, user, channel, modificationType)); - dispatchEventsAndRebuildList(); + dispatchEventsAndRebuildList("onNotificationChannelModified"); } private void onNotificationsInitialized() { @@ -610,7 +610,7 @@ public class NotifCollection implements Dumpable { mEventQueue.add(new RankingAppliedEvent()); } - private void dispatchEventsAndRebuildList() { + private void dispatchEventsAndRebuildList(String reason) { Trace.beginSection("NotifCollection.dispatchEventsAndRebuildList"); mAmDispatchingToOtherCode = true; while (!mEventQueue.isEmpty()) { @@ -619,7 +619,7 @@ public class NotifCollection implements Dumpable { mAmDispatchingToOtherCode = false; if (mBuildListener != null) { - mBuildListener.onBuildList(mReadOnlyNotificationSet); + mBuildListener.onBuildList(mReadOnlyNotificationSet, reason); } Trace.endSection(); } @@ -654,7 +654,7 @@ public class NotifCollection implements Dumpable { if (!isLifetimeExtended(entry)) { if (tryRemoveNotification(entry)) { - dispatchEventsAndRebuildList(); + dispatchEventsAndRebuildList("onEndLifetimeExtension"); } } } @@ -955,7 +955,7 @@ public class NotifCollection implements Dumpable { mEventQueue.add(new EntryUpdatedEvent(entry, false /* fromSystem */)); // Skip the applyRanking step and go straight to dispatching the events - dispatchEventsAndRebuildList(); + dispatchEventsAndRebuildList("updateNotificationInternally"); } /** diff --git a/packages/SystemUI/src/com/android/systemui/statusbar/notification/collection/ShadeListBuilder.java b/packages/SystemUI/src/com/android/systemui/statusbar/notification/collection/ShadeListBuilder.java index 6441d2fd94af7..93761f580dd41 100644 --- a/packages/SystemUI/src/com/android/systemui/statusbar/notification/collection/ShadeListBuilder.java +++ b/packages/SystemUI/src/com/android/systemui/statusbar/notification/collection/ShadeListBuilder.java @@ -304,11 +304,11 @@ public class ShadeListBuilder implements Dumpable { private final CollectionReadyForBuildListener mReadyForBuildListener = new CollectionReadyForBuildListener() { @Override - public void onBuildList(Collection entries) { + public void onBuildList(Collection entries, String reason) { Assert.isMainThread(); mPipelineState.requireIsBefore(STATE_BUILD_STARTED); - mLogger.logOnBuildList(); + mLogger.logOnBuildList(reason); mAllEntries = entries; mChoreographer.schedule(); } @@ -456,7 +456,8 @@ public class ShadeListBuilder implements Dumpable { mLogger.logEndBuildList( mIterationCount, mReadOnlyNotifList.size(), - countChildren(mReadOnlyNotifList)); + countChildren(mReadOnlyNotifList), + /* enforcedVisualStability */ !mNotifStabilityManager.isEveryChangeAllowed()); if (mAlwaysLogList || mIterationCount % 10 == 0) { Trace.beginSection("ShadeListBuilder.logFinalList"); mLogger.logFinalList(mNotifList); diff --git a/packages/SystemUI/src/com/android/systemui/statusbar/notification/collection/listbuilder/ShadeListBuilderLogger.kt b/packages/SystemUI/src/com/android/systemui/statusbar/notification/collection/listbuilder/ShadeListBuilderLogger.kt index 8d1759b8f4752..10a627d65b838 100644 --- a/packages/SystemUI/src/com/android/systemui/statusbar/notification/collection/listbuilder/ShadeListBuilderLogger.kt +++ b/packages/SystemUI/src/com/android/systemui/statusbar/notification/collection/listbuilder/ShadeListBuilderLogger.kt @@ -21,31 +21,42 @@ import com.android.systemui.log.LogLevel.DEBUG import com.android.systemui.log.LogLevel.INFO import com.android.systemui.log.LogLevel.WARNING import com.android.systemui.log.dagger.NotificationLog +import com.android.systemui.statusbar.notification.NotifPipelineFlags import com.android.systemui.statusbar.notification.collection.GroupEntry import com.android.systemui.statusbar.notification.collection.ListEntry import com.android.systemui.statusbar.notification.collection.NotificationEntry import com.android.systemui.statusbar.notification.collection.listbuilder.pluggable.NotifFilter import com.android.systemui.statusbar.notification.collection.listbuilder.pluggable.NotifPromoter import com.android.systemui.statusbar.notification.logKey +import com.android.systemui.util.Compile import javax.inject.Inject class ShadeListBuilderLogger @Inject constructor( + notifPipelineFlags: NotifPipelineFlags, @NotificationLog private val buffer: LogBuffer ) { - fun logOnBuildList() { + fun logOnBuildList(reason: String?) { buffer.log(TAG, INFO, { + str1 = reason }, { - "Request received from NotifCollection" + "Request received from NotifCollection for $str1" }) } - fun logEndBuildList(buildId: Int, topLevelEntries: Int, numChildren: Int) { + fun logEndBuildList( + buildId: Int, + topLevelEntries: Int, + numChildren: Int, + enforcedVisualStability: Boolean + ) { buffer.log(TAG, INFO, { long1 = buildId.toLong() int1 = topLevelEntries int2 = numChildren + bool1 = enforcedVisualStability }, { - "(Build $long1) Build complete ($int1 top-level entries, $int2 children)" + "(Build $long1) Build complete ($int1 top-level entries, $int2 children)" + + " enforcedVisualStability=$bool1" }) } @@ -280,6 +291,8 @@ class ShadeListBuilderLogger @Inject constructor( }) } + val logRankInFinalList = Compile.IS_DEBUG && notifPipelineFlags.isDevLoggingEnabled() + fun logFinalList(entries: List) { if (entries.isEmpty()) { buffer.log(TAG, DEBUG, {}, { "(empty list)" }) @@ -289,16 +302,20 @@ class ShadeListBuilderLogger @Inject constructor( buffer.log(TAG, DEBUG, { int1 = i str1 = entry.logKey + bool1 = logRankInFinalList + int2 = entry.representativeEntry!!.ranking.rank }, { - "[$int1] $str1" + "[$int1] $str1".let { if (bool1) "$it rank=$int2" else it } }) if (entry is GroupEntry) { entry.summary?.let { buffer.log(TAG, DEBUG, { str1 = it.logKey + bool1 = logRankInFinalList + int2 = it.ranking.rank }, { - " [*] $str1 (summary)" + " [*] $str1 (summary)".let { if (bool1) "$it rank=$int2" else it } }) } for (j in entry.children.indices) { @@ -306,8 +323,10 @@ class ShadeListBuilderLogger @Inject constructor( buffer.log(TAG, DEBUG, { int1 = j str1 = child.logKey + bool1 = logRankInFinalList + int2 = child.ranking.rank }, { - " [$int1] $str1" + " [$int1] $str1".let { if (bool1) "$it rank=$int2" else it } }) } } @@ -318,4 +337,4 @@ class ShadeListBuilderLogger @Inject constructor( buffer.log(TAG, INFO, {}) { "Suppressing pipeline run during animation." } } -private const val TAG = "ShadeListBuilder" \ No newline at end of file +private const val TAG = "ShadeListBuilder" diff --git a/packages/SystemUI/src/com/android/systemui/statusbar/notification/collection/notifcollection/CollectionReadyForBuildListener.java b/packages/SystemUI/src/com/android/systemui/statusbar/notification/collection/notifcollection/CollectionReadyForBuildListener.java index 4023474bf6a78..941b2ae4f7718 100644 --- a/packages/SystemUI/src/com/android/systemui/statusbar/notification/collection/notifcollection/CollectionReadyForBuildListener.java +++ b/packages/SystemUI/src/com/android/systemui/statusbar/notification/collection/notifcollection/CollectionReadyForBuildListener.java @@ -29,5 +29,5 @@ public interface CollectionReadyForBuildListener { * Called by the NotifCollection to indicate that something in the collection has changed and * that the list builder should regenerate the list. */ - void onBuildList(Collection entries); + void onBuildList(Collection entries, String reason); } diff --git a/packages/SystemUI/tests/src/com/android/systemui/statusbar/notification/collection/NotifCollectionTest.java b/packages/SystemUI/tests/src/com/android/systemui/statusbar/notification/collection/NotifCollectionTest.java index f286349971d27..af43826091a06 100644 --- a/packages/SystemUI/tests/src/com/android/systemui/statusbar/notification/collection/NotifCollectionTest.java +++ b/packages/SystemUI/tests/src/com/android/systemui/statusbar/notification/collection/NotifCollectionTest.java @@ -1684,9 +1684,9 @@ public class NotifCollectionTest extends SysuiTestCase { return new CollectionEvent(rawEvent, requireNonNull(mEntryCaptor.getValue())); } - private void verifyBuiltList(Collection list) { - verify(mBuildListener).onBuildList(mBuildListCaptor.capture()); - assertEquals(new ArraySet<>(list), new ArraySet<>(mBuildListCaptor.getValue())); + private void verifyBuiltList(Collection expectedList) { + verify(mBuildListener).onBuildList(mBuildListCaptor.capture(), any()); + assertThat(mBuildListCaptor.getValue()).containsExactly(expectedList.toArray()); } private static class RecordingCollectionListener implements NotifCollectionListener { diff --git a/packages/SystemUI/tests/src/com/android/systemui/statusbar/notification/collection/ShadeListBuilderTest.java b/packages/SystemUI/tests/src/com/android/systemui/statusbar/notification/collection/ShadeListBuilderTest.java index 95460583e857b..555adfdfdc31b 100644 --- a/packages/SystemUI/tests/src/com/android/systemui/statusbar/notification/collection/ShadeListBuilderTest.java +++ b/packages/SystemUI/tests/src/com/android/systemui/statusbar/notification/collection/ShadeListBuilderTest.java @@ -570,7 +570,7 @@ public class ShadeListBuilderTest extends SysuiTestCase { assertTrue(entry.hasFinishedInitialization()); // WHEN the pipeline is kicked off - mReadyForBuildListener.onBuildList(singletonList(entry)); + mReadyForBuildListener.onBuildList(singletonList(entry), "test"); mPipelineChoreographer.runIfScheduled(); // THEN the entry's initialization time is reset @@ -2092,7 +2092,7 @@ public class ShadeListBuilderTest extends SysuiTestCase { mPendingSet.clear(); } - mReadyForBuildListener.onBuildList(mEntrySet); + mReadyForBuildListener.onBuildList(mEntrySet, "test"); mPipelineChoreographer.runIfScheduled(); }