Improve tracking on choreographer frame ends

## Behavior changes

Whenever possible (i.e. any API != 28), we'll now detect the end of a frame by spying on main thread messages and running code right when the main thread message is done running and before a new main thread message starts running, by leveraging `Looper.getMainLooper().setMessageLogging { }`. We're also detecting whether we're in a frame or not by looking at the name of the runnable, rather than by creating a stacktrace.

## Non backward compatible API changes

- Renamed `MainThreadMessageSpy.startTracing()` and `MainThreadMessageSpy.stopTracing()` to `MainThreadMessageSpy.addTracer()` and `MainThreadMessageSpy.removeTracer()`.

## New APIs

- `MainThreadMessageSpy.startSpyingMainThreadDispatching()` and `MainThreadMessageSpy.stopSpyingMainThreadDispatching()`, `MainThreadMessageSpy.currentMessageAsString`, `MainThreadMessageSpy.enabled` and `MainThreadMessageSpy.onCurrentMessageFinished()`
- `MainThreadMessageScopedLazy` (`prop by mainThreadMessageScopedLazy {}`) property for main thread scoped lazy properties that get cleared at the end of each main thread message.
- `Choreographers.postOnFrameRendered()`, `Choreographers.postOnWindowFrameRendered()` and `Choreographers.isInChoreographerFrame`
- `InputEventTrigger.rendered`, `InputEventTrigger.renderedUptime` and `InputEventTrigger.onInputEventFrameRendered`

.github/workflows/android.yml

@@ -33,18 +33,33 @@ jobs:
  # Allow tests to continue on other devices if they fail on one device.
  fail-fast: false
  matrix:
- arch: [ x86_64 ]
- target: [ google_apis ]
- channel: [ stable ]
  api-level:
  - 21
+ - 22
  - 23
- # Disabled 26, running into https:/ReactiveCircus/android-emulator-runner/issues/385
- # - 26
+ - 24
+ - 25
+ - 26
+ # - 27 has 'default;x86_64' and 'google_apis;x86' but not 'google_apis;x86_64' so we're setting it up as a one-off with x86 below.
+ - 28
  - 29
  - 30
+ # No tests found, process crashed
+ # - 31
+ # No tests found, process crashed
+ # - 32
+ # No tests found, process crashed
+ # - 33
  # Disabled 34: needs min target SDK 23, and upgrading AGP.
  # - 34
+ arch: [ x86_64 ]
+ target: [ google_apis ]
+ channel: [ stable ]
+ include:
+ - arch: x86
+ api-level: 27
+ target: google_apis
+ channel: stable
  steps:
  - name: Enable KVM group perms
  run: |
@@ -58,30 +73,12 @@ jobs:
  java-version: 11
  distribution: 'zulu'
  - uses: gradle/gradle-build-action@v2
