Capture main thread triggers automatically

papa-main-trace/api/papa-main-trace.api

@@ -0,0 +1,10 @@
+public final class papa/MainThreadMessageSpy {
+ public static final field INSTANCE Lpapa/MainThreadMessageSpy;
+ public final fun startTracing (Lpapa/MainThreadMessageSpy$Tracer;)V
+ public final fun stopTracing (Lpapa/MainThreadMessageSpy$Tracer;)V
+}
+
+public abstract interface class papa/MainThreadMessageSpy$Tracer {
+ public abstract fun onMessageDispatch (Ljava/lang/String;Z)V
+}
+

papa-main-trace/build.gradle.kts

@@ -0,0 +1,42 @@
+import org.jetbrains.kotlin.gradle.tasks.KotlinCompile
+
+plugins {
+ id("com.android.library")
+ kotlin("android")
+ id("com.vanniktech.maven.publish")
+}
+
+android {
+ compileSdkVersion(31)
+
+ compileOptions {
+ sourceCompatibility = JavaVersion.VERSION_1_8
+ targetCompatibility = JavaVersion.VERSION_1_8
+ }
+
+ resourcePrefix = "papa_"
+
+ defaultConfig {
+ minSdkVersion(21)
+ versionCode = 1
+ versionName = "1.0"
+ }
+
+ buildFeatures {
+ buildConfig = false
+ }
+}
+
+tasks.withType<KotlinCompile> {
+ kotlinOptions {
+ freeCompilerArgs = listOfNotNull(
+ // allow-jvm-ir-dependencies is required to consume binaries built with the IR backend.
+ // It doesn't change the bytecode that gets generated for this module.
+ "-Xallow-jvm-ir-dependencies",
+ "-Xopt-in=kotlin.RequiresOptIn"
+ )
+ }
+}
+
+dependencies {
+}

papa-main-trace/gradle.properties

@@ -0,0 +1,3 @@
+POM_ARTIFACT_ID=papa-main-trace
+POM_NAME=Papa Main Thread Tracing
+POM_PACKAGING=aar

papa-main-trace/src/main/AndroidManifest.xml

@@ -0,0 +1,2 @@
+<?xml version="1.0" encoding="utf-8"?>
+<manifest package="com.squareup.papa.maintrace" />

papa-main-trace/src/main/java/papa/MainThreadMessageSpy.kt

@@ -0,0 +1,79 @@
+package papa
+
+import android.os.Build.VERSION
+import android.os.Looper
+
+object MainThreadMessageSpy {
+
+ fun interface Tracer {
+ fun onMessageDispatch(
+ messageAsString: String,
+ before: Boolean
+ )
+ }
+
+ private val tracers = mutableListOf<Tracer>()
+
+ fun startTracing(tracer: Tracer) {
+ checkMainThread()
+ if (VERSION.SDK_INT == 28) {
+ // This is disabled on Android 9 because it can introduce crashes. The log is created by
+ // concatenating several values from Message, including toString() from Message.callback, which is
+ // the posted runnable. Android 9 introduced lambdas support within AOSP code, which was kept
+ // "cheap" by introducing the concept of PooledLambda to avoid one new instance per lambda:
+ // https://cs.android.com/android/platform/superproject/+/master:frameworks/base/core/java/com/android/internal/util/function/pooled/PooledLambda.java
+ // Unfortunately, calling toString() on a PooledLambda will crash if that lambda has 0 argument
+ // and doesn't return one of void, Object or Boolean.
+ // The crash was fixed in Android 10:
+ // https://cs.android.com/android/_/android/platform/frameworks/base/+/75632d616dbf14b6c71ea0e3a8a55c6fc963ba10
+ // It's unclear how much PooledLambda was used in Android 9, but we've found at least one usage
+ // that is crashing our UI tests:
+ // https://cs.android.com/android/platform/superproject/+/master:frameworks/base/core/java/android/app/UiAutomation.java;l=1365-1371;drc=master
+ return
+ }
+ check(tracers.none { it === tracers }) {
+ "Tracer $tracer already in $tracers"
+ }
+ tracers.add(tracer)
+ if (tracers.size == 1) {
+ startSpyingMainThreadDispatching()
+ }
+ }
+
+ fun stopTracing(tracer: Tracer) {
+ checkMainThread()
+ val singleTracerLeft = tracers.size == 1
+ tracers.removeAll { it === tracer }
+ if (singleTracerLeft && tracers.isEmpty()) {
+ stopSpyingMainThreadDispatching()
+ }
+ }
+
+ private fun startSpyingMainThreadDispatching() {
+ // Looper can log to a printer before and after each message. We leverage this to surface the
+ // beginning and end of every main thread message in system traces. This costs a few extra string
+ // concatenations for each message handling.
+ // The printer is called before ('>>' prefix) and after ('<<' prefix) every message.
+ Looper.getMainLooper().setMessageLogging { messageAsString ->
+ if (messageAsString.startsWith('>')) {
+ for (tracer in tracers) {
+ tracer.onMessageDispatch(messageAsString, before = true)
+ }
+ } else {
+ for (tracer in tracers) {
+ tracer.onMessageDispatch(messageAsString, before = false)
+ }
+ }
+ }
+ }
+
+ private fun stopSpyingMainThreadDispatching() {
+ Looper.getMainLooper().setMessageLogging(null)
+ }
+
+ private fun checkMainThread() {
+ check(Looper.getMainLooper().thread === Thread.currentThread()) {
+ "Should be called from the main thread, not ${Thread.currentThread()}"
+ }
+ }
+}

