From 9feeca53a2ce962fb650e9b9f511e9e4ac22b43b Mon Sep 17 00:00:00 2001 From: Ned Burns Date: Fri, 29 May 2020 01:19:38 -0400 Subject: [PATCH] Freeze log buffers when a bug report is taken This prevents us from polluting the log buffers with logs generated by the bug report-taking process itself (notable, bug reports post a lot of notifications, which overwhelm the NotifLog). Bug: 112656837 Test: atest Test: manual Change-Id: I070ebc99a04d854b6aacb39da1cc311307ed0653 --- .../com/android/systemui/SystemUIService.java | 15 ++- .../com/android/systemui/dump/DumpManager.kt | 16 +++ .../android/systemui/dump/LogBufferFreezer.kt | 69 +++++++++++ .../src/com/android/systemui/log/LogBuffer.kt | 79 ++++++++---- .../systemui/dump/LogBufferFreezerTest.kt | 116 ++++++++++++++++++ 5 files changed, 269 insertions(+), 26 deletions(-) create mode 100644 packages/SystemUI/src/com/android/systemui/dump/LogBufferFreezer.kt create mode 100644 packages/SystemUI/tests/src/com/android/systemui/dump/LogBufferFreezerTest.kt diff --git a/packages/SystemUI/src/com/android/systemui/SystemUIService.java b/packages/SystemUI/src/com/android/systemui/SystemUIService.java index f1cb66784263e..708002d5b9460 100644 --- a/packages/SystemUI/src/com/android/systemui/SystemUIService.java +++ b/packages/SystemUI/src/com/android/systemui/SystemUIService.java @@ -27,8 +27,10 @@ import android.os.UserHandle; 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 index a4141b1b7cf01..bbb77504ec27c 100644 --- 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, fd: FileDescriptor, @@ -174,3 +188,5 @@ private data class RegisteredDumpable( val name: String, val dumpable: T ) + +private const val TAG = "DumpManager" \ No newline at end of file diff --git a/packages/SystemUI/src/com/android/systemui/dump/LogBufferFreezer.kt b/packages/SystemUI/src/com/android/systemui/dump/LogBufferFreezer.kt new file mode 100644 index 0000000000000..29f464285e5d0 --- /dev/null +++ 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" \ No newline at end of file diff --git a/packages/SystemUI/src/com/android/systemui/log/LogBuffer.kt b/packages/SystemUI/src/com/android/systemui/log/LogBuffer.kt index 342db346e14b7..78d70877a90e5 100644 --- 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 = 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 new file mode 100644 index 0000000000000..eb38073a85f71 --- /dev/null +++ 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 + + 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() + } +}