Android/frameworks_base
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Detect blocking binder calls in SystemUI

Browse Source 
Test: logcat -s 'StrictMode:*' 'SystemUIBinder:*'
Test: capture trace, look for "Blocking Binder Transactions" track
Fixes: 238923086
Bug: 241131634
Change-Id: I940bcb2d723aeb3b459a1ab62d0179582974a765
This commit is contained in:
Peter Kalauskas
2022-11-29 16:12:51 -08:00
parent f3192865a3
commit cc2d70f11d
4 changed files with 339 additions and 0 deletions
Download Patch File Download Diff File Expand all files Collapse all files

31
packages/SystemUI/src-debug/com/android/systemui/util/StartBinderLoggerModule.kt Normal file
View File

@@ -0,0 +1,31 @@
/*
* 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.util
import com.android.systemui.CoreStartable
import dagger.Binds
import dagger.Module
import dagger.multibindings.ClassKey
import dagger.multibindings.IntoMap
@Module
abstract class StartBinderLoggerModule {
@Binds
@IntoMap
@ClassKey(BinderLogger::class)
abstract fun bindBinderLogger(impl: BinderLogger): CoreStartable
}

24
packages/SystemUI/src-release/com/android/systemui/util/StartBinderLoggerModule.kt Normal file
View File

@@ -0,0 +1,24 @@
/*
* 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.util
import dagger.Module
@Module
abstract class StartBinderLoggerModule {
// Empty because this module is only used on debug builds
}

2
packages/SystemUI/src/com/android/systemui/dagger/SystemUICoreStartableModule.kt
View File

@@ -55,6 +55,7 @@ import com.android.systemui.theme.ThemeOverlayController
import com.android.systemui.toast.ToastUI
import com.android.systemui.usb.StorageNotification
import com.android.systemui.util.NotificationChannels
import com.android.systemui.util.StartBinderLoggerModule
import com.android.systemui.volume.VolumeUI
import com.android.systemui.wmshell.WMShell
import dagger.Binds
@@ -68,6 +69,7 @@ import dagger.multibindings.IntoMap
@Module(includes = [
MultiUserUtilsModule::class,
StartControlsStartableModule::class,
StartBinderLoggerModule::class,
])
abstract class SystemUICoreStartableModule {
/** Inject into AuthController. */

282
packages/SystemUI/src/com/android/systemui/util/BinderLogger.kt Normal file
View File

