Merge "Add logs for BroadcastDispatcher" into rvc-dev

9 files changed, 258 insertions, 13 deletions

diff --git a/packages/SystemUI/src/com/android/systemui/broadcast/BroadcastDispatcher.kt b/packages/SystemUI/src/com/android/systemui/broadcast/BroadcastDispatcher.kt
index 4269605cef12..d61de0623fe8 100644
--- a/packages/SystemUI/src/com/android/systemui/broadcast/BroadcastDispatcher.kt
+++ b/packages/SystemUI/src/com/android/systemui/broadcast/BroadcastDispatcher.kt
@@ -28,12 +28,12 @@ import android.text.TextUtils
 import android.util.SparseArray
 import com.android.internal.annotations.VisibleForTesting
 import com.android.systemui.Dumpable
+import com.android.systemui.broadcast.logging.BroadcastDispatcherLogger
 import com.android.systemui.dagger.qualifiers.Background
 import com.android.systemui.dagger.qualifiers.Main
 import com.android.systemui.dump.DumpManager
 import java.io.FileDescriptor
 import java.io.PrintWriter
-import java.lang.IllegalStateException
 import java.util.concurrent.Executor
 import javax.inject.Inject
 import javax.inject.Singleton
@@ -67,7 +67,8 @@ open class BroadcastDispatcher @Inject constructor (
     private val context: Context,
     @Main private val mainHandler: Handler,
     @Background private val bgLooper: Looper,
-    dumpManager: DumpManager
+    dumpManager: DumpManager,
+    private val logger: BroadcastDispatcherLogger
 ) : Dumpable {
 
     // Only modify in BG thread
@@ -156,7 +157,7 @@ open class BroadcastDispatcher @Inject constructor (
     /**
      * Unregister receiver for a particular user.
      *
-     * @param receiver The receiver to unregister. It will be unregistered for all users.
+     * @param receiver The receiver to unregister.
      * @param user The user associated to the registered [receiver]. It can be [UserHandle.ALL].
      */
     open fun unregisterReceiverForUser(receiver: BroadcastReceiver, user: UserHandle) {
@@ -166,7 +167,7 @@ open class BroadcastDispatcher @Inject constructor (
 
     @VisibleForTesting
     protected open fun createUBRForUser(userId: Int) =
-            UserBroadcastDispatcher(context, userId, bgLooper)
+            UserBroadcastDispatcher(context, userId, bgLooper, logger)
 
     override fun dump(fd: FileDescriptor, pw: PrintWriter, args: Array<out String>) {
         pw.println("Broadcast dispatcher:")
diff --git a/packages/SystemUI/src/com/android/systemui/broadcast/UserBroadcastDispatcher.kt b/packages/SystemUI/src/com/android/systemui/broadcast/UserBroadcastDispatcher.kt
index 3272fb7545e2..96f5a1f6fbe8 100644
--- a/packages/SystemUI/src/com/android/systemui/broadcast/UserBroadcastDispatcher.kt
+++ b/packages/SystemUI/src/com/android/systemui/broadcast/UserBroadcastDispatcher.kt
@@ -30,6 +30,7 @@ import android.util.Log
 import androidx.annotation.VisibleForTesting
 import com.android.internal.util.Preconditions
 import com.android.systemui.Dumpable
+import com.android.systemui.broadcast.logging.BroadcastDispatcherLogger
 import java.io.FileDescriptor
 import java.io.PrintWriter
 import java.lang.IllegalArgumentException
@@ -54,7 +55,8 @@ private const val DEBUG = false
 class UserBroadcastDispatcher(
     private val context: Context,
     private val userId: Int,
-    private val bgLooper: Looper
+    private val bgLooper: Looper,
+    private val logger: BroadcastDispatcherLogger
 ) : BroadcastReceiver(), Dumpable {
 
     companion object {
@@ -109,10 +111,12 @@ class UserBroadcastDispatcher(
     }
 
     override fun onReceive(context: Context, intent: Intent) {
-        val id = if (DEBUG) index.getAndIncrement() else 0
+        val id = index.getAndIncrement()
         if (DEBUG) Log.w(TAG, "[$id] Received $intent")
+        logger.logBroadcastReceived(id, userId, intent)
         bgHandler.post(
-                HandleBroadcastRunnable(actionsToReceivers, context, intent, pendingResult, id))
+                HandleBroadcastRunnable(
+                        actionsToReceivers, context, intent, pendingResult, id, logger))
     }
 
     /**
@@ -143,6 +147,7 @@ class UserBroadcastDispatcher(
                 ArraySet()
             }.add(receiverData)
         }
+        logger.logReceiverRegistered(userId, receiverData.receiver)
         if (changed) {
             createFilterAndRegisterReceiverBG()
         }
@@ -163,6 +168,7 @@ class UserBroadcastDispatcher(
                 actionsToReceivers.remove(action)
             }
         }
+        logger.logReceiverUnregistered(userId, receiver)
         if (changed) {
             createFilterAndRegisterReceiverBG()
         }
@@ -187,7 +193,8 @@ class UserBroadcastDispatcher(
         val context: Context,
         val intent: Intent,
         val pendingResult: PendingResult,
-        val index: Int
+        val index: Int,
+        val logger: BroadcastDispatcherLogger
     ) : Runnable {
         override fun run() {
             if (DEBUG) Log.w(TAG, "[$index] Dispatching $intent")
@@ -199,6 +206,7 @@ class UserBroadcastDispatcher(
                         it.executor.execute {
                             if (DEBUG) Log.w(TAG,
                                     "[$index] Dispatching ${intent.action} to ${it.receiver}")
+                            logger.logBroadcastDispatched(index, intent.action, it.receiver)
                             it.receiver.pendingResult = pendingResult
                             it.receiver.onReceive(context, intent)
                         }
@@ -215,6 +223,7 @@ class UserBroadcastDispatcher(
             if (registered.get()) {
                 try {
                     context.unregisterReceiver(this@UserBroadcastDispatcher)
+                    logger.logContextReceiverUnregistered(userId)
                 } catch (e: IllegalArgumentException) {
                     Log.e(TAG, "Trying to unregister unregistered receiver for user $userId",
                             IllegalStateException(e))
@@ -230,6 +239,7 @@ class UserBroadcastDispatcher(
                         null,
                         bgHandler)
                 registered.set(true)
+                logger.logContextReceiverRegistered(userId, intentFilter)
             }
         }
     }
diff --git a/packages/SystemUI/src/com/android/systemui/broadcast/logging/BroadcastDispatcherLogger.kt b/packages/SystemUI/src/com/android/systemui/broadcast/logging/BroadcastDispatcherLogger.kt
new file mode 100644
index 000000000000..123a8ae6307d
--- /dev/null
+++ b/packages/SystemUI/src/com/android/systemui/broadcast/logging/BroadcastDispatcherLogger.kt
@@ -0,0 +1,117 @@
+/*
+ * Copyright (C) 2020 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.broadcast.logging
+
+import android.content.BroadcastReceiver
+import android.content.Intent
+import android.content.IntentFilter
+import com.android.systemui.log.LogBuffer
+import com.android.systemui.log.LogLevel
+import com.android.systemui.log.LogLevel.DEBUG
+import com.android.systemui.log.LogLevel.INFO
+import com.android.systemui.log.LogMessage
+import com.android.systemui.log.dagger.BroadcastDispatcherLog
+import javax.inject.Inject
+
+private const val TAG = "BroadcastDispatcherLog"
+
+class BroadcastDispatcherLogger @Inject constructor(
+    @BroadcastDispatcherLog private val buffer: LogBuffer
+) {
+
+    fun logBroadcastReceived(broadcastId: Int, user: Int, intent: Intent) {
+        val intentString = intent.toString()
+        log(INFO, {
+            int1 = broadcastId
+            int2 = user
+            str1 = intentString
+        }, {
+            "[$int1] Broadcast received for user $int2: $str1"
+        })
+    }
+
+    fun logBroadcastDispatched(broadcastId: Int, action: String?, receiver: BroadcastReceiver) {
+        val receiverString = receiver.toString()
+        log(DEBUG, {
+            int1 = broadcastId
+            str1 = action
+            str2 = receiverString
+        }, {
+            "Broadcast $int1 ($str1) dispatched to $str2"
+        })
+    }
+
+    fun logReceiverRegistered(user: Int, receiver: BroadcastReceiver) {
+        val receiverString = receiver.toString()
+        log(INFO, {
+            int1 = user
+            str1 = receiverString
+        }, {
+            "Receiver $str1 registered for user $int1"
+        })
+    }
+
+    fun logReceiverUnregistered(user: Int, receiver: BroadcastReceiver) {
+        val receiverString = receiver.toString()
+        log(INFO, {
+            int1 = user
+            str1 = receiverString
+        }, {
+            "Receiver $str1 unregistered for user $int1"
+        })
+    }
+
+    fun logContextReceiverRegistered(user: Int, filter: IntentFilter) {
+        val actions = filter.actionsIterator().asSequence()
+                .joinToString(separator = ",", prefix = "Actions(", postfix = ")")
+        val categories = if (filter.countCategories() != 0) {
+            filter.categoriesIterator().asSequence()
+                    .joinToString(separator = ",", prefix = "Categories(", postfix = ")")
+        } else {
+            ""
+        }
+        log(INFO, {
+            int1 = user
+            str1 = if (categories != "") {
+                "${actions}\n$categories"
+            } else {
+                actions
+            }
+        }, {
+            """
+                Receiver registered with Context for user $int1.
+                $str1
+            """.trimIndent()
+        })
+    }
+
+    fun logContextReceiverUnregistered(user: Int) {
+        log(INFO, {
+            int1 = user
+        }, {
+            "Receiver unregistered with Context for user $int1."
+        })
+    }
+
+    private inline fun log(
+        logLevel: LogLevel,
+        initializer: LogMessage.() -> Unit,
+        noinline printer: LogMessage.() -> String
+    ) {
+        buffer.log(TAG, logLevel, initializer, printer)
+    }
+}
\ No newline at end of file
diff --git a/packages/SystemUI/src/com/android/systemui/log/dagger/BroadcastDispatcherLog.java b/packages/SystemUI/src/com/android/systemui/log/dagger/BroadcastDispatcherLog.java
new file mode 100644
index 000000000000..7d1f1c2709fa
--- /dev/null
+++ b/packages/SystemUI/src/com/android/systemui/log/dagger/BroadcastDispatcherLog.java
@@ -0,0 +1,33 @@
+/*
+ * Copyright (C) 2020 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.log.LogBuffer;
+
+import java.lang.annotation.Documented;
+import java.lang.annotation.Retention;
+
+import javax.inject.Qualifier;
+
+/** A {@link LogBuffer} for BroadcastDispatcher-related messages. */
+@Qualifier
+@Documented
+@Retention(RUNTIME)
+public @interface BroadcastDispatcherLog {
+}
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 9c89fee5cba1..a2086e8d3ac6 100644
--- a/packages/SystemUI/src/com/android/systemui/log/dagger/LogModule.java
+++ b/packages/SystemUI/src/com/android/systemui/log/dagger/LogModule.java
@@ -97,6 +97,18 @@ public class LogModule {
         return buffer;
     }
 
+    /** Provides a logging buffer for {@link com.android.systemui.broadcast.BroadcastDispatcher} */
+    @Provides
+    @Singleton
+    @BroadcastDispatcherLog
+    public static LogBuffer provideBroadcastDispatcherLogBuffer(
+            LogcatEchoTracker bufferFilter,
+            DumpManager dumpManager) {
+        LogBuffer buffer = new LogBuffer("BroadcastDispatcherLog", 500, 10, bufferFilter);
+        buffer.attach(dumpManager);
+        return buffer;
+    }
+
     /** Allows logging buffers to be tweaked via adb on debug builds but not on prod builds. */
     @Provides
     @Singleton
diff --git a/packages/SystemUI/tests/src/com/android/systemui/SysuiTestCase.java b/packages/SystemUI/tests/src/com/android/systemui/SysuiTestCase.java
index b2c35867e789..aa3f91a22208 100644
--- a/packages/SystemUI/tests/src/com/android/systemui/SysuiTestCase.java
+++ b/packages/SystemUI/tests/src/com/android/systemui/SysuiTestCase.java
@@ -35,6 +35,7 @@ import com.android.keyguard.KeyguardUpdateMonitor;
 import com.android.settingslib.bluetooth.LocalBluetoothManager;
 import com.android.systemui.broadcast.BroadcastDispatcher;
 import com.android.systemui.broadcast.FakeBroadcastDispatcher;
+import com.android.systemui.broadcast.logging.BroadcastDispatcherLogger;
 import com.android.systemui.classifier.FalsingManagerFake;
 import com.android.systemui.dump.DumpManager;
 import com.android.systemui.plugins.FalsingManager;
@@ -73,7 +74,7 @@ public abstract class SysuiTestCase {
         SystemUIFactory.createFromConfig(mContext);
         mDependency = new TestableDependency(mContext);
         mFakeBroadcastDispatcher = new FakeBroadcastDispatcher(mContext, mock(Handler.class),
-                mock(Looper.class), mock(DumpManager.class));
+                mock(Looper.class), mock(DumpManager.class), mock(BroadcastDispatcherLogger.class));
 
         mRealInstrumentation = InstrumentationRegistry.getInstrumentation();
         Instrumentation inst = spy(mRealInstrumentation);
diff --git a/packages/SystemUI/tests/src/com/android/systemui/broadcast/BroadcastDispatcherTest.kt b/packages/SystemUI/tests/src/com/android/systemui/broadcast/BroadcastDispatcherTest.kt
index 3357c5863d46..86ddb209f321 100644
--- a/packages/SystemUI/tests/src/com/android/systemui/broadcast/BroadcastDispatcherTest.kt
+++ b/packages/SystemUI/tests/src/com/android/systemui/broadcast/BroadcastDispatcherTest.kt
@@ -27,6 +27,7 @@ import android.test.suitebuilder.annotation.SmallTest
 import android.testing.AndroidTestingRunner
 import android.testing.TestableLooper
 import com.android.systemui.SysuiTestCase
+import com.android.systemui.broadcast.logging.BroadcastDispatcherLogger
 import com.android.systemui.dump.DumpManager
 import com.android.systemui.util.concurrency.FakeExecutor
 import com.android.systemui.util.time.FakeSystemClock
@@ -76,6 +77,8 @@ class BroadcastDispatcherTest : SysuiTestCase() {
     private lateinit var intentFilterOther: IntentFilter
     @Mock
     private lateinit var mockHandler: Handler
+    @Mock
+    private lateinit var logger: BroadcastDispatcherLogger
 
     private lateinit var executor: Executor
 
@@ -96,6 +99,7 @@ class BroadcastDispatcherTest : SysuiTestCase() {
                 Handler(testableLooper.looper),
                 testableLooper.looper,
                 mock(DumpManager::class.java),
+                logger,
                 mapOf(0 to mockUBRUser0, 1 to mockUBRUser1))
 
         // These should be valid filters
@@ -239,8 +243,9 @@ class BroadcastDispatcherTest : SysuiTestCase() {
         mainHandler: Handler,
         bgLooper: Looper,
         dumpManager: DumpManager,
+        logger: BroadcastDispatcherLogger,
         var mockUBRMap: Map<Int, UserBroadcastDispatcher>
-    ) : BroadcastDispatcher(context, mainHandler, bgLooper, dumpManager) {
+    ) : BroadcastDispatcher(context, mainHandler, bgLooper, dumpManager, logger) {
         override fun createUBRForUser(userId: Int): UserBroadcastDispatcher {
             return mockUBRMap.getOrDefault(userId, mock(UserBroadcastDispatcher::class.java))
         }
diff --git a/packages/SystemUI/tests/src/com/android/systemui/broadcast/FakeBroadcastDispatcher.kt b/packages/SystemUI/tests/src/com/android/systemui/broadcast/FakeBroadcastDispatcher.kt
index 9a5773a7a3b4..6e982e26b8cb 100644
--- a/packages/SystemUI/tests/src/com/android/systemui/broadcast/FakeBroadcastDispatcher.kt
+++ b/packages/SystemUI/tests/src/com/android/systemui/broadcast/FakeBroadcastDispatcher.kt
@@ -24,6 +24,7 @@ import android.os.UserHandle
 import android.util.ArraySet
 import android.util.Log
 import com.android.systemui.SysuiTestableContext
+import com.android.systemui.broadcast.logging.BroadcastDispatcherLogger
 import com.android.systemui.dump.DumpManager
 import java.util.concurrent.Executor
 
@@ -31,8 +32,9 @@ class FakeBroadcastDispatcher(
     context: SysuiTestableContext,
     handler: Handler,
     looper: Looper,
-    dumpManager: DumpManager
-) : BroadcastDispatcher(context, handler, looper, dumpManager) {
+    dumpManager: DumpManager,
+    logger: BroadcastDispatcherLogger
+) : BroadcastDispatcher(context, handler, looper, dumpManager, logger) {
 
     private val registeredReceivers = ArraySet<BroadcastReceiver>()
 
diff --git a/packages/SystemUI/tests/src/com/android/systemui/broadcast/UserBroadcastDispatcherTest.kt b/packages/SystemUI/tests/src/com/android/systemui/broadcast/UserBroadcastDispatcherTest.kt
index 847e442f1a49..443357694f4d 100644
--- a/packages/SystemUI/tests/src/com/android/systemui/broadcast/UserBroadcastDispatcherTest.kt
+++ b/packages/SystemUI/tests/src/com/android/systemui/broadcast/UserBroadcastDispatcherTest.kt
@@ -26,6 +26,7 @@ import android.test.suitebuilder.annotation.SmallTest
 import android.testing.AndroidTestingRunner
 import android.testing.TestableLooper
 import com.android.systemui.SysuiTestCase
+import com.android.systemui.broadcast.logging.BroadcastDispatcherLogger
 import com.android.systemui.util.concurrency.FakeExecutor
 import com.android.systemui.util.time.FakeSystemClock
 import junit.framework.Assert.assertEquals
@@ -40,6 +41,7 @@ import org.mockito.ArgumentMatchers.anyInt
 import org.mockito.ArgumentMatchers.eq
 import org.mockito.Captor
 import org.mockito.Mock
+import org.mockito.Mockito
 import org.mockito.Mockito.anyString
 import org.mockito.Mockito.atLeastOnce
 import org.mockito.Mockito.never
@@ -62,6 +64,8 @@ class UserBroadcastDispatcherTest : SysuiTestCase() {
         private val USER_HANDLE = UserHandle.of(USER_ID)
 
         fun <T> capture(argumentCaptor: ArgumentCaptor<T>): T = argumentCaptor.capture()
+        fun <T> any(): T = Mockito.any()
+        fun <T> eq(v: T) = Mockito.eq(v) ?: v
     }
 
     @Mock
@@ -72,6 +76,8 @@ class UserBroadcastDispatcherTest : SysuiTestCase() {
     private lateinit var mockContext: Context
     @Mock
     private lateinit var mPendingResult: BroadcastReceiver.PendingResult
+    @Mock
+    private lateinit var logger: BroadcastDispatcherLogger
 
     @Captor
     private lateinit var argumentCaptor: ArgumentCaptor<IntentFilter>
@@ -91,7 +97,7 @@ class UserBroadcastDispatcherTest : SysuiTestCase() {
         fakeExecutor = FakeExecutor(FakeSystemClock())
 
         userBroadcastDispatcher = UserBroadcastDispatcher(
-                mockContext, USER_ID, testableLooper.looper)
+                mockContext, USER_ID, testableLooper.looper, logger)
         userBroadcastDispatcher.pendingResult = mPendingResult
     }
 
@@ -106,6 +112,13 @@ class UserBroadcastDispatcherTest : SysuiTestCase() {
     }
 
     @Test
+    fun testNotRegisteredOnStart_logging() {
+        testableLooper.processAllMessages()
+
+        verify(logger, never()).logContextReceiverRegistered(anyInt(), any())
+    }
+
+    @Test
     fun testSingleReceiverRegistered() {
         intentFilter = IntentFilter(ACTION_1)
 
@@ -126,6 +139,18 @@ class UserBroadcastDispatcherTest : SysuiTestCase() {
     }
 
     @Test
+    fun testSingleReceiverRegistered_logging() {
+        intentFilter = IntentFilter(ACTION_1)
+
+        userBroadcastDispatcher.registerReceiver(
+                ReceiverData(broadcastReceiver, intentFilter, fakeExecutor, USER_HANDLE))
+        testableLooper.processAllMessages()
+
+        verify(logger).logReceiverRegistered(USER_HANDLE.identifier, broadcastReceiver)
+        verify(logger).logContextReceiverRegistered(eq(USER_HANDLE.identifier), any())
+    }
+
+    @Test
     fun testSingleReceiverUnregistered() {
         intentFilter = IntentFilter(ACTION_1)
 
@@ -145,6 +170,21 @@ class UserBroadcastDispatcherTest : SysuiTestCase() {
     }
 
     @Test
+    fun testSingleReceiverUnregistered_logger() {
+        intentFilter = IntentFilter(ACTION_1)
+
+        userBroadcastDispatcher.registerReceiver(
+                ReceiverData(broadcastReceiver, intentFilter, fakeExecutor, USER_HANDLE))
+        testableLooper.processAllMessages()
+
+        userBroadcastDispatcher.unregisterReceiver(broadcastReceiver)
+        testableLooper.processAllMessages()
+
+        verify(logger).logReceiverUnregistered(USER_HANDLE.identifier, broadcastReceiver)
+        verify(logger).logContextReceiverUnregistered(USER_HANDLE.identifier)
+    }
+
+    @Test
     fun testFilterHasAllActionsAndCategories_twoReceivers() {
         intentFilter = IntentFilter(ACTION_1)
         intentFilterOther = IntentFilter(ACTION_2).apply {
@@ -196,6 +236,30 @@ class UserBroadcastDispatcherTest : SysuiTestCase() {
     }
 
     @Test
+    fun testDispatch_logger() {
+        intentFilter = IntentFilter(ACTION_1)
+        intentFilterOther = IntentFilter(ACTION_2)
+
+        userBroadcastDispatcher.registerReceiver(
+                ReceiverData(broadcastReceiver, intentFilter, fakeExecutor, USER_HANDLE))
+        userBroadcastDispatcher.registerReceiver(
+                ReceiverData(broadcastReceiverOther, intentFilterOther, fakeExecutor, USER_HANDLE))
+
+        val intent = Intent(ACTION_2)
+
+        userBroadcastDispatcher.onReceive(mockContext, intent)
+        testableLooper.processAllMessages()
+        fakeExecutor.runAllReady()
+
+        val captor = ArgumentCaptor.forClass(Int::class.java)
+        verify(logger)
+                .logBroadcastReceived(captor.capture(), eq(USER_HANDLE.identifier), eq(intent))
+        verify(logger).logBroadcastDispatched(captor.value, ACTION_2, broadcastReceiverOther)
+        verify(logger, never())
+                .logBroadcastDispatched(eq(captor.value), any(), eq(broadcastReceiver))
+    }
+
+    @Test
     fun testDispatchToCorrectReceiver_differentFiltersSameReceiver() {
         intentFilter = IntentFilter(ACTION_1)
         intentFilterOther = IntentFilter(ACTION_2)