Merge "Subtle improvements to notification logging." into tm-qpr-dev

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) {
+    public static LogBuffer provideNotificationsLogBuffer(
-        return factory.create("NotifLog", 1000 /* maxSize */, false /* systrace */);
+            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. */

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<CoalescedEvent> 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");
     }
 
     /**

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<NotificationEntry> entries) {
+                public void onBuildList(Collection<NotificationEntry> 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);

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<ListEntry>) {
         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"
+private const val TAG = "ShadeListBuilder"

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<NotificationEntry> entries);
+    void onBuildList(Collection<NotificationEntry> entries, String reason);
 }

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<NotificationEntry> list) {
+    private void verifyBuiltList(Collection<NotificationEntry> expectedList) {
-        verify(mBuildListener).onBuildList(mBuildListCaptor.capture());
+        verify(mBuildListener).onBuildList(mBuildListCaptor.capture(), any());
-        assertEquals(new ArraySet<>(list), new ArraySet<>(mBuildListCaptor.getValue()));
+        assertThat(mBuildListCaptor.getValue()).containsExactly(expectedList.toArray());
     }
 
     private static class RecordingCollectionListener implements NotifCollectionListener {

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();
     }