מעקב בתהליך (ניסיוני)

ספריית androidx.tracing:tracing:2.0.0-alpha01 החדשה היא Kotlin API עם תקורה נמוכה, שמאפשרת ללכוד אירועי מעקב בתהליך. האירועים האלה יכולים לתעד פלחים של זמן והקשר שלהם. בנוסף, הספרייה תומכת בהעברת הקשר (context) עבור Kotlin Coroutines.

הספרייה משתמשת באותו פורמט של מנות נתונים למעקב של Perfetto שמוכר למפתחי Android. בנוסף, Tracing 2.0 (בניגוד לממשקי 1.0.0-* API) תומך במושגים של pluggable tracing backends ו-sinks, כך שספריות Tracing אחרות יכולות להתאים אישית את פורמט הפלט של Tracing ואת אופן הפצת ההקשר בהטמעה שלהן.

תלויות

כדי להתחיל במעקב, צריך להגדיר את התלות הבאה בקובץ 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")
        // ...
      }
    }
  }
}

צריך להצהיר על תלות ב-androidx.tracing:tracing-wire-android:2.0.0-alpha01 אם אתם מכוונים לספריית Android או לאפליקציה. אפשר להשתמש בתלות androidx.tracing:tracing-wire-desktop:2.0.0-alpha01 אם מכוונים ל-JVM.

שימוש בסיסי

TraceSink מגדיר איך חבילות של נתוני מעקב עוברות סריאליזציה. ‫Tracing 2.0.0 כולל הטמעה של Sink שמשתמש בפורמט מנות המעקב Perfetto. TraceDriver מספק ידית ל-Tracer ואפשר להשתמש בו כדי להשלים את המעקב.

אפשר גם להשתמש ב-TraceDriver כדי להשבית את כל נקודות המעקב באפליקציה, אם בוחרים לא לעקוב בכלל בחלק מהווריאציות של האפליקציה. ממשקי API עתידיים ב-TraceDriver יאפשרו למפתחים גם לקבוע אילו קטגוריות של מעקב הם רוצים לתעד (או להשבית אם קטגוריה מסוימת רועשת).

כדי להתחיל, יוצרים מופע של TraceSink ושל 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
}

אחרי שיש לכם מופע של TraceDriver, צריך לקבל את Tracer שמגדיר את נקודת הכניסה לכל ממשקי ה-API של מעקב.

// 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 בסיסי.

אפשר לראות שהתהליך והשרשור הנכונים מאוכלסים, ונוצר קטע מעקב יחיד basic, שפעל במשך 100ms.

אפשר להציב חלקים (או פרוסות) של מעקב אחד בתוך מעקב אחר באותו מסלול כדי לייצג אירועים חופפים. הנה דוגמה.

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 בסיסי עם קטעים מוטמעים.

אפשר לראות שיש חפיפה בין האירועים ב-track של ה-thread הראשי. ברור מאוד ש-processImage מתקשרת אל loadImage ואל sharpen באותו השרשור.

הוספת מטא-נתונים נוספים בקטעי מעקב

לפעמים כדאי לצרף פרוסת נתונים של מעקב עם מטא-נתונים נוספים לפי הקשר, כדי לקבל פרטים נוספים. דוגמאות למטא-נתונים כאלה יכולות לכלול את 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.

צילום מסך של מעקב Perfetto בסיסי עם מטא-נתונים נוספים

איור 3. צילום מסך של מעקב Perfetto בסיסי עם מטא-נתונים נוספים.

העברת הקשר

כשמשתמשים ב-Kotlin Coroutines (או במסגרות דומות אחרות שעוזרות בניהול עומסי עבודה מקבילים), 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 הושעו וחודשו.

לדוגמה, אפשר לראות שהפלח main יצר את הפלחים taskOne ו-taskTwo. אחרי זה שני השרשורים לא היו פעילים (בהנחה שהקורוטינות הושעו – בגלל השימוש ב-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, בזמן שמעקב המערכת מופעל. אחרי שיהיו לכם שני קובצי ה-trace, תוכלו להשתמש באפשרות Open Multiple Trace Files ב-Perfetto.

פתיחת כמה קובצי מעקב בממשק המשתמש של Perfetto

איור 6. פתיחה של כמה קובצי מעקב בממשק המשתמש של Perfetto.

תהליכי עבודה מתקדמים

השוואה בין רצועות

לפעמים כדאי לשייך את הפלחים ב-Trace לפעולת משתמש ברמה גבוהה יותר או לאירוע מערכת. לדוגמה, כדי לשייך את כל הפלחים שמתאימים לעבודה ברקע כחלק מהתראה, אפשר לעשות משהו כזה:

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 עם פרוסות מתואמות.

הוספת מידע על call stack

בנוסף, כלים בצד המארח (תוספי קומפיילר, מעבדי הערות וכו') יכולים לבחור להטמיע מידע על מחסנית הקריאות במעקב, כדי שיהיה נוח לאתר את הקובץ, המחלקה או השיטה שאחראים ליצירת קטע מעקב במעקב.

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 עם מידע על מחסנית הקריאות.