- - name: AVD cache
- uses: actions/cache@v4
- id: avd-cache
- with:
- path: |
- ~/.android/avd/*
- ~/.android/adb*
- key: avd-cached-${{ matrix.api-level }}-${{ matrix.os }}-${{ matrix.target }}
- - name: Create AVD and generate snapshot for caching
- if: steps.avd-cache.outputs.cache-hit != 'true'
- uses: reactivecircus/android-emulator-runner@v2
- with:
- api-level: ${{ matrix.api-level }}
- target: ${{ matrix.target }}
- arch: ${{ matrix.arch }}
- force-avd-creation: false
- emulator-options: -no-window -gpu swiftshader_indirect -noaudio -no-boot-anim -camera-back none -no-snapshot-load
- disable-animations: false
- script: echo "Generated AVD snapshot for caching."
  - name: Instrumentation Tests
  uses: reactivecircus/android-emulator-runner@v2
  with:
  api-level: ${{ matrix.api-level }}
- force-avd-creation: false
+ # Disabled AVD caching and forcing AVD creation to avoid running into https:/ReactiveCircus/android-emulator-runner/issues/385
+ force-avd-creation: true
  target: ${{ matrix.target }}
  arch: ${{ matrix.arch }}
  emulator-options: -no-window -gpu swiftshader_indirect -noaudio -no-boot-anim -no-metrics -camera-back none -no-snapshot-save
@@ -91,7 +88,6 @@ jobs:
  adb logcat >> emulator.log & # pipe all logcat messages into log file as a background process
  adb shell settings put global package_verifier_user_consent -1
  ./gradlew connectedCheck --no-build-cache --no-daemon --stacktrace
-
  - name: Upload results
  if: ${{ always() }}
  uses: actions/upload-artifact@v3
@@ -103,7 +99,7 @@ jobs:
 
  snapshot-deployment:
  if: github.repository == 'square/papa' && github.event_name == 'push'
- needs: [ checks , instrumentation-tests ]
+ needs: [ checks ]
  runs-on: ubuntu-latest
  steps:
  - uses: actions/checkout@v3

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

@@ -1,7 +1,22 @@
+public final class papa/MainThreadMessageScopedLazy : kotlin/properties/ReadOnlyProperty {
+ public fun <init> (Lkotlin/jvm/functions/Function0;)V
+ public final fun getProvider ()Lkotlin/jvm/functions/Function0;
+ public fun getValue (Ljava/lang/Object;Lkotlin/reflect/KProperty;)Ljava/lang/Object;
+}
+
+public final class papa/MainThreadMessageScopedLazyKt {
+ public static final fun mainThreadMessageScopedLazy (Lkotlin/jvm/functions/Function0;)Lpapa/MainThreadMessageScopedLazy;
+}
+
 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 final fun addTracer (Lpapa/MainThreadMessageSpy$Tracer;)V
+ public final fun getCurrentMessageAsString ()Ljava/lang/String;
+ public final fun getEnabled ()Z
+ public final fun onCurrentMessageFinished (Lkotlin/jvm/functions/Function0;)V
+ public final fun removeTracer (Lpapa/MainThreadMessageSpy$Tracer;)V
+ public final fun startSpyingMainThreadDispatching ()V
+ public final fun stopSpyingMainThreadDispatching ()V
 }
 
 public abstract interface class papa/MainThreadMessageSpy$Tracer {

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

@@ -0,0 +1,26 @@
+package papa
+
+import kotlin.properties.ReadOnlyProperty
+import kotlin.reflect.KProperty
+
+class MainThreadMessageScopedLazy<T>(val provider: () -> T) : ReadOnlyProperty<Any?, T> {
+
+ private var valueOrNull: T? = null
+
+ override fun getValue(
+ thisRef: Any?,
+ property: KProperty<*>
+ ): T {
+ check(MainThreadMessageSpy.enabled) {
+ "Can't use a MainThreadMessageScopedLazy when MainThreadMessageSpy is not enabled."
+ }
+ val value = provider()
+ valueOrNull = value
+ MainThreadMessageSpy.onCurrentMessageFinished {
+ valueOrNull = null
+ }
+ return value
+ }
+}
+
+fun <T> mainThreadMessageScopedLazy(provider: () -> T) = MainThreadMessageScopedLazy(provider)

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

@@ -14,7 +14,46 @@ object MainThreadMessageSpy {
 
  private val tracers = mutableListOf<Tracer>()
 
- fun startTracing(tracer: Tracer) {
+ var enabled = false
+ private set
+
+ var currentMessageAsString: String? = null
+ private set
+ get() {
+ checkMainThread()
+ return field
+ }
+
+ fun addTracer(tracer: Tracer) {
+ checkMainThread()
+ check(tracers.none { it === tracers }) {
+ "Tracer $tracer already in $tracers"
+ }
+ tracers.add(tracer)
+ }
+
+ fun removeTracer(tracer: Tracer) {
+ checkMainThread()
+ tracers.removeAll { it === tracer }
+ }
+
+ fun onCurrentMessageFinished(block: () -> Unit) {
+ if (!enabled) {
+ return
+ }
+ checkMainThread()
+ tracers.add(object : Tracer {
+ override fun onMessageDispatch(
+ messageAsString: String,
+ before: Boolean
+ ) {
+ tracers.remove(this)
+ block()
+ }
+ })
+ }
+
+ fun startSpyingMainThreadDispatching() {
  checkMainThread()
  if (VERSION.SDK_INT == 28) {
  // This is disabled on Android 9 because it can introduce crashes. The log is created by
@@ -31,43 +70,29 @@ object MainThreadMessageSpy {
  // 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() {
+ enabled = true
  // 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)
- }
+ val before = messageAsString.startsWith('>')
+ if (before) {
+ currentMessageAsString = messageAsString
+ }
+ for (tracer in tracers) {
+ tracer.onMessageDispatch(messageAsString, before = before)
+ }
+ if (!before) {
+ currentMessageAsString = null
  }
  }
  }
 
- private fun stopSpyingMainThreadDispatching() {
+ fun stopSpyingMainThreadDispatching() {
+ checkMainThread()
+ currentMessageAsString = null
+ enabled = false
  Looper.getMainLooper().setMessageLogging(null)
  }
 

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

@@ -36,7 +36,7 @@ internal object SafeTraceMainThreadMessages {
  if (!enabled && SafeTrace.isTraceable && traceMainThreadMessages) {
  enabled = true
  var currentlyTracing = false
- MainThreadMessageSpy.startTracing { messageAsString, before ->
+ MainThreadMessageSpy.addTracer { messageAsString, before ->
  if (!currentlyTracing) {
  if (SafeTrace.isCurrentlyTracing &&
  before &&

papa/api/papa.api

@@ -201,20 +201,28 @@ public final class papa/AppVisibilityState : java/lang/Enum {
  public static fun values ()[Lpapa/AppVisibilityState;
 }
 
+public final class papa/Choreographers {
+ public static final field INSTANCE Lpapa/Choreographers;
+ public final fun isInChoreographerFrame ()Z
+ public final fun postOnFrameRendered (Lpapa/OnFrameRenderedListener;)V
+ public final fun postOnWindowFrameRendered (Landroid/view/Window;Lpapa/OnFrameRenderedListener;)V
+}
+
 public abstract interface class papa/FinishingInteraction : papa/TrackedInteraction {
 }
 
 public final class papa/InputEventTrigger {
+ public static final field Companion Lpapa/InputEventTrigger$Companion;
  public synthetic fun <init> (Landroid/view/InputEvent;JLkotlin/jvm/internal/DefaultConstructorMarker;)V
- public final fun component1 ()Landroid/view/InputEvent;
- public final fun component2-UwyO8pc ()J
- public final fun copy-HG0u8IE (Landroid/view/InputEvent;J)Lpapa/InputEventTrigger;
- public static synthetic fun copy-HG0u8IE$default (Lpapa/InputEventTrigger;Landroid/view/InputEvent;JILjava/lang/Object;)Lpapa/InputEventTrigger;
- public fun equals (Ljava/lang/Object;)Z
  public final fun getDeliveryUptime-UwyO8pc ()J
  public final fun getInputEvent ()Landroid/view/InputEvent;
- public fun hashCode ()I
- public fun toString ()Ljava/lang/String;
+ public final fun getRendered ()Z
+ public final fun getRenderedUptime-FghU774 ()Lkotlin/time/Duration;
+ public final fun onInputEventFrameRendered (Lpapa/OnFrameRenderedListener;)V
+}
+
+public final class papa/InputEventTrigger$Companion {
+ public final fun createTrackingWhenFrameRendered-SxA4cEA (Landroid/view/Window;Landroid/view/InputEvent;J)Lpapa/InputEventTrigger;
 }
 
 public final class papa/InputEventTriggerKt {
@@ -335,6 +343,10 @@ public final class papa/OnEventScope$DefaultImpls {
  public static synthetic fun startInteraction-SxA4cEA$default (Lpapa/OnEventScope;Lpapa/InteractionTrigger;Lpapa/InteractionTrace;JILjava/lang/Object;)Lpapa/RunningInteraction;
 }
 
+public abstract interface class papa/OnFrameRenderedListener {
+ public abstract fun onFrameRendered-LRDsOJo (J)V
+}
+
 public abstract class papa/PapaEvent {
 }