Add logging for unseen notif filtering

Bug: 275032839 Test: manual - inspect bugreport output Change-Id: Id9b715a758f7357d922078dc3daf5b2be161a4c5
2023-04-10 15:51:56 -04:00
parent 766ec400f2
commit 6a03dcd4e8
5 changed files with 188 additions and 9 deletions
--- a/packages/SystemUI/src/com/android/systemui/log/dagger/LogModule.java
+++ b/packages/SystemUI/src/com/android/systemui/log/dagger/LogModule.java
@@ -136,6 +136,14 @@ public class LogModule {
        return factory.create("NotifRemoteInputLog", 50 /* maxSize */, false /* systrace */);
    }

+    /** Provides a logging buffer for all logs related to unseen notifications. */
+    @Provides
+    @SysUISingleton
+    @UnseenNotificationLog
+    public static LogBuffer provideUnseenNotificationLogBuffer(LogBufferFactory factory) {
+        return factory.create("UnseenNotifLog", 20 /* maxSize */, false /* systrace */);
+    }
+
    /** Provides a logging buffer for all logs related to the data layer of notifications. */
    @Provides
    @SysUISingleton
--- a/packages/SystemUI/src/com/android/systemui/log/dagger/UnseenNotificationLog.java
+++ b/packages/SystemUI/src/com/android/systemui/log/dagger/UnseenNotificationLog.java
@@ -0,0 +1,33 @@
+/*
+ * Copyright (C) 2023 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *      http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+package com.android.systemui.log.dagger;
+
+import static java.lang.annotation.RetentionPolicy.RUNTIME;
+
+import com.android.systemui.plugins.log.LogBuffer;
+
+import java.lang.annotation.Documented;
+import java.lang.annotation.Retention;
+
+import javax.inject.Qualifier;
+
+/** A {@link LogBuffer} for unseen notification related messages. */
+@Qualifier
+@Documented
+@Retention(RUNTIME)
+public @interface UnseenNotificationLog {
+}
--- a/packages/SystemUI/src/com/android/systemui/statusbar/notification/collection/coordinator/KeyguardCoordinator.kt
+++ b/packages/SystemUI/src/com/android/systemui/statusbar/notification/collection/coordinator/KeyguardCoordinator.kt
@@ -21,8 +21,10 @@ package com.android.systemui.statusbar.notification.collection.coordinator
 import android.os.UserHandle
 import android.provider.Settings
 import androidx.annotation.VisibleForTesting
+import com.android.systemui.Dumpable
 import com.android.systemui.dagger.qualifiers.Application
 import com.android.systemui.dagger.qualifiers.Background
+import com.android.systemui.dump.DumpManager
 import com.android.systemui.keyguard.data.repository.KeyguardRepository
 import com.android.systemui.keyguard.data.repository.KeyguardTransitionRepository
 import com.android.systemui.keyguard.shared.model.KeyguardState
@@ -42,8 +44,14 @@ import com.android.systemui.statusbar.notification.collection.provider.SeenNotif
 import com.android.systemui.statusbar.notification.interruption.KeyguardNotificationVisibilityProvider
 import com.android.systemui.statusbar.policy.HeadsUpManager
 import com.android.systemui.statusbar.policy.headsUpEvents
+import com.android.systemui.util.asIndenting
+import com.android.systemui.util.indentIfPossible
 import com.android.systemui.util.settings.SecureSettings
 import com.android.systemui.util.settings.SettingsProxyExt.observerFlow
+import java.io.PrintWriter
+import javax.inject.Inject
+import kotlin.time.Duration
+import kotlin.time.Duration.Companion.seconds
 import kotlinx.coroutines.CoroutineDispatcher
 import kotlinx.coroutines.CoroutineScope
 import kotlinx.coroutines.ExperimentalCoroutinesApi
@@ -57,13 +65,11 @@ import kotlinx.coroutines.flow.emitAll
 import kotlinx.coroutines.flow.first
 import kotlinx.coroutines.flow.flowOn
 import kotlinx.coroutines.flow.map
+import kotlinx.coroutines.flow.onEach
 import kotlinx.coroutines.flow.onStart
 import kotlinx.coroutines.flow.transformLatest
 import kotlinx.coroutines.launch
 import kotlinx.coroutines.yield
