プロセス内トレース(試験運用版)

新しい androidx.tracing:tracing:2.0.0-alpha01 ライブラリは、プロセス内トレース イベントのキャプチャを可能にする低オーバーヘッドの Kotlin API です。これらのイベントは、タイムスライスとそのコンテキストをキャプチャできます。このライブラリは、Kotlin コルーチンのコンテキスト伝播もサポートしています。

このライブラリは、Android デベロッパーがよく知っている Perfetto トレース パケット形式を使用します。また、Tracing 2.01.0.0-* API とは異なり)は、プラグ可能なトレース バックエンドシンクの概念をサポートしているため、他のトレース ライブラリは、出力トレース形式と、実装でのコンテキスト伝播の仕組みをカスタマイズできます。

依存関係

トレースを開始するには、build.gradle.kts で次の依存関係を定義する必要があります。

kotlin {
  androidLibrary {
    namespace = "com.example.library"
    // ...
  }
  sourceSets {
    androidMain {
      dependencies {
        api("androidx.tracing:tracing-wire-android:2.0.0-alpha01")
        // ...
      }
    }
    jvmMain {
      dependencies {
        api("androidx.tracing:tracing-wire-desktop:2.0.0-alpha01")
        // ...
      }
    }
  }
}

Android ライブラリまたはアプリケーションをターゲットにしている場合は、androidx.tracing:tracing-wire-android:2.0.0-alpha01 への依存関係を宣言します。JVM をターゲットにしている場合は、androidx.tracing:tracing-wire-desktop:2.0.0-alpha01 依存関係を使用できます。

基本的な使用方法

TraceSink は、トレース パケットのシリアル化方法を定義します。Tracing 2.0.0 には、Perfetto トレース パケット形式を使用する Sink の実装が付属しています。TraceDriverTracer へのハンドルを提供し、トレースの終了に使用できます。

また、一部のアプリ バリアントでトレースを行わない場合は、TraceDriver を使用してアプリ内のすべてのトレースポイントを無効にすることもできます。TraceDriver の今後の API では、デベロッパーがキャプチャする(またはカテゴリがノイズの多い場合に無効にする)トレース カテゴリを制御できるようになります。

まず、TraceSinkTraceDriver のインスタンスを作成します。

/**
 * A [TraceSink] defines how traces are serialized.
 *
 * [androidx.tracing.wire.TraceSink] uses the `Perfetto` trace packet format.
 */
fun createSink(): TraceSink {
    val outputDirectory = File(/* path = */ "/tmp/perfetto")
    if (!outputDirectory.exists()) {
        outputDirectory.mkdirs()
    }
    // We are using the factory function defined in androidx.tracing.wire
    return TraceSink(
        sequenceId = 1,
        directory = outputDirectory
    )
}
/**
 * Creates a new instance of [androidx.tracing.TraceDriver].
 */
fun createTraceDriver(): TraceDriver {
    // We are using a factory function from androidx.tracing.wire here.
    // `isEnabled` controls whether tracing is enabled for the application.
    val driver = TraceDriver(sink = createSink(), isEnabled = true)
    return driver
}

TraceDriver のインスタンスを取得したら、すべてのトレース API のエントリ ポイントを定義する Tracer を取得します。

// Tracing Categories identify subsystems that are responsible
// in generating trace sections. Future APIs in `TraceDriver` will allow the
// application to specify which categories they are interested in tracing.
// This lets the application disable entire trace categories, without
// needing to disable trace instrumentation at the call sites for those
// categories.

internal const val CATEGORY_MAIN = "main"

fun main() {
    val driver = createTraceDriver()
    driver.use {
        driver.tracer.trace(category = CATEGORY_MAIN, name = "basic") {
            Thread.sleep(100L)
        }
    }
}

これにより、次のトレースが生成されます。

基本的な Perfetto トレースのスクリーン キャプチャ

図 1: 基本的な Perfetto トレースの画面キャプチャ。

正しいプロセスとスレッドのトラックが入力され、100ms の間実行された単一のトレース セクション basic が生成されたことがわかります。

トレース セクション(またはスライス)は、同じトラックにネストして、重複するイベントを表すことができます。次に例を示します。

