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

Commit aca8680d authored by Peter Kalauskas's avatar Peter Kalauskas
Browse files

tracinglib: update README, fix tracing demos 

Test: install CoroutineTracingDemoApp, capture trace
Flag: com.android.systemui.coroutine_tracing
Bug: 289353932
Change-Id: I72d95ccc7e5aeb09662eea3249e5f46ad8cdf995
parent d0f6ef48

tracinglib/README.md

0 → 100644
+112 −0
Original line number Diff line number Diff line 
# Coroutine Tracing



This library contains utilities for tracing coroutines. Coroutines cannot normally be traced using

the `android.os.Trace` APIs because it will often lead to malformed trace sections. This is because

each `Trace.beginSection` must have a matching `Trace.endSection` on the same thread before the

scope is finished, so if they are used around a suspend point, the trace section will remain open

while other unrelated work executes. It could even remain open indefinitely if the coroutine is

canceled.



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.



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



```

traceCoroutine("Slice A") {

  println("Start")

  delay(10)

  println("End")

}

```



```

Thread #1 |  [==== Slice ====]          [==== Slice ====]

               ^ "Start" printed          ^ "End" printed

```



If multiple threads are used, it would be as follows:



```

traceCoroutine("Slice") {

  println("Start")

  delay(10)

  withContext(backgroundThread) {

    println("End")

  }

}

```



```

Thread #1 |  [==== Slice ====]

          |    ^ "Start" printed

----------+---------------------------------------------------------

Thread #2 |                              [==== Slice ====]

                                           ^ "End" printed

```



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 */ }`.



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



```

val coldFlow = flow {

  emit(1)

  emit(2)

  emit(3)

}.withTraceName("my-flow")



coldFlow.collect {

  println(it)

  delay(10)

}

```



Would be traced as follows:



```

Thread #1 |  [=== my-flow:collect ===]    [=== my-flow:collect ===]    [=== my-flow:collect ===]

          |    [== my-flow:emit ==]         [== my-flow:emit ==]         [== my-flow:emit ==]

```



# Building and Running



## Host Tests



Host tests are implemented in `tracinglib-host-test`. To run the host tests:



```

atest tracinglib-host-test

```



## Feature Flag



Coroutine tracing is flagged off by default. To enable coroutine tracing on a device, flip the flag

and restart the user-space system:



```

adb shell device_config override systemui com.android.systemui.coroutine_tracing true

adb shell am restart

```



## Demo App



Build and install the app using Soong and adevice:



```

adevice track CoroutineTracingDemoApp

m CoroutineTracingDemoApp

adevice update