-import javax.inject.Inject
-import kotlin.time.Duration
-import kotlin.time.Duration.Companion.seconds

 /**
 * Filters low priority and privacy-sensitive notifications from the lockscreen, and hides section
@@ -74,17 +80,19 @@ class KeyguardCoordinator
@Inject
 constructor(
    @Background private val bgDispatcher: CoroutineDispatcher,
+    private val dumpManager: DumpManager,
    private val headsUpManager: HeadsUpManager,
    private val keyguardNotificationVisibilityProvider: KeyguardNotificationVisibilityProvider,
    private val keyguardRepository: KeyguardRepository,
    private val keyguardTransitionRepository: KeyguardTransitionRepository,
+    private val logger: KeyguardCoordinatorLogger,
    private val notifPipelineFlags: NotifPipelineFlags,
    @Application private val scope: CoroutineScope,
    private val sectionHeaderVisibilityProvider: SectionHeaderVisibilityProvider,
    private val secureSettings: SecureSettings,
    private val seenNotifsProvider: SeenNotificationsProviderImpl,
    private val statusBarStateController: StatusBarStateController,
-) : Coordinator {
+) : Coordinator, Dumpable {

    private val unseenNotifications = mutableSetOf<NotificationEntry>()
    private var unseenFilterEnabled = false
@@ -103,6 +111,7 @@ constructor(
        pipeline.addCollectionListener(collectionListener)
        scope.launch { trackUnseenNotificationsWhileUnlocked() }
        scope.launch { invalidateWhenUnseenSettingChanges() }
+        dumpManager.registerDumpable(this)
    }

    private suspend fun trackUnseenNotificationsWhileUnlocked() {
@@ -122,14 +131,16 @@ constructor(
                        // If the screen is turning off, stop tracking, but if that transition is
                        // cancelled, then start again.
                        emitAll(
-                            keyguardTransitionRepository.transitions
-                                .map { step -> !step.isScreenTurningOff }
+                            keyguardTransitionRepository.transitions.map { step ->
+                                !step.isScreenTurningOff
+                            }
                        )
                    }
                }
                // Prevent double emit of `false` caused by transition to AOD, followed by keyguard
                // showing
                .distinctUntilChanged()
+                .onEach { trackingUnseen -> logger.logTrackingUnseen(trackingUnseen) }

        // Use collectLatest so that trackUnseenNotifications() is cancelled when the keyguard is
        // showing again
@@ -140,9 +151,11 @@ constructor(
                // set when unlocked
                awaitTimeSpentNotDozing(SEEN_TIMEOUT)
                clearUnseenOnBeginTracking = true
+                logger.logSeenOnLockscreen()
            } else {
                if (clearUnseenOnBeginTracking) {
                    clearUnseenOnBeginTracking = false
+                    logger.logAllMarkedSeenOnUnlock()
                    unseenNotifications.clear()
                }
                unseenNotifFilter.invalidateList("keyguard no longer showing")
@@ -166,6 +179,8 @@ constructor(
            .first()
    }

+    // Track "unseen" notifications, marking them as seen when either shade is expanded or the
+    // notification becomes heads up.
    private suspend fun trackUnseenNotifications() {
        coroutineScope {
            launch { clearUnseenNotificationsWhenShadeIsExpanded() }
@@ -179,6 +194,7 @@ constructor(
            // keyguard transition and not the user expanding the shade
            yield()
            if (isExpanded) {
+                logger.logShadeExpanded()
                unseenNotifications.clear()
            }
        }
@@ -190,6 +206,7 @@ constructor(
            .forEach { unseenNotifications.remove(it) }
        headsUpManager.headsUpEvents.collect { (entry, isHun) ->
            if (isHun) {
+                logger.logUnseenHun(entry.key)
                unseenNotifications.remove(entry)
            }
        }
@@ -231,6 +248,7 @@ constructor(
                if (
                    keyguardRepository.isKeyguardShowing() || !statusBarStateController.isExpanded
                ) {
+                    logger.logUnseenAdded(entry.key)
                    unseenNotifications.add(entry)
                }
            }
@@ -239,12 +257,15 @@ constructor(
                if (
                    keyguardRepository.isKeyguardShowing() || !statusBarStateController.isExpanded
                ) {
+                    logger.logUnseenUpdated(entry.key)
                    unseenNotifications.add(entry)
                }
            }

            override fun onEntryRemoved(entry: NotificationEntry, reason: Int) {
-                unseenNotifications.remove(entry)
+                if (unseenNotifications.remove(entry)) {
+                    logger.logUnseenRemoved(entry.key)
+                }
            }
        }

@@ -272,6 +293,7 @@ constructor(
                }.also { hasFiltered -> hasFilteredAnyNotifs = hasFilteredAnyNotifs || hasFiltered }

            override fun onCleanup() {
+                logger.logProviderHasFilteredOutSeenNotifs(hasFilteredAnyNotifs)
                seenNotifsProvider.hasFilteredOutSeenNotifications = hasFilteredAnyNotifs
                hasFilteredAnyNotifs = false
            }
@@ -306,11 +328,25 @@ constructor(
        sectionHeaderVisibilityProvider.sectionHeadersVisible = showSections
    }

+    override fun dump(pw: PrintWriter, args: Array<out String>) =
+        with(pw.asIndenting()) {
+            println(
+                "seenNotifsProvider.hasFilteredOutSeenNotifications=" +
+                    seenNotifsProvider.hasFilteredOutSeenNotifications
+            )
+            println("unseen notifications:")
+            indentIfPossible {
+                for (notification in unseenNotifications) {
+                    println(notification.key)
+                }
+            }
+        }
+
    companion object {
        private const val TAG = "KeyguardCoordinator"
        private val SEEN_TIMEOUT = 5.seconds
    }
 }

-private val TransitionStep.isScreenTurningOff: Boolean get() =
-    transitionState == TransitionState.STARTED && to != KeyguardState.GONE
+private val TransitionStep.isScreenTurningOff: Boolean
+    get() = transitionState == TransitionState.STARTED && to != KeyguardState.GONE
--- a/packages/SystemUI/src/com/android/systemui/statusbar/notification/collection/coordinator/KeyguardCoordinatorLogger.kt
+++ b/packages/SystemUI/src/com/android/systemui/statusbar/notification/collection/coordinator/KeyguardCoordinatorLogger.kt
@@ -0,0 +1,99 @@
+/*
+ * Copyright (C) 2023 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *      http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+package com.android.systemui.statusbar.notification.collection.coordinator
+
+import com.android.systemui.log.dagger.UnseenNotificationLog
+import com.android.systemui.plugins.log.LogBuffer
+import com.android.systemui.plugins.log.LogLevel
+import javax.inject.Inject
+
+private const val TAG = "KeyguardCoordinator"
+
+class KeyguardCoordinatorLogger
+@Inject
+constructor(
+    @UnseenNotificationLog private val buffer: LogBuffer,
+) {
+    fun logSeenOnLockscreen() =
+        buffer.log(
+            TAG,
+            LogLevel.DEBUG,
+            "Notifications on lockscreen will be marked as seen when unlocked."
+        )
+
+    fun logTrackingUnseen(trackingUnseen: Boolean) =
+        buffer.log(
+            TAG,
+            LogLevel.DEBUG,
+            messageInitializer = { bool1 = trackingUnseen },
+            messagePrinter = { "${if (bool1) "Start" else "Stop"} tracking unseen notifications." },
+        )
+
+    fun logAllMarkedSeenOnUnlock() =
+        buffer.log(
+            TAG,
+            LogLevel.DEBUG,
+            "Notifications have been marked as seen now that device is unlocked."
+        )
+
+    fun logShadeExpanded() =
+        buffer.log(
+            TAG,
+            LogLevel.DEBUG,
+            "Notifications have been marked as seen due to shade expansion."
+        )
+
+    fun logUnseenAdded(key: String) =
+        buffer.log(
+            TAG,
+            LogLevel.DEBUG,
+            messageInitializer = { str1 = key },
+            messagePrinter = { "Unseen notif added: $str1" },
+        )
+
+    fun logUnseenUpdated(key: String) =
+        buffer.log(
+            TAG,
+            LogLevel.DEBUG,
+            messageInitializer = { str1 = key },
+            messagePrinter = { "Unseen notif updated: $str1" },
+        )
+
+    fun logUnseenRemoved(key: String) =
+        buffer.log(
+            TAG,
+            LogLevel.DEBUG,
+            messageInitializer = { str1 = key },
+            messagePrinter = { "Unseen notif removed: $str1" },
+        )
+
+    fun logProviderHasFilteredOutSeenNotifs(hasFilteredAnyNotifs: Boolean) =
+        buffer.log(
+            TAG,
+            LogLevel.DEBUG,
+            messageInitializer = { bool1 = hasFilteredAnyNotifs },
+            messagePrinter = { "UI showing unseen filter treatment: $bool1" },
+        )
+
+    fun logUnseenHun(key: String) =
+        buffer.log(
+            TAG,
+            LogLevel.DEBUG,
+            messageInitializer = { str1 = key },
+            messagePrinter = { "Unseen notif has become heads up: $str1" },
+        )
+}
--- a/packages/SystemUI/tests/src/com/android/systemui/statusbar/notification/collection/coordinator/KeyguardCoordinatorTest.kt
+++ b/packages/SystemUI/tests/src/com/android/systemui/statusbar/notification/collection/coordinator/KeyguardCoordinatorTest.kt
@@ -24,6 +24,7 @@ import android.testing.AndroidTestingRunner
 import androidx.test.filters.SmallTest
 import com.android.systemui.SysuiTestCase
 import com.android.systemui.coroutines.advanceTimeBy
+import com.android.systemui.dump.DumpManager
 import com.android.systemui.keyguard.data.repository.FakeKeyguardRepository
 import com.android.systemui.keyguard.data.repository.FakeKeyguardTransitionRepository
 import com.android.systemui.keyguard.shared.model.KeyguardState
@@ -380,10 +381,12 @@ class KeyguardCoordinatorTest : SysuiTestCase() {
        val keyguardCoordinator =
            KeyguardCoordinator(
                testDispatcher,
+                mock<DumpManager>(),
                headsUpManager,
                keyguardNotifVisibilityProvider,
                keyguardRepository,
                keyguardTransitionRepository,
+                mock<KeyguardCoordinatorLogger>(),
                notifPipelineFlags,
                testScope.backgroundScope,
                sectionHeaderVisibilityProvider,