fun main() {
    // Initialize the tracing infrastructure to monitor app performance
    val driver = createTraceDriver()
    val tracer = driver.tracer
    driver.use {
        tracer.trace(
            category = CATEGORY_MAIN,
            name = "processImage",
        ) {
            // Load the data first, then apply the sharpen filter
            sharpen(tracer = tracer, output = loadImage(tracer))
        }
    }
}

internal fun loadImage(tracer: Tracer): ByteArray {
    return tracer.trace(CATEGORY_MAIN, "loadImage") {
        // Loads an image
        // ...
        // A placeholder
        ByteArray(0)
    }
}

internal fun sharpen(tracer: Tracer, output: ByteArray) {
    // ...
    tracer.trace(CATEGORY_MAIN, "sharpen") {
        // ...
    }
}

これにより、次のトレースが生成されます。

ネストされたセクションを含む基本的な Perfetto トレースの画面キャプチャ

図 2. ネストされたセクションを含む基本的な Perfetto トレースのスクリーン キャプチャ。

メインスレッド トラックに重複するイベントがあることがわかります。processImage が同じスレッドで loadImagesharpen を呼び出していることが明確にわかります。

トレース セクションにメタデータを追加する

場合によっては、トレース スライスに追加のコンテキスト メタデータを追加して、詳細情報を取得すると便利なことがあります。このようなメタデータの例としては、ユーザーが使用している nav destination や、関数の実行時間を決定する input arguments などがあります。

fun main() {
    val driver = createTraceDriver()
    driver.use {
        driver.tracer.trace(
            category = CATEGORY_MAIN,
            name = "basicWithContext",
            // Add additional metadata
            metadataBlock = {
                // Add key value pairs.
                addMetadataEntry("key", "value")
                addMetadataEntry("count", 1L)
            }
        ) {
            Thread.sleep(100L)
        }
    }
}

結果は次のようになります。Arguments セクションには、slice の生成時に追加された Key-Value ペアが含まれています。

追加のメタデータを含む基本的な Perfetto トレースのスクリーン キャプチャ

図 3. 追加のメタデータを含む基本的な Perfetto トレースのスクリーン キャプチャ。

コンテキストの伝播

Kotlin コルーチン(または同時ワークロードに役立つ他の同様のフレームワーク)を使用する場合、Tracing 2.0 はコンテキスト伝播の概念をサポートします。これは、例で説明するのが最適です。

suspend fun taskOne(tracer: Tracer) {
    tracer.traceCoroutine(category = CATEGORY_MAIN, "taskOne") {
        delay(timeMillis = 100L)
    }
}

suspend fun taskTwo(tracer: Tracer) {
    tracer.traceCoroutine(category = CATEGORY_MAIN, "taskTwo") {
        delay(timeMillis = 50L)
    }
}

fun main() = runBlocking(context = Dispatchers.Default) {
    val driver = createTraceDriver()
    val tracer = driver.tracer
    driver.use {
        tracer.traceCoroutine(category = CATEGORY_MAIN, name = "main") {
            coroutineScope {
                launch { taskOne(tracer) }
                launch { taskTwo(tracer) }
            }
        }
        println("All done")
    }
}

結果は次のようになります。

コンテキスト伝播を含む Perfetto トレースのスクリーン キャプチャ

図 4. コンテキスト伝播を含む基本的な Perfetto トレースの画面キャプチャ。

コンテキスト伝播により、実行フローを簡単に可視化できます。どのタスクが関連付けられているか(他のタスクに接続されているか)、Threads がいつ一時停止され、いつ再開されたかを正確に確認できます。

たとえば、スライス maintaskOnetaskTwo を生成したことがわかります。その後、両方のスレッドが非アクティブになりました(コルーチンが一時停止されたため - delay の使用による)。

手動伝播

Kotlin コルーチンと Java Executor のインスタンスを使用して同時実行ワークロードを混在させている場合、コンテキストを一方から他方に伝播すると便利なことがあります。次に例を示します。

fun executorTask(
    tracer: Tracer,
    token: PropagationToken,
    executor: Executor,
    callback: () -> Unit
) {
    executor.execute {
        tracer.trace(
            category = CATEGORY_MAIN,
            name = "executeTask",
            token = token,
        ) {
            // Do something
            Thread.sleep(100)
            callback()
        }
    }
}

