In-Process-Tracing (experimentell)

Die neue androidx.tracing:tracing:2.0.0-alpha01-Bibliothek ist eine Kotlin-API mit geringem Overhead, mit der In-Process-Trace-Ereignisse erfasst werden können. Mit diesen Ereignissen können Zeitabschnitte und ihr Kontext erfasst werden. Die Bibliothek unterstützt außerdem die Kontextweitergabe für Kotlin-Coroutinen.

Die Bibliothek verwendet dasselbe Perfetto-Trace-Paketformat, das Android-Entwickler kennen. Außerdem unterstützt Tracing 2.0 (im Gegensatz zu den 1.0.0-*-APIs) das Konzept von einsteckbaren Tracing-Back-Ends und Senken. Andere Tracing-Bibliotheken können das Ausgabetracing-Format und die Funktionsweise der Kontextweitergabe in ihrer Implementierung anpassen.

Abhängigkeiten

Um mit dem Tracing zu beginnen, müssen Sie die folgenden Abhängigkeiten in Ihrer build.gradle.kts definieren.

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")
        // ...
      }
    }
  }
}

Deklarieren Sie eine Abhängigkeit von androidx.tracing:tracing-wire-android:2.0.0-alpha01, wenn Sie eine Android-Bibliothek oder eine Anwendung als Ziel haben. Sie können die androidx.tracing:tracing-wire-desktop:2.0.0-alpha01-Abhängigkeit verwenden, wenn Sie die JVM als Zielplattform verwenden.

Grundlegende Nutzung

Ein TraceSink definiert, wie Trace-Pakete serialisiert werden. Tracing 2.0.0 enthält eine Implementierung eines Sinks, der das Perfetto-Trace-Paketformat verwendet. Ein TraceDriver bietet einen Handle für den Tracer und kann zum Abschließen eines Traces verwendet werden.

Sie können auch TraceDriver verwenden, um alle Trace-Punkte in der Anwendung zu deaktivieren, wenn Sie in einigen Anwendungs-Varianten überhaupt kein Tracing durchführen möchten. Mit zukünftigen APIs in TraceDriver können Entwickler auch steuern, welche Trace-Kategorien sie erfassen möchten (oder deaktivieren, wenn eine Kategorie zu viele Daten enthält).

Erstellen Sie zuerst eine Instanz von TraceSink und TraceDriver.

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

Nachdem Sie eine Instanz von TraceDriver haben, rufen Sie Tracer ab, das den Einstiegspunkt für alle Tracing-APIs definiert.

// 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)
        }
    }
}

Dadurch wird der folgende Trace generiert.

Screenshot eines einfachen Perfetto-Traces

Abbildung 1: Screenshot eines einfachen Perfetto-Traces.

Sie sehen, dass die richtigen Prozess- und Thread-Tracks ausgefüllt wurden und ein einzelner Trace-Abschnitt basic erstellt wurde, der 100ms lang war.

Abschnitte (oder Slices) können auf demselben Track verschachtelt werden, um sich überschneidende Ereignisse darzustellen. Hier ein Beispiel:

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") {
        // ...
    }
}

Dadurch wird der folgende Trace generiert.

Screenshot eines einfachen Perfetto-Traces mit verschachtelten Abschnitten

Abbildung 2: Screenshot eines einfachen Perfetto-Traces mit verschachtelten Abschnitten.

Sie sehen, dass sich Ereignisse im Main-Thread-Track überschneiden. Es ist ganz klar, dass processImage die Funktionen loadImage und sharpen im selben Thread aufruft.

Zusätzliche Metadaten in Trace-Abschnitten hinzufügen

Manchmal ist es sinnvoll, einem Trace-Segment zusätzliche kontextbezogene Metadaten anzuhängen, um weitere Details zu erhalten. Beispiele für solche Metadaten sind die nav destination des Nutzers oder input arguments, die letztendlich die Ausführungsdauer einer Funktion bestimmen können.

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)
        }
    }
}

Das führt zu folgendem Ergebnis. Beachten Sie, dass der Abschnitt Arguments Schlüssel/Wert-Paare enthält, die beim Erstellen von slice hinzugefügt wurden.

Screenshot eines einfachen Perfetto-Traces mit zusätzlichen Metadaten

Abbildung 3: Screenshot eines einfachen Perfetto-Traces mit zusätzlichen Metadaten.