@@ -0,0 +1,282 @@
/*
* 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.util
import android.os.Binder
import android.os.Binder.ProxyTransactListener
import android.os.Build
import android.os.IBinder
import android.os.StrictMode
import android.os.StrictMode.ThreadPolicy
import android.os.Trace.TRACE_TAG_APP
import android.os.Trace.asyncTraceForTrackBegin
import android.os.Trace.asyncTraceForTrackEnd
import android.util.Log
import com.android.settingslib.utils.ThreadUtils
import com.android.systemui.CoreStartable
import com.android.systemui.DejankUtils
import com.android.systemui.dagger.SysUISingleton
import com.android.systemui.flags.FeatureFlags
import com.android.systemui.flags.Flags
import javax.inject.Inject
import kotlin.random.Random.Default.nextInt
@SysUISingleton
class BinderLogger
@Inject
constructor(
private val featureFlags: FeatureFlags,
) : CoreStartable, ProxyTransactListener {
override fun start() {
// This feature is only allowed on "userdebug" and "eng" builds
if (Build.IS_USER) return
if (!featureFlags.isEnabled(Flags.WARN_ON_BLOCKING_BINDER_TRANSACTIONS)) return
if (DejankUtils.STRICT_MODE_ENABLED) {
Log.e(
TAG,
"Feature disabled; persist.sysui.strictmode (DejankUtils) and " +
"WARN_ON_BLOCKING_BINDER_TRANSACTIONS (BinderLogger) are incompatible"
)
return
}
Binder.setProxyTransactListener(this)
val policyBuilder = ThreadPolicy.Builder().detectCustomSlowCalls().penaltyLog()
StrictMode.setThreadPolicy(policyBuilder.build())
}
override fun onTransactStarted(binder: IBinder, transactionCode: Int, flags: Int): Any? {
// Ignore one-way binder transactions
if (flags and IBinder.FLAG_ONEWAY != 0) return null
// Ignore anything not on the main thread
if (!ThreadUtils.isMainThread()) return null
// To make it easier to debug, log the most likely cause of the blocking binder transaction
// by parsing the stack trace.
val tr = Throwable()
val analysis = BinderTransactionAnalysis.fromStackTrace(tr.stackTrace)
val traceCookie = nextInt()
asyncTraceForTrackBegin(TRACE_TAG_APP, TRACK_NAME, analysis.traceMessage, traceCookie)
if (analysis.isSystemUi) {
StrictMode.noteSlowCall(analysis.logMessage)
} else {
Log.v(TAG, analysis.logMessage, tr)
}
return traceCookie
}
override fun onTransactStarted(binder: IBinder, transactionCode: Int): Any? {
return null
}
override fun onTransactEnded(o: Any?) {
if (o is Int) {
asyncTraceForTrackEnd(TRACE_TAG_APP, TRACK_NAME, o)
}
}
/**
* Class for finding the origin of a binder transaction from a stack trace and creating an error
* message that indicates 1) whether or not the call originated from System UI, and 2) the name
* of the binder transaction and where it was called.
*
* There are two types of stack traces:
* 1. Stack traces that originate from System UI, which look like the following: ```
* android.os.BinderProxy.transact(BinderProxy.java:541)
* android.content.pm.BaseParceledListSlice.<init>(BaseParceledListSlice.java:94)
* android.content.pm.ParceledListSlice.<init>(ParceledListSlice.java:42)
* android.content.pm.ParceledListSlice.<init>(Unknown Source:0)
* android.content.pm.ParceledListSlice$1.createFromParcel(ParceledListSlice.java:80)
* android.content.pm.ParceledListSlice$1.createFromParcel(ParceledListSlice.java:78)
* android.os.Parcel.readTypedObject(Parcel.java:3982)
* android.content.pm.IPackageManager$Stub$Proxy.getInstalledPackages(IPackageManager.java:5029)
* com.android.systemui.ExampleClass.runTwoWayBinderIPC(ExampleClass.kt:343) ... ``` Most of
* these binder transactions contain a reference to a `$Stub$Proxy`, but some don't. For
* example: ``` android.os.BinderProxy.transact(BinderProxy.java:541)
* android.content.ContentProviderProxy.query(ContentProviderNative.java:479)
* android.content.ContentResolver.query(ContentResolver.java:1219)
* com.android.systemui.power.PowerUI.refreshEstimateIfNeeded(PowerUI.java:383) ``` In both
* cases, we identify the call closest to a sysui package to make the error more clear.
* 2. Stack traces that originate outside of System UI, which look like the following: ```
* android.os.BinderProxy.transact(BinderProxy.java:541)
* android.service.notification.IStatusBarNotificationHolder$Stub$Proxy.get(IStatusBarNotificationHolder.java:121)
* android.service.notification.NotificationListenerService$NotificationListenerWrapper.onNotificationPosted(NotificationListenerService.java:1396)
* android.service.notification.INotificationListener$Stub.onTransact(INotificationListener.java:248)
* android.os.Binder.execTransactInternal(Binder.java:1285)
* android.os.Binder.execTransact(Binder.java:1244) ```
*
* @param isSystemUi Whether or not the call originated from System UI. If it didn't, it's due
* to internal implementation details of a core framework API.
* @param cause The cause of the binder transaction
* @param binderCall The binder transaction itself
*/
private class BinderTransactionAnalysis
constructor(
val isSystemUi: Boolean,
cause: StackTraceElement?,
binderCall: StackTraceElement?
) {
val logMessage: String
val traceMessage: String
init {
val callName =
(if (isSystemUi) getSimpleCallRefWithFileAndLineNumber(cause)
else "${getSimpleCallRef(cause)}()") + " -> ${getBinderCallRef(binderCall)}"
logMessage =
"Blocking binder transaction detected" +
(if (!isSystemUi) ", but the call did not originate from System UI" else "") +
": $callName"
traceMessage = "${if (isSystemUi) "sysui" else "core"}: $callName"
}
companion object {
fun fromStackTrace(stackTrace: Array<StackTraceElement>): BinderTransactionAnalysis {
if (stackTrace.size < 2) {
return BinderTransactionAnalysis(false, null, null)
}
var previousStackElement: StackTraceElement = stackTrace.first()
// The stack element corresponding to the binder transaction. For example:
// `android.content.pm.IPackageManager$Stub$Proxy.getInstalledPackages(IPackageManager.java:50)`
var binderTransaction: StackTraceElement? = null
// The stack element that caused the binder transaction in the first place.
// For example:
// `com.android.systemui.ExampleClass.runTwoWayBinderIPC(ExampleClass.kt:343)`
var causeOfBinderTransaction: StackTraceElement? = null
// Iterate starting from the top of the stack (BinderProxy.transact).
for (i in 1 until stackTrace.size) {
val stackElement = stackTrace[i]
if (previousStackElement.className?.endsWith("\$Stub\$Proxy") == true) {
binderTransaction = previousStackElement
causeOfBinderTransaction = stackElement
}
// As a heuristic, find the top-most call from a sysui package (besides this
// class) and blame it
val className = stackElement.className
if (
className != BinderLogger::class.java.name &&
(className.startsWith(SYSUI_PKG) || className.startsWith(KEYGUARD_PKG))
) {
causeOfBinderTransaction = stackElement
return BinderTransactionAnalysis(
true,
causeOfBinderTransaction,
// If an IInterface.Stub.Proxy-like call has not been identified yet,
// blame the previous call in the stack.
binderTransaction ?: previousStackElement
)
}
previousStackElement = stackElement
}
// If we never found a call originating from sysui, report it with an explanation
// that we could not find a culprit in sysui.
return BinderTransactionAnalysis(false, causeOfBinderTransaction, binderTransaction)
}
}
}
companion object {
private const val TAG: String = "SystemUIBinder"
private const val TRACK_NAME = "Blocking Binder Transactions"
private const val SYSUI_PKG = "com.android.systemui"
private const val KEYGUARD_PKG = "com.android.keyguard"
private const val UNKNOWN = "<unknown>"
/**
* Start of the source file for any R8 build within AOSP.
*
* TODO(b/213833843): Allow configuration of the prefix via a build variable.
*/
private const val AOSP_SOURCE_FILE_MARKER = "go/retraceme "
/** Start of the source file for any R8 compiler build. */
private const val R8_SOURCE_FILE_MARKER = "R8_"
/**
* Returns a short string for a [StackTraceElement] that references a binder transaction.
* For example, a stack frame of
* `android.content.pm.IPackageManager$Stub$Proxy.getInstalledPackages(IPackageManager.java:50)`
* would return `android.content.pm.IPackageManager#getInstalledPackages()`
*/
private fun getBinderCallRef(stackFrame: StackTraceElement?): String =
if (stackFrame != null) "${getBinderClassName(stackFrame)}#${stackFrame.methodName}()"
else UNKNOWN
/**
* Returns the class name of a [StackTraceElement], removing any `$Stub$Proxy` suffix, but
* still including the package name. This makes binder class names more readable. For
* example, for a stack element of
* `android.content.pm.IPackageManager$Stub$Proxy.getInstalledPackages(IPackageManager.java:50)`
* this would return `android.content.pm.IPackageManager`
*/
private fun getBinderClassName(stackFrame: StackTraceElement): String {
val className = stackFrame.className
val stubDefIndex = className.indexOf("\$Stub\$Proxy")
return if (stubDefIndex > 0) className.substring(0, stubDefIndex) else className
}
/**
* Returns a short string for a [StackTraceElement], including the file name and line
* number.
*
* If the source file needs retracing, this falls back to the default `toString()` method so
* that it can be read by the `retrace` command-line tool (`m retrace`).
*/
private fun getSimpleCallRefWithFileAndLineNumber(stackFrame: StackTraceElement?): String =
if (stackFrame != null) {
with(stackFrame) {
if (
fileName == null ||
fileName.startsWith(AOSP_SOURCE_FILE_MARKER) ||
fileName.startsWith(R8_SOURCE_FILE_MARKER)
) {
// If the source file needs retracing, use the default toString() method for
// compatibility with the retrace command-line tool
"at $stackFrame"
} else {
"at ${getSimpleCallRef(stackFrame)}($fileName:$lineNumber)"
}
}
} else UNKNOWN
/**
* Returns a short string for a [StackTraceElement] including it's class name and method
* name. For example, if the stack frame is
* `com.android.systemui.ExampleController.makeBlockingBinderIPC(ExampleController.kt:343)`
* this would return `ExampleController#makeBlockingBinderIPC()`
*/
private fun getSimpleCallRef(stackFrame: StackTraceElement?): String =
if (stackFrame != null) "${getSimpleClassName(stackFrame)}#${stackFrame.methodName}"
else UNKNOWN
/**
* Returns a short string for a [StackTraceElement] including just its class name without
* any package name. For example, if the stack frame is
* `com.android.systemui.ExampleController.makeBlockingBinderIPC(ExampleController.kt:343)`
* this would return `ExampleController`
*/
private fun getSimpleClassName(stackFrame: StackTraceElement): String =
try {
with(Class.forName(stackFrame.className)) {
canonicalName?.substring(packageName.length + 1)
}
} finally {} ?: stackFrame.className
}
}