```



Then, open the app and tap an experiment to run it. The experiments run in the background. To see

the effects of what coroutine tracing is doing, you will need to capture a Perfetto trace. The

[`coroutine_tracing` flag](#feature-flag) will need to be enabled for coroutine trace sections to

work.

tracinglib/demo/README.md

deleted100644 → 0
+0 −5
Original line number Diff line number Diff line 
# Building and Running



Build and install the app using Soong and adevice. Then, tap an experiment to run it. The

experiments run in the background, so to see what it is doing you will neeed to capture a perfetto

trace.

tracinglib/demo/src/com/android/app/tracing/demo/ApplicationComponent.kt

+35 −7
Original line number Diff line number Diff line
@@ -15,6 +15,10 @@ 
 */

package com.android.app.tracing.demo



import android.os.Handler

import android.os.HandlerThread

import android.os.Looper

import android.os.Trace

import com.android.app.tracing.coroutines.createCoroutineTracingContext

import com.android.app.tracing.demo.experiments.CollectFlow

import com.android.app.tracing.demo.experiments.CombineDeferred
@@ -35,10 +39,9 @@ import javax.inject.Qualifier 
import javax.inject.Singleton

import kotlin.annotation.AnnotationRetention.RUNTIME

import kotlin.coroutines.CoroutineContext

import kotlinx.coroutines.DelicateCoroutinesApi

import kotlinx.coroutines.CoroutineScope

import kotlinx.coroutines.Dispatchers

import kotlinx.coroutines.ExperimentalCoroutinesApi

import kotlinx.coroutines.newSingleThreadContext

import kotlinx.coroutines.android.asCoroutineDispatcher



@Qualifier @MustBeDocumented @Retention(RUNTIME) annotation class Main
@@ -52,6 +55,8 @@ import kotlinx.coroutines.newSingleThreadContext 


@Qualifier @MustBeDocumented @Retention(RUNTIME) annotation class FixedThread2



@Qualifier @MustBeDocumented @Retention(RUNTIME) annotation class ExperimentLauncherThread



@Qualifier @MustBeDocumented @Retention(RUNTIME) annotation class Tracer



@Module
@@ -80,24 +85,37 @@ class ConcurrencyModule { 
        return Dispatchers.Unconfined + tracerContext

    }



    @OptIn(ExperimentalCoroutinesApi::class, DelicateCoroutinesApi::class)

    @Provides

    @Singleton

    @FixedThread1

    fun provideFixedThread1CoroutineContext(

        @Tracer tracerContext: CoroutineContext

    ): CoroutineContext {

        return newSingleThreadContext("FixedThread #1") + tracerContext

        val looper = startThreadWithLooper("FixedThread #1")

        return Handler(looper).asCoroutineDispatcher("FixedCoroutineDispatcher #1") + tracerContext

    }



    @OptIn(ExperimentalCoroutinesApi::class, DelicateCoroutinesApi::class)

    @Provides

    @Singleton

    @FixedThread2

    fun provideFixedThread2CoroutineContext(

        @Tracer tracerContext: CoroutineContext

    ): CoroutineContext {

        return newSingleThreadContext("FixedThread #2") + tracerContext

        val looper = startThreadWithLooper("FixedThread #2")

        return Handler(looper).asCoroutineDispatcher("FixedCoroutineDispatcher #2") + tracerContext

    }



    @Provides

    @Singleton

    @ExperimentLauncherThread

    fun provideExperimentLauncherCoroutineScope(

        @Tracer tracerContext: CoroutineContext

    ): CoroutineScope {

        val looper = startThreadWithLooper("Experiment Launcher Thread")

        return CoroutineScope(

            Handler(looper).asCoroutineDispatcher("Experiment Launcher CoroutineDispatcher") +

                tracerContext

        )

    }



    @Provides
@@ -151,4 +169,14 @@ interface ExperimentModule { 
interface ApplicationComponent {

    /** Returns [Experiment]s that should be used with the application. */

    @Singleton fun getAllExperiments(): Map<Class<*>, Provider<Experiment>>



    @Singleton @ExperimentLauncherThread fun getExperimentLauncherCoroutineScope(): CoroutineScope

}



private fun startThreadWithLooper(name: String): Looper {

    val thread = HandlerThread(name)

    thread.start()

    val looper = thread.looper

    looper.setTraceTag(Trace.TRACE_TAG_APP)

    return looper

}

tracinglib/demo/src/com/android/app/tracing/demo/MainActivity.kt

+5 −9
Original line number Diff line number Diff line
@@ -26,30 +26,26 @@ import android.widget.TextView 
import com.android.app.tracing.TraceUtils.trace

import com.android.app.tracing.demo.experiments.Experiment

import kotlinx.coroutines.CancellationException

import kotlinx.coroutines.CoroutineScope

import kotlinx.coroutines.DelicateCoroutinesApi

import kotlinx.coroutines.ExperimentalCoroutinesApi

import kotlinx.coroutines.Job

import kotlinx.coroutines.cancel

import kotlinx.coroutines.launch

import kotlinx.coroutines.newSingleThreadContext



private const val TRACK_NAME = "Active experiments"



class MainActivity : Activity() {



    @OptIn(ExperimentalCoroutinesApi::class, DelicateCoroutinesApi::class)

    val threadContext = newSingleThreadContext("Experiment launcher")



    private val allExperiments = lazy {

        (applicationContext as MainApplication).appComponent.getAllExperiments()

    }



    private val experimentLaunchScope = lazy {

        (applicationContext as MainApplication).appComponent.getExperimentLauncherCoroutineScope()

    }



    private var logContainer: ScrollView? = null

    private var loggerView: TextView? = null



    private fun <T : Experiment> createButtonForExperiment(demo: T): Button {

        val buttonCoroutineScope = CoroutineScope(threadContext)

        var launchCounter = 0

        var job: Job? = null

        val className = demo::class.simpleName ?: "<unknown class>"
@@ -64,7 +60,7 @@ class MainActivity : Activity() { 
                val experimentName = "$className #${launchCounter++}"

                trace("$className#onClick") {

                    job?.let { trace("cancel") { it.cancel("Cancelled due to click") } }

                    trace("launch") { job = buttonCoroutineScope.launch { demo.run() } }

                    trace("launch") { job = experimentLaunchScope.value.launch { demo.run() } }

                    trace("toast") { appendLine("$experimentName started") }

                    job?.let {

                        Trace.asyncTraceForTrackBegin(

tracinglib/demo/src/com/android/app/tracing/demo/experiments/CollectFlow.kt

+45 −17
Original line number Diff line number Diff line
@@ -15,45 +15,73 @@ 
 */

package com.android.app.tracing.demo.experiments



import com.android.app.tracing.coroutines.flow.filter

import com.android.app.tracing.coroutines.flow.flowOn

import com.android.app.tracing.coroutines.flow.map

import com.android.app.tracing.coroutines.flow.withTraceName

import com.android.app.tracing.coroutines.launch

import com.android.app.tracing.coroutines.traceCoroutine

import com.android.app.tracing.demo.FixedThread1

import com.android.app.tracing.demo.FixedThread2

import javax.inject.Inject

import javax.inject.Singleton

import kotlin.coroutines.CoroutineContext

import kotlinx.coroutines.coroutineScope

import kotlinx.coroutines.delay

import kotlinx.coroutines.flow.filter

import kotlinx.coroutines.flow.flow

import kotlinx.coroutines.flow.flowOn

import kotlinx.coroutines.flow.map



/** Util for introducing artificial delays to make the trace more readable for demo purposes. */

private fun blockCurrentThread(millis: Long) {

    Thread.sleep(millis)

}



@Singleton

class CollectFlow

@Inject

constructor(

    @FixedThread1 private var fixedThreadContext1: CoroutineContext,

    @FixedThread1 private var fixedThreadContext2: CoroutineContext,

    @FixedThread2 private var fixedThreadContext2: CoroutineContext,

) : Experiment {



    override fun getDescription(): String = "Collect a cold flow with intermediate operators"



    private val numFlow =

    override suspend fun run(): Unit = coroutineScope {

        val numFlow =

            flow {

                for (n in 0..1000) {

                    traceCoroutine("num-flow:delay(1)") { delay(1) }

                    traceCoroutine("num-flow:emit($n)") { emit(n) }

                    for (n in 0..4) {

                        traceCoroutine("delay-and-emit for $n") {

                            blockCurrentThread(10)

                            delay(1)

                            blockCurrentThread(10)

                            emit(n)

                            blockCurrentThread(10)

                            delay(1)

                            blockCurrentThread(10)

                        }

                    }

                }

                .withTraceName("flowOf numbers")

                .filter {

                    blockCurrentThread(10)

                    it % 2 == 0

                }

            .withTraceName("num-flow")

            .filter { it % 2 == 0 }

            .map { it * 0.5 }

                .withTraceName("filter for even")

                .map {

                    blockCurrentThread(10)

                    it * 3

                }

                .withTraceName("map 3x")

                .flowOn(fixedThreadContext2)

                .withTraceName("flowOn thread #2")



    override suspend fun run(): Unit = coroutineScope {

        launch("launch", fixedThreadContext1) {

            numFlow.collect { value -> traceCoroutine("got: $value") { delay(1) } }

        launch("launch on thread #1", fixedThreadContext1) {

            numFlow.collect {

                traceCoroutine("got: $it") {

                    blockCurrentThread(10)

                    delay(1)

                    blockCurrentThread(10)

                }

            }

        }

    }

}