Śledzenie w trakcie przetwarzania

Biblioteka androidx.tracing:tracing:2.0.2 to Kotlin API o niskim obciążeniu, które umożliwia rejestrowanie zdarzeń śledzenia w trakcie procesu. Te zdarzenia mogą rejestrować przedziały czasu i ich kontekst. Biblioteka obsługuje też propagację kontekstu w przypadku korutyn w Kotlinie.

Biblioteka używa tego samego formatu pakietów śledzenia Perfetto, który jest znany deweloperom Androida. Śledzenie 2.0 (w przeciwieństwie do interfejsów 1.0.0-* API) obsługuje koncepcję wtykowych punktów końcowych śledzenia i ujść, dzięki czemu inne biblioteki śledzenia mogą dostosowywać format śledzenia danych wyjściowych oraz sposób działania propagacji kontekstu w swojej implementacji.

Zależności

Aby rozpocząć śledzenie, musisz zdefiniować zależności w pliku build.gradle.kts.

Projekty Kotlin Multiplatform

Biblioteki, które muszą tylko emitować zdarzenia śledzenia, powinny korzystać z uproszczonego interfejsu API androidx.tracing:tracing. Aplikacje, które konfigurują backend śledzenia, powinny też zależeć od androidx.tracing:tracing-wire.

kotlin {
  sourceSets {
    commonMain {
      dependencies {
        // API definition
        implementation("androidx.tracing:tracing:2.0.2")
      }
    }
    androidMain {
      dependencies {
        // Android implementation (includes the Perfetto Sink and automatic initialization)
        implementation("androidx.tracing:tracing-wire:2.0.2")
      }
    }
    jvmMain {
      dependencies {
        // JVM implementation
        implementation("androidx.tracing:tracing-wire:2.0.2")
      }
    }
  }
}

Projekty tylko na Androida

Jeśli kierujesz reklamy tylko na Androida, dodaj ten kod do pliku build.gradle.kts aplikacji lub biblioteki:

dependencies {
    // For libraries and applications to emit events
    implementation("androidx.tracing:tracing:2.0.2")

    // For applications to configure the tracing backend
    implementation("androidx.tracing:tracing-wire:2.0.2")
}

Inicjowanie i odkrywanie

Zanim zaczniesz rejestrować zdarzenia śledzenia, musisz zainicjować infrastrukturę śledzenia. Wymaga to utworzenia AbstractTraceDriver i zarejestrowania jego Tracer na całym świecie.

Android

Jeśli na Androidzie uwzględnisz zależność androidx.tracing:tracing-wire, inicjowanie nastąpi automatycznie podczas uruchamiania aplikacji przy użyciu biblioteki androidx.startup.

Domyślnie automatyczna inicjalizacja wykonuje te czynności:

  • Tworzy TraceDriver z TraceSink, który zapisuje pliki śledzenia Perfetto w Context.noBackupFilesDir/perfetto_traces/.

  • Rejestruje wynikowy obiekt Tracer globalnie.

Dostosowywanie instancji TraceDriver

Jeśli chcesz dostosować konfigurację, np. zmienić miejsce zapisywania plików śledzenia lub użyć niestandardowego TraceSink, możesz podać własną instancję AbstractTraceDriver.

Aby dostosować konfigurację, zaimplementuj w klasie Application interfejs AbstractTraceDriver.Factory:

import android.app.Application
import androidx.tracing.AbstractTraceDriver
import androidx.tracing.wire.TraceDriver
import androidx.tracing.wire.TraceSink
import java.io.File

class App : Application(), AbstractTraceDriver.Factory {
    override fun create(): AbstractTraceDriver {
        val sink = TraceSink(
            context = this,
            fileProvider = { File(noBackupFilesDir, "traces") },
        )
        // Return the custom TraceDriver
        // You can also fully customize the instance of Tracer
        return TraceDriver(context = this, sink = sink)
    }
}

Automatyczny inicjator wykrywa, że podklasa Application implementuje interfejs Factory, i używa niestandardowej fabryki sterowników.

JVM

W przypadku JVM nie ma automatycznego mechanizmu uruchamiania. Aplikacja jest odpowiedzialna za zainicjowanie TraceDriver i zarejestrowanie Tracer globalnie podczas uruchamiania, najczęściej w funkcji main.

Aby zarejestrować lokalizator, zadzwoń pod numer Tracer.setGlobalTracer().

import androidx.tracing.Tracer
import androidx.tracing.DelicateTracingApi
import androidx.tracing.wire.TraceDriver
import androidx.tracing.wire.TraceSink
import java.io.File

fun main() {
    // Create the TraceSink, and the `TraceDriver`
    val outputDirectory = File("/tmp/perfetto")
    val sink = TraceSink(directory = outputDirectory)
    val driver = TraceDriver(sink = sink, isEnabled = true)

    // Register the tracer
    @OptIn(DelicateTracingApi::class)
    Tracer.setGlobalTracer(driver.tracer)

    // Call driver.close() as a result of the process shutdown hook.
    Runtime.getRuntime().addShutdownHook(Thread {
        driver.close()
    })
}