Kontextweitergabe

Bei der Verwendung von Kotlin-Coroutinen (oder anderen ähnlichen Frameworks, die bei gleichzeitigen Arbeitslasten helfen) unterstützt Tracing 2.0 die Kontextweitergabe. Das lässt sich am besten anhand eines Beispiels erklären.

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")
    }
}

Das führt zu folgendem Ergebnis.

Screenshot eines Perfetto-Traces mit Kontextweitergabe

Abbildung 4: Screenshot eines einfachen Perfetto-Traces mit Kontextweitergabe.

Mit der Kontextübertragung lässt sich der Ablauf der Ausführung viel einfacher visualisieren. Sie können genau sehen, welche Aufgaben miteinander verknüpft waren und wann Threads angehalten und fortgesetzt wurden.

Sie können beispielsweise sehen, dass für den Segment main die Segmente taskOne und taskTwo generiert wurden. Danach waren beide Threads inaktiv, da die Coroutinen aufgrund der Verwendung von delay angehalten wurden.

Manuelle Weitergabe

Wenn Sie gleichzeitige Arbeitslasten mit Kotlin-Coroutinen und Instanzen von Java Executor kombinieren, kann es manchmal nützlich sein, den Kontext von einer zur anderen zu übertragen. Hier ein Beispiel:

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()
    }
}

Das führt zu folgendem Ergebnis.

Screenshot eines Perfetto-Traces mit manueller Kontextweitergabe

Abbildung 5: Screenshot eines einfachen Perfetto-Traces mit manueller Kontextweitergabe.

Die Ausführung wurde in einem CoroutineContext gestartet und dann zu einem Java-Executor gewechselt. Die Kontextweitergabe war aber weiterhin möglich.

Mit System-Traces kombinieren

Im neuen androidx.tracing werden keine Informationen wie CPU-Scheduling, Arbeitsspeichernutzung und die Interaktion der Anwendung mit dem Betriebssystem im Allgemeinen erfasst. Das liegt daran, dass die Bibliothek eine Möglichkeit bietet, In-Process-Tracing mit sehr geringem Overhead durchzuführen.

Es ist jedoch sehr einfach, System-Traces mit In-Process-Traces zusammenzuführen und sie bei Bedarf als einzelnen Trace zu visualisieren. Das liegt daran, dass Perfetto UI die Visualisierung mehrerer Tracedateien von einem Gerät auf einer einheitlichen Zeitachse unterstützt.

Dazu können Sie eine System-Tracing-Sitzung mit Perfetto UI starten. Folgen Sie dazu dieser Anleitung.

Sie können auch In-Process-Trace-Ereignisse mit der Tracing 2.0 API aufzeichnen, während das System-Tracing aktiviert ist. Sobald Sie beide Trace-Dateien haben, können Sie die Option Open Multiple Trace Files in Perfetto verwenden.

Mehrere Tracedateien in der Perfetto-Benutzeroberfläche öffnen

Abbildung 6 Mehrere Tracedateien in der Perfetto-UI öffnen

Erweiterte Workflows

Slices korrelieren

Manchmal ist es sinnvoll, Slices in einem Trace einer Nutzeraktion oder einem Systemereignis auf höherer Ebene zuzuordnen. Wenn Sie beispielsweise alle Slices, die einer Hintergrundaufgabe als Teil einer Benachrichtigung entsprechen, zuordnen möchten, können Sie Folgendes tun:

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)
        }
    }
}

Das führt zu folgendem Ergebnis.

Screenshot eines Perfetto-Traces mit korrelierten Slices

Abbildung 7. Screenshot eines Perfetto-Traces mit korrelierten Slices.

Callstack-Informationen hinzufügen

Hostseitige Tools (Compiler-Plug-ins, Annotationsprozessoren usw.) können zusätzlich Callstack-Informationen in einen Trace einbetten, um die Suche nach der Datei, Klasse oder Methode zu erleichtern, die für die Erstellung eines Trace-Abschnitts in einem Trace verantwortlich ist.

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)
        }
    }
}

Das führt zu folgendem Ergebnis.

Screenshot eines Perfetto-Traces mit Informationen zum Aufrufstack

Abbildung 8. Screenshot eines Perfetto-Traces mit Informationen zum Aufrufstack.