Merge "Freeze log buffers when a bug report is taken" into rvc-dev

Ned Burns · Android (Google) Code Review · commit 9d4f3850ee35 · 2020-06-01T22:00:26.000Z
diff --git a/packages/SystemUI/src/com/android/systemui/SystemUIService.java b/packages/SystemUI/src/com/android/systemui/SystemUIService.java
@@ -27,8 +27,10 @@
 import android.util.Slog;
 
 import com.android.internal.os.BinderInternal;
+import com.android.systemui.broadcast.BroadcastDispatcher;
 import com.android.systemui.dagger.qualifiers.Main;
 import com.android.systemui.dump.DumpHandler;
+import com.android.systemui.dump.LogBufferFreezer;
 import com.android.systemui.dump.SystemUIAuxiliaryDumpService;
 
 import java.io.FileDescriptor;
@@ -40,21 +42,32 @@ public class SystemUIService extends Service {
 
     private final Handler mMainHandler;
     private final DumpHandler mDumpHandler;
+    private final BroadcastDispatcher mBroadcastDispatcher;
+    private final LogBufferFreezer mLogBufferFreezer;
 
     @Inject
     public SystemUIService(
             @Main Handler mainHandler,
-            DumpHandler dumpHandler) {
+            DumpHandler dumpHandler,
+            BroadcastDispatcher broadcastDispatcher,
+            LogBufferFreezer logBufferFreezer) {
         super();
         mMainHandler = mainHandler;
         mDumpHandler = dumpHandler;
+        mBroadcastDispatcher = broadcastDispatcher;
+        mLogBufferFreezer = logBufferFreezer;
     }
 
     @Override
     public void onCreate() {
         super.onCreate();
+
+        // Start all of SystemUI
         ((SystemUIApplication) getApplication()).startServicesIfNeeded();
 
+        // Finish initializing dump logic
+        mLogBufferFreezer.attach(mBroadcastDispatcher);
+
         // For debugging RescueParty
         if (Build.IS_DEBUGGABLE && SystemProperties.getBoolean("debug.crash_sysui", false)) {
             throw new RuntimeException();
diff --git a/packages/SystemUI/src/com/android/systemui/dump/DumpManager.kt b/packages/SystemUI/src/com/android/systemui/dump/DumpManager.kt
@@ -140,6 +140,20 @@ class DumpManager @Inject constructor() {
         }
     }
 
+    @Synchronized
+    fun freezeBuffers() {
+        for (buffer in buffers.values) {
+            buffer.dumpable.freeze()
+        }
+    }
+
+    @Synchronized
+    fun unfreezeBuffers() {
+        for (buffer in buffers.values) {
+            buffer.dumpable.unfreeze()
+        }
+    }
+
     private fun dumpDumpable(
         dumpable: RegisteredDumpable<Dumpable>,
         fd: FileDescriptor,
@@ -174,3 +188,5 @@ private data class RegisteredDumpable<T>(
     val name: String,
     val dumpable: T
 )
+
+private const val TAG = "DumpManager"
diff --git a/packages/SystemUI/src/com/android/systemui/dump/LogBufferFreezer.kt b/packages/SystemUI/src/com/android/systemui/dump/LogBufferFreezer.kt
@@ -0,0 +1,69 @@
+/*
+ * 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.dump
+
+import android.content.BroadcastReceiver
+import android.content.Context
+import android.content.Intent
+import android.content.IntentFilter
+import android.os.UserHandle
+import android.util.Log
+import com.android.systemui.broadcast.BroadcastDispatcher
+import com.android.systemui.dagger.qualifiers.Main
+import com.android.systemui.util.concurrency.DelayableExecutor
+import java.util.concurrent.TimeUnit
+import javax.inject.Inject
+
+class LogBufferFreezer constructor(
+    private val dumpManager: DumpManager,
+    @Main private val executor: DelayableExecutor,
+    private val freezeDuration: Long
+) {
+    @Inject constructor(
+        dumpManager: DumpManager,
+        @Main executor: DelayableExecutor
+    ) : this(dumpManager, executor, TimeUnit.MINUTES.toMillis(5))
+
+    private var pendingToken: Runnable? = null
+
+    fun attach(broadcastDispatcher: BroadcastDispatcher) {
+        broadcastDispatcher.registerReceiver(
+                object : BroadcastReceiver() {
+                    override fun onReceive(context: Context?, intent: Intent?) {
+                        onBugreportStarted()
+                    }
+                },
+                IntentFilter("com.android.internal.intent.action.BUGREPORT_STARTED"),
+                executor,
+                UserHandle.ALL)
+    }
+
+    private fun onBugreportStarted() {
+        pendingToken?.run()
+
+        Log.i(TAG, "Freezing log buffers")
+        dumpManager.freezeBuffers()
+
+        pendingToken = executor.executeDelayed({
+            Log.i(TAG, "Unfreezing log buffers")
+            pendingToken = null
+            dumpManager.unfreezeBuffers()
+        }, freezeDuration)
+    }
+}
+
+private const val TAG = "LogBufferFreezer"
diff --git a/packages/SystemUI/src/com/android/systemui/log/LogBuffer.kt b/packages/SystemUI/src/com/android/systemui/log/LogBuffer.kt
@@ -74,6 +74,9 @@ class LogBuffer(
 ) {
     private val buffer: ArrayDeque<LogMessageImpl> = ArrayDeque()
 
+    var frozen = false
+        private set
+
     fun attach(dumpManager: DumpManager) {
         dumpManager.registerBuffer(name, this)
     }
@@ -112,9 +115,11 @@ class LogBuffer(
         initializer: LogMessage.() -> Unit,
         noinline printer: LogMessage.() -> String
     ) {
-        val message = obtain(tag, level, printer)
-        initializer(message)
-        push(message)
+        if (!frozen) {
+            val message = obtain(tag, level, printer)
+            initializer(message)
+            push(message)
+        }
     }
 
     /**
@@ -139,17 +144,16 @@ class LogBuffer(
      *
      * In general, you should call [log] or [document] instead of this method.
      */
+    @Synchronized
     fun obtain(
         tag: String,
         level: LogLevel,
         printer: (LogMessage) -> String
     ): LogMessageImpl {
-        val message = synchronized(buffer) {
-            if (buffer.size > maxLogs - poolSize) {
-                buffer.removeFirst()
-            } else {
-                LogMessageImpl.create()
-            }
+        val message = when {
+            frozen -> LogMessageImpl.create()
+            buffer.size > maxLogs - poolSize -> buffer.removeFirst()
+            else -> LogMessageImpl.create()
         }
         message.reset(tag, level, System.currentTimeMillis(), printer)
         return message
@@ -158,33 +162,58 @@ class LogBuffer(
     /**
      * Pushes a message into buffer, possibly evicting an older message if the buffer is full.
      */
+    @Synchronized
     fun push(message: LogMessage) {
-        synchronized(buffer) {
-            if (buffer.size == maxLogs) {
-                Log.e(TAG, "LogBuffer $name has exceeded its pool size")
-                buffer.removeFirst()
-            }
-            buffer.add(message as LogMessageImpl)
-            if (logcatEchoTracker.isBufferLoggable(name, message.level) ||
-                    logcatEchoTracker.isTagLoggable(message.tag, message.level)) {
-                echoToLogcat(message)
-            }
+        if (frozen) {
+            return
+        }
+        if (buffer.size == maxLogs) {
+            Log.e(TAG, "LogBuffer $name has exceeded its pool size")
+            buffer.removeFirst()
+        }
+        buffer.add(message as LogMessageImpl)
+        if (logcatEchoTracker.isBufferLoggable(name, message.level) ||
+                logcatEchoTracker.isTagLoggable(message.tag, message.level)) {
+            echoToLogcat(message)
         }
     }
 
     /** Converts the entire buffer to a newline-delimited string */
+    @Synchronized
     fun dump(pw: PrintWriter, tailLength: Int) {
-        synchronized(buffer) {
-            val start = if (tailLength <= 0) { 0 } else { buffer.size - tailLength }
+        val start = if (tailLength <= 0) { 0 } else { buffer.size - tailLength }
 
-            for ((i, message) in buffer.withIndex()) {
-                if (i >= start) {
-                    dumpMessage(message, pw)
-                }
+        for ((i, message) in buffer.withIndex()) {
+            if (i >= start) {
+                dumpMessage(message, pw)
             }
         }
     }
 
+    /**
+     * "Freezes" the contents of the buffer, making them immutable until [unfreeze] is called.
+     * Calls to [log], [document], [obtain], and [push] will not affect the buffer and will return
+     * dummy values if necessary.
+     */
+    @Synchronized
+    fun freeze() {
+        if (!frozen) {
+            log(TAG, LogLevel.DEBUG, { str1 = name }, { "$str1 frozen" })
+            frozen = true
+        }
+    }
+
+    /**
+     * Undoes the effects of calling [freeze].
+     */
+    @Synchronized
+    fun unfreeze() {
+        if (frozen) {
+            log(TAG, LogLevel.DEBUG, { str1 = name }, { "$str1 unfrozen" })
+            frozen = false
+        }
+    }
+
     private fun dumpMessage(message: LogMessage, pw: PrintWriter) {
         pw.print(DATE_FORMAT.format(message.timestamp))
         pw.print(" ")
diff --git a/packages/SystemUI/tests/src/com/android/systemui/dump/LogBufferFreezerTest.kt b/packages/SystemUI/tests/src/com/android/systemui/dump/LogBufferFreezerTest.kt
@@ -0,0 +1,116 @@
+/*
+ * 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.dump
+
+import android.content.BroadcastReceiver
+import android.content.IntentFilter
+import android.os.UserHandle
+import androidx.test.filters.SmallTest
+import com.android.systemui.SysuiTestCase
+import com.android.systemui.broadcast.BroadcastDispatcher
+import com.android.systemui.util.concurrency.FakeExecutor
+import com.android.systemui.util.mockito.any
+import com.android.systemui.util.mockito.capture
+import com.android.systemui.util.mockito.eq
+import com.android.systemui.util.time.FakeSystemClock
+import org.junit.Before
+import org.junit.Test
+import org.mockito.ArgumentCaptor
+import org.mockito.Captor
+import org.mockito.Mock
+import org.mockito.Mockito.never
+import org.mockito.Mockito.times
+import org.mockito.Mockito.verify
+import org.mockito.MockitoAnnotations
+
+@SmallTest
+class LogBufferFreezerTest : SysuiTestCase() {
+
+    lateinit var freezer: LogBufferFreezer
+    lateinit var receiver: BroadcastReceiver
+
+    @Mock
+    lateinit var dumpManager: DumpManager
+    @Mock
+    lateinit var broadcastDispatcher: BroadcastDispatcher
+    @Captor
+    lateinit var receiverCaptor: ArgumentCaptor<BroadcastReceiver>
+
+    val clock = FakeSystemClock()
+    val executor = FakeExecutor(clock)
+
+    @Before
+    fun setUp() {
+        MockitoAnnotations.initMocks(this)
+
+        freezer = LogBufferFreezer(dumpManager, executor, 500)
+
+        freezer.attach(broadcastDispatcher)
+
+        verify(broadcastDispatcher)
+                .registerReceiver(
+                        capture(receiverCaptor),
+                        any(IntentFilter::class.java),
+                        eq(executor),
+                        any(UserHandle::class.java))
+        receiver = receiverCaptor.value
+    }
+
+    @Test
+    fun testBuffersAreFrozenInResponseToBroadcast() {
+        // WHEN the bugreport intent is fired
+        receiver.onReceive(null, null)
+
+        // THEN the buffers are frozen
+        verify(dumpManager).freezeBuffers()
+    }
+
+    @Test
+    fun testBuffersAreUnfrozenAfterTimeout() {
+        // GIVEN that we've already frozen the buffers in response to a broadcast
+        receiver.onReceive(null, null)
+        verify(dumpManager).freezeBuffers()
+
+        // WHEN the timeout expires
+        clock.advanceTime(501)
+
+        // THEN the buffers are unfrozen
+        verify(dumpManager).unfreezeBuffers()
+    }
+
+    @Test
+    fun testBuffersAreNotPrematurelyUnfrozen() {
+        // GIVEN that we received a broadcast 499ms ago (shortly before the timeout would expire)
+        receiver.onReceive(null, null)
+        verify(dumpManager).freezeBuffers()
+        clock.advanceTime(499)
+
+        // WHEN we receive a second broadcast
+        receiver.onReceive(null, null)
+
+        // THEN the buffers are frozen a second time
+        verify(dumpManager, times(2)).freezeBuffers()
+
+        // THEN when we advance beyond the first timeout, nothing happens
+        clock.advanceTime(101)
+        verify(dumpManager, never()).unfreezeBuffers()
+
+        // THEN only when we advance past the reset timeout window are the buffers unfrozen
+        clock.advanceTime(401)
+        verify(dumpManager).unfreezeBuffers()
+    }
+}
