tracinglib: changes to coroutine tracing format (7fe9e8fa) · Commits · e / os / android_frameworks_libs_systemui

tracinglib/README.md

+24 −12

Original line number	Diff line number	Diff line
		# Coroutine Tracing

		This library contains utilities for tracing coroutines. Coroutines cannot be traced using the
		`android.os.Trace` APIs because suspension points will lead to malformed trace sections. This is
		because each `Trace.beginSection` must have a matching `Trace.endSection`; if a coroutine suspends
		before `Trace.endSection` is called, the trace section will remain open while other unrelated work
		executes.
		`android.os.Trace` APIs normally because suspension points will lead to malformed trace sections.
		This is because each `Trace.beginSection()` call must have a matching `Trace.endSection()` call; if
		a coroutine suspends before `Trace.endSection()` is called, the trace section will remain open while
		other unrelated work executes on the thread.

		To address this, we introduce a function `traceCoroutine("name") { ... }` that can be used for
		tracing sections of coroutine code. When invoked, a trace section with the given name will start
		immediately, and its name will also be written to an object in the current `CoroutineContext` used
		for coroutine-local storage. When the coroutine suspends, all trace sections will end immediately.
		When resumed, the coroutine will read the names of the previous sections from coroutine-local
		storage, and it will begin the sections again.
		immediately, and its name will also be written to an object in thread-local storage which is managed
		by an object in the current `CoroutineContext`, making it safe, "coroutine-local" storage. When the
		coroutine suspends, all trace sections will end immediately. When resumed, the coroutine will read
		the names of the previous sections from coroutine-local storage, and it will begin the sections
		again.

		For example, the following coroutine code will be traced as follows:

		@@ -51,9 +52,9 @@ Thread #2 \| [==== Slice ====]
		This library also provides wrappers for some of the coroutine functions provided in the
		`kotlinx.coroutines.*` package. For example, instead of:
		`launch { traceCoroutine("my-launch") { /* block */ } }`, you can instead write:
		`launch("my-launch") { /* block */ }`.
		`launchTraced("my-launch") { /* block */ }`.

		It also provides a wrapper for tracing Flow emissions. For example,
		It also provides a wrapper for tracing `Flow` collections. For example,

		```
		val coldFlow = flow {
		@@ -71,8 +72,9 @@ coldFlow.collect("F") {
		Would be traced as follows:

		```
		Thread #1 \| [====== collect:F ======] [==== collect:F =====] [====== collect:F ======]
		\| [== collect:F:emit ==] [== collect:F:emit ==] [== collect:F:emit ==]
		Thread #1 \| [===== collect:F =====] [=== collect:F ====] [===== collect:F =====]
		\| [= collect:F:emit =] [= collect:F:emit =] [= collect:F:emit =]
		\| ^ "1" printed ^ "2" printed ^ "3" printed
		```

		# Building and Running
		@@ -95,6 +97,16 @@ adb shell device_config override systemui com.android.systemui.coroutine_tracing
		adb shell am restart
		```

		## Extra Debug Flags

		The behavior of coroutine tracing can be further fine-tuned using the following sysprops:

		- `debug.coroutine_tracing.walk_stack_override`
		- `debug.coroutine_tracing.count_continuations_override`

		See [`createCoroutineTracingContext()`](core/src/coroutines/TraceContextElement.kt) for
		documentation.

		## Demo App

		Build and install the app using Soong and adevice:

tracinglib/core/src/TraceUtils.kt

+10 −0

