Use tracing to gain insights into system performance

Use tracing to record events and counters on the system and to visualize each on a timeline. The standard tracing tool in Android is Perfetto. To learn more, see Tracing 101.

Instrument your code

To get events from the app it needs to be instrumented by adding tracepoints into the code. Sections that are not instrumented won't show up in traces.

SDV tracing sample is a demo of tracing integration, along with instructions and an example of tracing config. It is located in system/software_defined_vehicle/core_services/samples/tracing/.

Rust

The recommended approach for Rust is to use the tracing crate to emit ATrace events. Perfetto supports ATrace as a data source. We plan to switch to Perfetto SDK when Rust bindings are available and depending on how the use cases evolve.

Add the tracing defaults to Android.bp:

rust_binary {
...
    defaults: [
        ...
        "sdv_tracing@rust_defaults",
    ],
...
}

Initialize the subscriber. This can only be done once per process:

fn main() {
    // Initialize the subscriber, panic if it fails.
    // sdv_tracing::try_init_tracing() is the version that returns a Result.
    sdv_tracing::init_tracing()
    ...
}

You can omit the initialization call. Doing so leaves tracing uninitialized and Perfetto won't collect instrumentation events from the app.

Add tracepoints. You can find more samples in system/software_defined_vehicle/core_services/samples/tracing/rust_tracing_api_demo/tracing.rs.

use tracing::{instrument, info_span};

// #[tracing::instrument] wraps the method into a tracing span and records arguments.
// Use #[instrument(skip(num))] if you don't want to record the argument.
#[instrument]
fn mul_by_100(num: i32) -> i32 {
    // Create and enter a span with INFO verbosity, name, and a debug field annotation.
    // The span will exit when dropped.
    let _span = info_span!("This is a span", var=123).entered();
    let result = num * 100;
    // Emit an instant INFO event that records the result value.
    // We recommend to fully qualify the crate when using events to avoid confusion with log records.
    tracing::info!(result, "Completed");
    result
}

C++

C++ tracing uses Perfetto SDK to track events. Add the tracing defaults to Android.bp:

cc_binary {
...
    defaults: [
...
        "sdv_tracing@cc_defaults",
    ],
...
}

Define the categories. If you use the categories across multiple modules, move them into a common library. For example, system/software_defined_vehicle/core_services/samples/tracing/cpp_service/tracing_categories.h.

In the header:

#include "perfetto/tracing/tracing.h"
#include "perfetto/tracing/track_event.h"

PERFETTO_DEFINE_CATEGORIES(
        perfetto::Category("sample")
                .SetTags("tag")
                .SetDescription("Sample events"));

Put the static storage macro in a .cpp source file not in a method. If you're sharing the categories across components, use the source file that corresponds to the header with categories.

PERFETTO_TRACK_EVENT_STATIC_STORAGE();

int main() {
    ...
}

To initialize Perfetto, initialize the system backend and register the track events:

#include <sdv/tracing_init.h>

int main() {
  ...
  android::sdv::InitPerfettoWithTrackEvents<perfetto::TrackEvent>();
  ...
}

Add instrumentation. See more samples in system/software_defined_vehicle/core_services/samples/tracing/cpp_service/client.cpp.

int32_t mulBy100(int32_t num) {
    // Start a slice that will get closed at the end of the scope.
    TRACE_EVENT("client", "mulBy100", "num", num);

    TRACE_EVENT("client", "This is a slice", "var", 123);
    int32_t result = num * 100;

    // Instant events have zero duration. They are drawn as markers on the track.
    TRACE_EVENT_INSTANT("client", "Completed", "result", result);
    return result;
}

As in the Rust example, this code produces two nested slices and a marker for the instant event in the UI. The debug argument values are shown when an event is selected.

Collect a trace

Use the record\_android\_trace command line script to record a trace and Perfetto web UI to view it.

Configure the capture

You need to provide a config for record_android_trace in textproto format. See Perfetto doc to learn more.

SDV repository contains a sample configuration (system/software_defined_vehicle/core_services/samples/tracing/config/trace_cfg.pbtx). This file includes several data sources and can be customized or used as is.