@OptIn(DelicateTracingApi::class)
fun main() = runBlocking(context = Dispatchers.Default) {
    val driver = createTraceDriver()
    val executor = Executors.newSingleThreadExecutor()
    val tracer = driver.tracer
    driver.use {
        tracer.traceCoroutine(category = CATEGORY_MAIN, name = "main") {
            coroutineScope {
                val deferred = CompletableDeferred<Unit>()
                executorTask(
                    tracer = tracer,
                    // Obtain the propagation token from the CoroutineContext
                    token = tracer.tokenFromCoroutineContext(),
                    executor = executor,
                    callback = {
                        deferred.complete(Unit)
                    }
                )
                deferred.await()
            }
        }
        executor.shutdownNow()
    }
}

結果は次のようになります。

手動コンテキスト伝播を含む Perfetto トレースの画面キャプチャ

図 5. 手動コンテキスト伝播を使用した基本的な Perfetto トレースの画面キャプチャ。

実行が CoroutineContext で開始され、その後 Java Executor に切り替わったものの、コンテキスト伝播を使用できたことがわかります。

システム トレースと組み合わせる

新しい androidx.tracing では、CPU スケジューリング、メモリ使用量、オペレーティング システムとのアプリの一般的なやり取りなどの情報はキャプチャされません。これは、ライブラリが非常に低オーバーヘッドのインプロセス トレースを実行する方法を提供するためです。

ただし、必要に応じて、システム トレースとプロセス内トレースを統合して、単一のトレースとして可視化することは非常に簡単です。これは、Perfetto UI がデバイスの複数のトレースファイルを統合されたタイムラインで可視化することをサポートしているためです。

これを行うには、こちらの手順に沿って Perfetto UI を使用してシステム トレース セッションを開始します。

システム トレースがオンになっている間、Tracing 2.0 API を使用してインプロセス トレース イベントを記録することもできます。両方のトレース ファイルを取得したら、Perfetto の Open Multiple Trace Files オプションを使用できます。

Perfetto UI で複数のトレース ファイルを開く

図 6. Perfetto UI で複数のトレースファイルを開く。

高度なワークフロー

スライスを関連付ける

トレースのスライスをより上位のユーザー アクションやシステム イベントに関連付けると便利な場合があります。たとえば、バックグラウンド作業に対応するすべてのスライスを通知の一部として帰属させるには、次のようにします。

fun main() {
    val driver = createTraceDriver()
    onEvent(driver, eventId = EVENT_ID)
}

fun onEvent(driver: TraceDriver, eventId: Long) {
    driver.use {
        driver.tracer.trace(
            category = CATEGORY_MAIN,
            name = "step-1",
            metadataBlock = {
                addCorrelationId(eventId)
            }
        ) {
            Thread.sleep(100L)
        }

        Thread.sleep(20)

        driver.tracer.trace(
            category = CATEGORY_MAIN,
            name = "step-2",
            metadataBlock = {
                addCorrelationId(eventId)
            }
        ) {
            Thread.sleep(180)
        }
    }
}

結果は次のようになります。

関連付けられたスライスを含む Perfetto トレースの画面キャプチャ

図 7. 関連付けられたスライスを含む Perfetto トレースの画面キャプチャ。

コールスタック情報を追加

ホスト側のツール(コンパイラ プラグイン、アノテーション プロセッサなど)は、コールスタック情報をトレースに埋め込むこともできます。これにより、トレースのセクションを生成したファイル、クラス、メソッドをトレース内で簡単に見つけることができます。

fun main() {
    val driver = createTraceDriver()
    driver.use {
        driver.tracer.trace(
            category = CATEGORY_MAIN,
            name = "callStackEntry",
            metadataBlock = {
                addCallStackEntry(
                    name = "main",
                    lineNumber = 14,
                    sourceFile = "Basic.kt"
                )
            }
        ) {
            Thread.sleep(100L)
        }
    }
}

結果は次のようになります。

コールスタック情報を含む Perfetto トレースのスクリーン キャプチャ

図 8.コールスタック情報を含む Perfetto トレースの画面キャプチャ。