Podstawowe użycie

TraceSink określa sposób serializacji pakietów śledzenia. Śledzenie w wersji 2.0.0 zawiera implementację elementu Sink, który używa Perfettoformatu pakietu śledzenia. TraceDriver udostępnia uchwyt do Tracer i może służyć do finalizowania śledzenia.

Po zainicjowaniu Tracer (automatycznie na Androidzie lub ręcznie na JVM) użyj globalnej instancji Tracer.global, aby emitować zdarzenia śledzenia.

Możesz też użyć ikony TraceDriver, aby wyłączyć wszystkie punkty śledzenia w aplikacji, jeśli w niektórych jej wersjach nie chcesz w ogóle śledzić danych. Możesz opcjonalnie włączyć punkty śledzenia dla danego category, podając implementację isCategoryEnabled podczas tworzenia instancji TraceDriver.

val driver = TraceDriver(
    sink = sink,
    isCategoryEnabled = { category ->
        // Only enable trace points in the "com.example" package
        category.startsWith("com.example")
    }
)

Oto podstawowy przykład wysyłania zdarzenia śledzenia za pomocą Tracer.global na maszynie JVM, w tym konfiguracja ręczna:

import androidx.tracing.Tracer
import androidx.tracing.DelicateTracingApi
import androidx.tracing.wire.TraceDriver
import androidx.tracing.wire.TraceSink
import java.io.File

// Category names should also follow the same convention used for package names
// on Android and Java. This makes them easier to identify and filter.
internal const val CATEGORY_MAIN = "com.example"

fun createSink(): TraceSink {
    val outputDirectory = File("/tmp/perfetto")
    if (!outputDirectory.exists()) {
        outputDirectory.mkdirs()
    }
    return TraceSink(directory = outputDirectory)
}

fun createTraceDriver(): TraceDriver {
    return TraceDriver(sink = createSink(), isCategoryEnabled = {true})
}

fun main() {
    val driver = createTraceDriver()
    @OptIn(DelicateTracingApi::class)
    Tracer.setGlobalTracer(driver.tracer)

    driver.use {
        Tracer.global.trace(category = CATEGORY_MAIN, name = "basic") {
            // The block of code that needs to be traced.
            Thread.sleep(100L)
        }
    }
}

Spowoduje to wygenerowanie tego logu czasu.

Zrzut ekranu podstawowego śledzenia Perfetto

Rysunek 1. Zrzut ekranu z podstawowym śladem Perfetto.

Widać, że wypełnione są prawidłowe ścieżki procesu i wątku, które utworzyły pojedynczą sekcję śladu basic trwającą 100 ms.

Sekcje śladu (lub wycinki) mogą być zagnieżdżone na tej samej ścieżce, aby reprezentować nakładające się zdarzenia. Oto przykład.

fun main() {
    val driver = createTraceDriver()
    @OptIn(DelicateTracingApi::class)
    Tracer.setGlobalTracer(driver.tracer)

    driver.use {
        Tracer.global.trace(
            category = CATEGORY_MAIN,
            name = "processImage",
        ) {
            // Load the data first, then apply the sharpen filter
            sharpen(output = loadImage())
        }
    }
}

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

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

Spowoduje to wygenerowanie tego logu czasu.

Zrzut ekranu podstawowego śladu Perfetto z zagnieżdżonymi sekcjami

Rysunek 2. Zrzut ekranu podstawowego śladu Perfetto z zagnieżdżonymi sekcjami.

Na ścieżce głównego wątku widać nakładające się zdarzenia. Wyraźnie widać, że processImage dzwoni do loadImage i sharpen w tym samym wątku.

Dodawanie dodatkowych metadanych w sekcjach śledzenia

Czasami warto dołączyć do wycinka śladu dodatkowe metadane kontekstowe, aby uzyskać więcej szczegółów. Przykłady takich metadanych to nav destination, na którym znajduje się użytkownik, lub input arguments, które mogą ostatecznie określić, jak długo trwa funkcja.

fun main() {
    val driver = createTraceDriver()
    @OptIn(DelicateTracingApi::class)
    Tracer.setGlobalTracer(driver.tracer)

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

Daje to następujący wynik. Zwróć uwagę, że sekcja Arguments zawiera pary klucz-wartość dodane podczas tworzenia slice.

Zrzut ekranu podstawowego śladu Perfetto z dodatkowymi metadanymi

Rysunek 3. Zrzut ekranu podstawowego śladu Perfetto z dodatkowymi metadanymi.

Propagacja kontekstu

W przypadku korzystania z korutyn Kotlin lub innych podobnych platform, które pomagają w równoczesnych zadaniach, Tracing 2.0 obsługuje koncepcję propagacji kontekstu. Najlepiej wyjaśnić to na przykładzie.

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

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

fun main() = runBlocking(context = Dispatchers.Default) {
    val driver = createTraceDriver()
    @OptIn(DelicateTracingApi::class)
    Tracer.setGlobalTracer(driver.tracer)

    driver.use {
        Tracer.global.traceCoroutine(category = CATEGORY_MAIN, name = "main") {
              taskOne()
              taskTwo()
            }
        }
        println("All done")
    }
}