data_sources: {
    config {
        name: "linux.ftrace"
        ftrace_config {
            # Setting atrace_apps to "*" enable ATrace events for all apps.
            # You can set it to a pattern to match specific processes by name.
            # Use multiple atrace_apps entries to enable multiple processes.
            atrace_apps: "*"
        }
    }
}

data_sources: {
    config {
        name: "track_event"
        track_event_config {
            enabled_categories: "the_best_category_in_the_world"
            disabled_categories: "*"
        }
    }
}

Record a trace

Open a terminal in the Android repository root. No need to do envsetup. The recording script is in external/perfetto/tools/record_android_trace.

Run the script with the sample config:

external/perfetto/tools/record_android_trace --config system/software_defined_vehicle/core_services/samples/tracing/config/trace_cfg.pbtx

To stop the recording early, select Ctrl + C.

Doing so triggers adb shell perfetto to record a trace and then pull the trace to the host, usually in ~/traces. When the trace is collected, the tool opens a browser window to display the trace.

Helpful arguments:

• -s SERIAL to use the device with a given serial. For example -s 0.0.0.0:6520

• --no-open-browser would make a URL to serve the trace but won't open the browser. It is useful for remote sessions when you have port forwarding set up (usually 9001).

• -n, --no-open won't open the browser or make the URL to serve the trace after the tracing session. You can still open files in the Perfetto UI by clicking on "Open trace file" and selecting the file.

• -o <path> to set the output path.

Usage details

This section provides details that may be helpful when using the tracing system.

Trace instrumentation in SDV components

In agents with tracing instrumentation, tracing is available by default on debuggable builds (-eng, -userdebug), unless otherwise specified. When you collect a trace, you should see the events for the processes without extra configuration.

Libraries typically don't automatically initialize tracing. In Rust the binary that uses the library needs to initialize tracing for the process using sdv_tracing::init_tracing(). Refer to Instrument your code to learn more.

Middleware

Publishing/Subscribing Library: libsdv_middleware_dt

Events:

• Publisher: Publishing and registering topics.
• Subscriber: Subscribing and polling.

Enabling: Call sdv_tracing::init_tracing() or sdv_tracing::try_init_tracing() in the binary.

gRPC Library: libsdvmiddleware_rpc_grpc_transport

Events:

• RPC client: Starting, connecting to server, and RPC method calls.
• RPC server: Starting, registering with Service Discovery, adding and calling RPC methods.

Enabling: Call sdv_tracing::init_tracing() or sdv_tracing::try_init_tracing() in binary.

SOME/IP

• Process: sdv_someip_broker_agent. \
• Events: Message processing and translation, event subscription.

Lifecycle manager

• Process: sdv_lifecycle_agent. \
• Events: Service operations - launching, stopping, registering, unregistering.

Vehicle power mode

• Process: sdv_vpm_agent. \
• Events: Power state changes and subscriptions.

Data Tunnel

We plan to support tracing integration at a future time.

Performance overhead of tracing

The overhead measurements come with the usual caveat that the performance may differ across different systems and especially between the emulator and real hardware.

Rust

Raw benchmark data is available in AOSP. The data was collected on a Cuttlefish VM.

• Single span: tracing::info_span!(), #[tracing::instrument] and similar:
  • Tracing uninitialized: 1ns.
  • Tracing initialized and disabled (no trace recording happening): 30ns.
  • Tracing enabled: 3 µs. Debug field annotations can add 1-2 µs, depending on stringification complexity.
• Single event: tracing::info!() and similar:
  • Tracing uninitialized: 1ns.
  • Tracing initialized and disabled: 30ns.
  • Tracing enabled: 1.5 µs. Debug field annotations can add 0.5-1 µs, depending on stringification complexity.

C++

Performance numbers are from the Performance section of the Track events doc in Perfetto. The times for Pixel 3 in the table are consistent with our observations on Cuttlefish VM.

Single slice: TRACE_EVENT() and similar. Tracing:

• Disabled: 2ns.
• Enabled: 300ns. Using debug field annotations can add 50-100ns.