Original line number	Diff line number	Diff line
		@@ -20,6 +20,9 @@ import android.annotation.SuppressLint
		import android.os.Trace
		import com.android.app.tracing.coroutines.traceCoroutine
		import java.util.concurrent.ThreadLocalRandom
		import kotlin.contracts.ExperimentalContracts
		import kotlin.contracts.InvocationKind
		import kotlin.contracts.contract

		/**
		* Writes a trace message to indicate that a given section of code has begun running __on the
		@@ -88,7 +91,9 @@ internal fun endSlice() {
		* Run a block within a [Trace] section. Calls [Trace.beginSection] before and [Trace.endSection]
		* after the passed block.
		*/
		@OptIn(ExperimentalContracts::class)
		public inline fun <T> traceSection(tag: String, block: () -> T): T {
		contract { callsInPlace(block, InvocationKind.EXACTLY_ONCE) }
		val tracingEnabled = Trace.isEnabled()
		if (tracingEnabled) beginSlice(tag)
		return try {
		@@ -104,7 +109,12 @@ public inline fun <T> traceSection(tag: String, block: () -> T): T {
		* Same as [traceSection], but the tag is provided as a lambda to help avoiding creating expensive
		* strings when not needed.
		*/
		@OptIn(ExperimentalContracts::class)
		public inline fun <T> traceSection(tag: () -> String, block: () -> T): T {
		contract {
		callsInPlace(tag, InvocationKind.AT_MOST_ONCE)
		callsInPlace(block, InvocationKind.EXACTLY_ONCE)
		}
		val tracingEnabled = Trace.isEnabled()
		if (tracingEnabled) beginSlice(tag())
		return try {

tracinglib/core/src/coroutines/TraceContextElement.kt

+99 −64

Original line number	Diff line number	Diff line
		@@ -55,6 +55,10 @@ private val alwaysEnableStackWalker: Boolean by lazy {
		SystemProperties.getBoolean("debug.coroutine_tracing.walk_stack_override", false)
		}

		private val alwaysEnableContinuationCounting: Boolean by lazy {
		SystemProperties.getBoolean("debug.coroutine_tracing.count_continuations_override", false)
		}

		/**
		* Returns a new [TraceContextElement] (or [EmptyCoroutineContext] if `coroutine_tracing` feature is
		* flagged off). This context should only be installed on root coroutines (e.g. when constructing a
		@@ -78,29 +82,36 @@ private val alwaysEnableStackWalker: Boolean by lazy {
		* }
		* ```
		*
		* NOTE: The sysprop `debug.coroutine_tracing.walk_stack_override` can be used to override the
		* `walkStackForDefaultNames` parameter, forcing it to always be `true`. If the sysprop is `false`
		* (or does not exist), the value of `walkStackForDefaultNames` is used, whether `true` or `false`.
		* NOTE: The sysprops `debug.coroutine_tracing.walk_stack_override` and
		* `debug.coroutine_tracing.count_continuations_override` can be used to override the parameters
		* `walkStackForDefaultNames` and `countContinuations` respectively, forcing them to always be
		* `true`. If the sysprop is `false` (or does not exist), the value of the parameter is passed here
		* is used. If `true`, all calls to [createCoroutineTracingContext] will be overwritten with that
		* parameter set to `true`. Importantly, this means that the sysprops can be used to globally turn
		* ON `walkStackForDefaultNames` or `countContinuations`, but they cannot be used to globally turn
		* OFF either parameter.
		*
		* @param name the name of the coroutine scope. Since this should only be installed on top-level
		* coroutines, this should be the name of the root [CoroutineScope].
		* @param walkStackForDefaultNames whether to walk the stack and use the class name of the current
		* suspending function if child does not have a name that was manually specified. Walking the
		* stack is very expensive so this should not be used in production.
		* @param includeParentNames whether to concatenate parent names and sibling counts with the name of
		* the child. This should only be used for testing because it can result in extremely long trace
		* names.
		* @param strictMode whether to add additional checks to coroutine tracing machinery. These checks
		* are expensive and should only be used for testing.
		* @param countContinuations whether to include an extra trace section showing the total number of
		* times a coroutine has suspended and resumed.
		* @param testMode changes behavior is several ways: 1) parent names and sibling counts are
		* concatenated with the name of the child. This can result in extremely long trace names, which
		* is why it is only for testing. 2) additional strict-mode checks are added to coroutine tracing
		* machinery. These checks are expensive and should only be used for testing. 3) omits "coroutine
		* execution" trace slices, and omits coroutine metadata slices
		* @param shouldIgnoreClassName lambda that takes binary class name (as returned from
		* [StackFrame.getClassName] and returns true if it should be ignored (e.g. search for relevant
		* class name should continue) or false otherwise
		* class name should continue) or false otherwise.
		*/
		public fun createCoroutineTracingContext(
		name: String = "UnnamedScope",
		walkStackForDefaultNames: Boolean = false,
		includeParentNames: Boolean = false,
		strictMode: Boolean = false,
		countContinuations: Boolean = false,
		testMode: Boolean = false,
		shouldIgnoreClassName: (String) -> Boolean = { false },
		): CoroutineContext {
		return if (Flags.coroutineTracing()) {
		@@ -109,15 +120,16 @@ public fun createCoroutineTracingContext(
		// Minor perf optimization: no need to create TraceData() for root scopes since all
		// launches require creation of child via [copyForChild] or [mergeForChild].
		contextTraceData = null,
		inheritedTracePrefix = "",
		coroutineDepth = 0,
		parentId = -1,
		config =
		TraceConfig(
		walkStackForDefaultNames = walkStackForDefaultNames \|\| alwaysEnableStackWalker,
		includeParentNames = includeParentNames,
		strictMode = strictMode,
		testMode = testMode,
		shouldIgnoreClassName = shouldIgnoreClassName,
		countContinuations = countContinuations \|\| alwaysEnableContinuationCounting,
		),
		parentId = null,
		inheritedTracePrefix = "",
		coroutineDepth = 0,
		)
		} else {
		EmptyCoroutineContext
		@@ -193,11 +205,11 @@ internal open class CoroutineTraceName(internal val name: String) : CoroutineCon
		}
		}

		internal data class TraceConfig(
		internal class TraceConfig(
		val walkStackForDefaultNames: Boolean,
		val includeParentNames: Boolean,
		val strictMode: Boolean,
		val testMode: Boolean,
		val shouldIgnoreClassName: (String) -> Boolean,
		val countContinuations: Boolean,
		)

		/**
		@@ -206,28 +218,18 @@ internal data class TraceConfig(
		*
		* This is internal machinery for [traceCoroutine] and should not be used directly.
		*
		* @param name the name of the current coroutine. Since this should only be installed on top-level
		* @param name The name of the current coroutine. Since this should only be installed on top-level
		* coroutines, this should be the name of the root [CoroutineScope].
		* @property contextTraceData [TraceData] to be saved to thread-local storage.
		* @param inheritedTracePrefix prefix containing metadata for parent scopes. Each child is separated
		* @property config Configuration parameters
		* @param parentId The ID of the parent coroutine, as defined in [BaseTraceElement]
		* @param inheritedTracePrefix Prefix containing metadata for parent scopes. Each child is separated
		* by a `:` and prefixed by a counter indicating the ordinal of this child relative to its
		* siblings. Thus, the prefix such as `root-name:3^child-name` would indicate this is the 3rd
		* child (of any name) to be started on `root-scope`. If the child has no name, an empty string
		* would be used instead: `root-scope:3^`
		* @property coroutineDepth how deep the coroutine is relative to the top-level [CoroutineScope]
		* @param coroutineDepth How deep the coroutine is relative to the top-level [CoroutineScope]
		* containing the original [TraceContextElement] from which this [TraceContextElement] was copied.
		* @param parentId the ID of the parent coroutine, as defined in [BaseTraceElement]
		* @param walkStackForDefaultNames whether to walk the stack and use the class name of the current
		* suspending function if child does not have a name that was manually specified. Walking the
		* stack is very expensive so this should not be used in production.
		* @param includeParentNames whether to concatenate parent names and sibling counts with the name of
		* the child. This should only be used for testing because it can result in extremely long trace
		* names.
		* @param strictMode whether to add additional checks to coroutine machinery. These checks are
		* expensive and should only be used for testing.
		* @param shouldIgnoreClassName lambda that takes binary class name (as returned from
		* [StackFrame.getClassName] and returns true if it should be ignored (e.g. search for relevant
		* class name should continue) or false otherwise
		* @see createCoroutineTracingContext
		* @see nameCoroutine
		* @see traceCoroutine
		@@ -236,22 +238,30 @@ internal data class TraceConfig(
		internal class TraceContextElement(
		name: String,
		internal val contextTraceData: TraceData?,
		inheritedTracePrefix: String,
		private val coroutineDepth: Int,
		parentId: Int,
		private val config: TraceConfig,
		parentId: Int?,
		inheritedTracePrefix: String,
		coroutineDepth: Int,
		) : CopyableThreadContextElement<TraceData?>, CoroutineTraceName(name) {

		private var childCoroutineCount = AtomicInteger(0)

		private val fullCoroutineTraceName =
		if (config.includeParentNames) "$inheritedTracePrefix$name" else ""
		private val continuationTraceMessage =
		"$fullCoroutineTraceName;$name;d=$coroutineDepth;c=$currentId;p=$parentId"
		private val coroutineTraceName =
		if (config.testMode) "$inheritedTracePrefix$name"
		else "$name;d=$coroutineDepth;c=$currentId;p=${parentId ?: "none"}"

		init {
		debug { "#init: name=$name" }
		Trace.instant(Trace.TRACE_TAG_APP, continuationTraceMessage)
		Trace.traceBegin(Trace.TRACE_TAG_APP, "TraceContextElement#init[$coroutineTraceName]")
		}

		private var continuationCount = 0
		private val childDepth = coroutineDepth + 1
		private var childCoroutineCount = if (config.testMode) AtomicInteger(0) else null

		private val copyForChildTraceMessage = "TraceContextElement#copyForChild[$coroutineTraceName]"
		private val mergeForChildTraceMessage = "TraceContextElement#mergeForChild[$coroutineTraceName]"

		init {
		Trace.traceEnd(Trace.TRACE_TAG_APP)
		}

		/**
		@@ -274,7 +284,13 @@ internal class TraceContextElement(
		val oldState = traceThreadLocal.get()
		debug { "#updateThreadContext oldState=$oldState" }
		if (oldState !== contextTraceData) {
		Trace.traceBegin(Trace.TRACE_TAG_APP, continuationTraceMessage)
		if (!config.testMode) {
		Trace.traceBegin(Trace.TRACE_TAG_APP, "coroutine execution")
		}
		Trace.traceBegin(Trace.TRACE_TAG_APP, coroutineTraceName)
		if (config.countContinuations) {
		Trace.traceBegin(Trace.TRACE_TAG_APP, "continuation: #${continuationCount++}")
		}
		traceThreadLocal.set(contextTraceData)
		// Calls to `updateThreadContext` will not happen in parallel on the same context, and
		// they cannot happen before the prior suspension point. Additionally,
		@@ -321,13 +337,24 @@ internal class TraceContextElement(
		if (oldState !== traceThreadLocal.get()) {
		contextTraceData?.endAllOnThread()
		traceThreadLocal.set(oldState)
		Trace.traceEnd(Trace.TRACE_TAG_APP) // end: currentScopeTraceMessage
		if (!config.testMode) {
		Trace.traceEnd(Trace.TRACE_TAG_APP) // end: "coroutine execution"
		}
		Trace.traceEnd(Trace.TRACE_TAG_APP) // end: contextMetadata
		if (config.countContinuations) {
		Trace.traceEnd(Trace.TRACE_TAG_APP) // end: continuation: #
		}
		}
		}

		public override fun copyForChild(): CopyableThreadContextElement<TraceData?> {
		debug { "#copyForChild" }
		try {
		Trace.traceBegin(Trace.TRACE_TAG_APP, copyForChildTraceMessage)
		return createChildContext()
		} finally {
		Trace.traceEnd(Trace.TRACE_TAG_APP) // end: copyForChildTraceMessage
		}
		}

		public override fun mergeForChild(
		@@ -344,25 +371,33 @@ internal class TraceContextElement(
		)
		}
		}
		try {
		Trace.traceBegin(Trace.TRACE_TAG_APP, mergeForChildTraceMessage)
		val nameForChild = (overwritingElement as CoroutineTraceName).name
		return createChildContext(nameForChild)
		} finally {
		Trace.traceEnd(Trace.TRACE_TAG_APP) // end: mergeForChildTraceMessage
		}
		}

		private fun createChildContext(
		name: String =
		if (config.walkStackForDefaultNames) walkStackForClassName(config.shouldIgnoreClassName)
		private fun createChildContext(name: String? = null): TraceContextElement {
		val childName =
		name
		?: if (config.walkStackForDefaultNames)
		walkStackForClassName(config.shouldIgnoreClassName)
		else ""
		): TraceContextElement {
		debug { "#createChildContext: \"$name\" has new child with name \"${name}\"" }
		val childCount = childCoroutineCount.incrementAndGet()
		debug { "#createChildContext: \"${this.name}\" has new child with name \"${childName}\"" }
		return TraceContextElement(
		name = name,
		contextTraceData = TraceData(config.strictMode),
		inheritedTracePrefix =
		if (config.includeParentNames) "$fullCoroutineTraceName:$childCount^" else "",
		coroutineDepth = coroutineDepth + 1,
		parentId = currentId,
		name = childName,
		contextTraceData = TraceData(strictMode = config.testMode),
		config = config,
		parentId = currentId,
		inheritedTracePrefix =
		if (config.testMode) {
		val childCount = childCoroutineCount?.incrementAndGet() ?: 0
		"$coroutineTraceName:$childCount^"
		} else "",
		coroutineDepth = childDepth,
		)
		}
		}

tracinglib/demo/Android.bp

+15 −3

Original line number	Diff line number	Diff line
		@@ -18,18 +18,30 @@ package {

		android_app {
		name: "CoroutineTracingDemoApp",

		platform_apis: true,
		system_ext_specific: true,
		certificate: "platform",
		min_sdk_version: "34",
		target_sdk_version: "34",
		use_resource_processor: true,

		srcs: ["src/*/.kt"],
		manifest: "app-manifest.xml",

		resource_dirs: ["res"],
		use_resource_processor: true,

		static_libs: [
		"tracinglib-platform",
		"dagger2",
		"jsr330",
		"androidx.compose.runtime_runtime",
		"androidx.compose.animation_animation",
		"androidx.compose.material_material",
		"androidx.compose.material3_material3",
		"androidx.compose.material_material-icons-extended",
		"androidx.activity_activity-compose",
		"androidx.navigation_navigation-compose",
		"androidx.appcompat_appcompat",
		],

		plugins: ["dagger2-compiler"],
		}

tracinglib/demo/app-manifest.xml

+1 −1

Original line number	Diff line number	Diff line
		@@ -20,7 +20,7 @@
		android:label="@string/app_name">
		<activity
		android:name=".MainActivity"
		android:theme="@style/ActivityTheme"
		android:theme="@style/Theme.ActivityTheme"
		android:exported="true">
		<intent-filter>
		<action android:name="android.intent.action.MAIN" />