papa-safetrace/build.gradle.kts

@@ -39,6 +39,8 @@ tasks.withType<KotlinCompile> {
 }
 
 dependencies {
+ implementation(project(":papa-main-trace"))
+
  compileOnly(Dependencies.Build.AndroidXAnnotation)
 
  implementation(Dependencies.AndroidXTracing)

papa-safetrace/src/main/java/papa/SafeTrace.kt

@@ -6,7 +6,7 @@ import papa.SafeTrace.MAX_LABEL_LENGTH
 import papa.SafeTrace.beginSection
 import papa.SafeTrace.isCurrentlyTracing
 import papa.SafeTrace.isTraceable
-import papa.internal.TraceMainThreadMessages
+import papa.internal.SafeTraceMainThreadMessages
 
 /**
  * This is a wrapper for [androidx.tracing.Trace] that should be used instead as [beginSection] and
@@ -64,7 +64,7 @@ object SafeTrace {
  fun forceTraceable() {
  androidx.tracing.Trace.forceEnableAppTracing()
  isForcedTraceable = true
- TraceMainThreadMessages.enableMainThreadMessageTracing()
+ SafeTraceMainThreadMessages.enableMainThreadMessageTracing()
  }
 
  @Volatile

papa-safetrace/src/main/java/papa/SafeTraceSetup.kt

@@ -1,7 +1,7 @@
 package papa
 
 import android.app.Application
-import papa.internal.TraceMainThreadMessages
+import papa.internal.SafeTraceMainThreadMessages
 
 object SafeTraceSetup {
 
@@ -13,7 +13,7 @@ object SafeTraceSetup {
 
  fun init(application: Application) {
  this.application = application
- TraceMainThreadMessages.enableMainThreadMessageTracing()
+ SafeTraceMainThreadMessages.enableMainThreadMessageTracing()
  }
 
  var mainThreadSectionNameMapper: SectionNameMapper = SectionNameMapper {

papa-safetrace/src/main/java/papa/internal/SafeTraceMainThreadMessages.kt

@@ -0,0 +1,57 @@
+package papa.internal
+
+import android.os.Handler
+import android.os.Looper
+import com.squareup.papa.safetrace.R
+import papa.MainThreadMessageSpy
+import papa.SafeTrace
+import papa.SafeTraceSetup
+
+internal object SafeTraceMainThreadMessages {
+
+ private val traceMainThreadMessages: Boolean
+ get() {
+ if (!SafeTraceSetup.initDone) {
+ return false
+ }
+ val resources = SafeTraceSetup.application.resources
+ return resources.getBoolean(R.bool.papa_trace_main_thread)
+ }
+
+ @Volatile
+ private var enabled = false
+
+ fun enableMainThreadMessageTracing() {
+ val mainLooper = Looper.getMainLooper()
+ if (mainLooper === Looper.myLooper()) {
+ enableOnMainThread()
+ } else {
+ Handler(mainLooper).post {
+ enableOnMainThread()
+ }
+ }
+ }
+
+ private fun enableOnMainThread() {
+ if (!enabled && SafeTrace.isTraceable && traceMainThreadMessages) {
+ enabled = true
+ var currentlyTracing = false
+ MainThreadMessageSpy.startTracing { messageAsString, before ->
+ if (!currentlyTracing) {
+ if (SafeTrace.isCurrentlyTracing &&
+ before &&
+ // Don't add a trace section for Choreographer#doFrame, as that messes up
+ // Macrobenchmark: https://issuetracker.google.com/issues/340206285
+ "android.view.Choreographer\$FrameDisplayEventReceiver" !in messageAsString) {
+ val traceSection = SafeTraceSetup.mainThreadSectionNameMapper.mapSectionName(messageAsString)
+ SafeTrace.beginSection(traceSection)
+ currentlyTracing = true
+ }
+ } else {
+ currentlyTracing = false
+ SafeTrace.endSection()
+ }
+ }
+ }
+ }
+}

papa/build.gradle.kts

@@ -45,6 +45,7 @@ tasks.withType<KotlinCompile> {
 
 dependencies {
 
+ api(project(":papa-main-trace"))
  api(project(":papa-safetrace"))
  compileOnly(Dependencies.Build.AndroidXAnnotation)
 

papa/src/main/java/papa/internal/ApplicationHolder.kt

@@ -20,5 +20,6 @@ internal object ApplicationHolder {
  }
  InputTracker.install(application)
  FrozenFrameOnTouchDetector.install()
+ MainThreadTriggerTracer.install(application)
  }
 }

papa/src/main/java/papa/internal/MainThreadTriggerTracer.kt

@@ -0,0 +1,40 @@
+package papa.internal
+
+import android.app.Application
+import com.squareup.papa.R
+import papa.InteractionTrigger
+import papa.MainThreadMessageSpy
+import papa.MainThreadTriggerStack
+import papa.SafeTrace
+import papa.SimpleInteractionTrigger
+import kotlin.time.Duration.Companion.nanoseconds
+
+internal object MainThreadTriggerTracer {
+
+ private const val ASYNC_SECTION_LABEL = "Main Message Interaction"
+
+ fun install(application: Application) {
+ if (!application.resources.getBoolean(R.bool.papa_track_main_thread_triggers)) {
+ return
+ }
+ val asyncTraceCookie = System.nanoTime().toInt()
+ lateinit var currentTrigger: InteractionTrigger
+ MainThreadMessageSpy.startTracing { _, before ->
+ if (before) {
+ val dispatchUptime = System.nanoTime().nanoseconds
+ SafeTrace.beginAsyncSection(ASYNC_SECTION_LABEL, asyncTraceCookie)
+ currentTrigger = SimpleInteractionTrigger(
+ triggerUptime = dispatchUptime,
+ name = "main-message",
+ interactionTrace = {
+ SafeTrace.endAsyncSection(ASYNC_SECTION_LABEL, asyncTraceCookie)
+ }
+ )
+ MainThreadTriggerStack.pushTriggeredBy(currentTrigger)
+ } else {
+ MainThreadTriggerStack.popTriggeredBy(currentTrigger)
+ currentTrigger.takeOverInteractionTrace()?.endTrace()
+ }
+ }
+ }
+}

papa/src/main/res/values/tart_bools.xml

@@ -1,4 +1,5 @@
 <?xml version="1.0" encoding="utf-8"?>
 <resources>
  <bool name="papa_track_input_events">true</bool>
+ <bool name="papa_track_main_thread_triggers">true</bool>
 </resources>

papa/src/main/res/values/tart_public.xml

@@ -1,4 +1,5 @@
 <?xml version="1.0" encoding="utf-8"?>
 <resources>
  <public name="papa_track_input_events" type="bool" />
+ <public name="papa_track_main_thread_triggers" type="bool" />
 </resources>

settings.gradle.kts

@@ -4,5 +4,6 @@ include(
  ":papa",
  ":papa-dev",
  ":papa-safetrace",
+ ":papa-main-trace",
  ":sample"
 )