Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 197ffffb authored by Peter Kalauskas's avatar Peter Kalauskas Committed by Automerger Merge Worker
Browse files

Merge "Detect blocking binder calls in SystemUI" into udc-dev am: d7ce1479

parents bdb153f5 d7ce1479
Loading
Loading
Loading
Loading
+31 −0
Original line number Diff line number Diff line
/*
 * 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 −0
Original line number Diff line number Diff line
/*
 * 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 −0
Original line number Diff line number Diff line
@@ -54,6 +54,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
@@ -67,6 +68,7 @@ import dagger.multibindings.IntoMap
@Module(includes = [
    MultiUserUtilsModule::class,
    StartControlsStartableModule::class,
    StartBinderLoggerModule::class,
])
abstract class SystemUICoreStartableModule {
    /** Inject into AuthController.  */
+282 −0
Original line number Diff line number Diff line
/*
 * 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
    }
}