Daje to następujący wynik.

Zrzut ekranu śladu Perfetto z propagacją kontekstu

Rysunek 4. Zrzut ekranu podstawowego śladu Perfetto z propagacją kontekstu.

Propagacja kontekstu znacznie ułatwia wizualizację przepływu wykonania. Możesz dokładnie sprawdzić, które zadania były powiązane (połączone z innymi), a także kiedy dokładnie Threads zostały zawieszone i wznowione.

Możesz na przykład zobaczyć, że wycinek main spowodował powstanie wycinków taskOne i taskTwo. Następnie oba wątki były nieaktywne, ponieważ korutyny zostały zawieszone z powodu użycia delay.

Ręczne propagowanie

Czasami podczas mieszania współbieżnych zadań za pomocą korutyn Kotlin z instancjami Java Executor może być przydatne propagowanie kontekstu z jednego do drugiego. Oto przykład:

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

fun main() = runBlocking(context = Dispatchers.Default) {
    val driver = createTraceDriver()
    @OptIn(DelicateTracingApi::class)
    Tracer.setGlobalTracer(driver.tracer)

    val executor = Executors.newSingleThreadExecutor()
    driver.use {
        Tracer.global.traceCoroutine(category = CATEGORY_MAIN, name = "main") {
            coroutineScope {
                val deferred = CompletableDeferred<Unit>()
                executorTask(
                    // Obtain the propagation token from the CoroutineContext
                    token = Tracer.global.tokenFromCoroutineContext(),
                    executor = executor,
                    callback = {
                        deferred.complete(Unit)
                    }
                )
                deferred.await()
            }
        }
        executor.shutdownNow()
    }
}

Daje to następujący wynik.

Zrzut ekranu śladu Perfetto z ręcznym propagowaniem kontekstu

Rysunek 5. Zrzut ekranu podstawowego śladu Perfetto z ręcznym propagowaniem kontekstu.

Widać, że wykonanie rozpoczęło się w CoroutineContext, a następnie przełączyło się na Executor w języku Java, ale nadal mogliśmy używać propagacji kontekstu.

Łączenie ze śladami systemu

Biblioteka androidx.tracing nie rejestruje informacji takich jak planowanie procesora, wykorzystanie pamięci i interakcja aplikacji z systemem operacyjnym. Dzieje się tak, ponieważ biblioteka umożliwia śledzenie w procesie o niskim obciążeniu.

W razie potrzeby można jednak bardzo łatwo połączyć logi systemowe z logami w trakcie przetwarzania i wizualizować je jako jeden log czasu. Dzieje się tak, ponieważ Perfetto UI umożliwia wizualizację wielu plików śledzenia z urządzenia na ujednoliconej osi czasu.

Aby to zrobić, możesz rozpocząć sesję śledzenia systemu za pomocą Perfetto UI, postępując zgodnie z instrukcjami tutaj.

Możesz też rejestrować zdarzenia śledzenia w trakcie procesu za pomocą interfejsu Tracing 2.0 API, gdy śledzenie systemu jest włączone. Gdy będziesz mieć oba pliki śledzenia, możesz użyć opcji Open Multiple Trace Files w Perfetto.

Otwieranie wielu plików śledzenia w interfejsie Perfetto

Rysunek 6. Otwieranie wielu plików śledzenia w interfejsie Perfetto.

Zaawansowane przepływy pracy

W tej sekcji opisujemy zaawansowane przepływy pracy, które możesz wdrożyć za pomocą biblioteki śledzenia w procesie.

Korelacja pasków

Czasami przydatne jest przypisywanie fragmentów śladu do działania użytkownika wyższego poziomu lub zdarzenia systemowego. Jeśli na przykład chcesz przypisać wszystkie wycinki odpowiadające pracy w tle do powiadomienia, możesz to zrobić w ten sposób:

fun main() {
    val driver = createTraceDriver()
    @OptIn(DelicateTracingApi::class)
    Tracer.setGlobalTracer(driver.tracer)

    driver.use {
        onEvent(eventId = EVENT_ID)
    }
}

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

    Thread.sleep(20)

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

Daje to następujący wynik.

Zrzut ekranu z zrzutem Perfetto z powiązanymi fragmentami

Rysunek 7. Zrzut ekranu śladu Perfetto ze skorelowanymi wycinkami.

Dodawanie informacji o stosie wywołań

Narzędzia po stronie hosta, takie jak wtyczki kompilatora i procesory adnotacji, mogą też osadzać w śladzie informacje o stosie wywołań, aby ułatwić lokalizowanie pliku, klasy lub metody odpowiedzialnej za utworzenie sekcji śladu.

fun main() {
    val driver = createTraceDriver()
    @OptIn(DelicateTracingApi::class)
    Tracer.setGlobalTracer(driver.tracer)

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

Daje to następujący wynik.

Zrzut ekranu z zrzutu Perfetto z informacjami o stosie wywołań

Rysunek 8. Zrzut ekranu śladu Perfetto z informacjami o stosie wywołań.