# Track events (Tracing SDK) Track events are part of the [Perfetto Tracing SDK](tracing-sdk.md). *Track events* are application specific, time bounded events recorded into a *trace* while the application is running. Track events are always associated with a *track*, which is a timeline of monotonically increasing time. A track corresponds to an independent sequence of execution, such as a single thread in a process. ![Track events shown in the Perfetto UI]( /docs/images/track-events.png "Track events in the Perfetto UI") See the [Getting started](/docs/instrumentation/tracing-sdk#getting-started) section of the Tracing SDK page for instructions on how to check out and build the SDK. TIP: The code from these examples is also available [in the repository](/examples/sdk/README.md). There are a few main types of track events: - **Slices**, which represent nested, time bounded operations. For example, a slice could cover the time period from when a function begins executing to when it returns, the time spent loading a file from the network or the time to complete a user journey. - **Counters**, which are snapshots of time-varying numeric values. For example, a track event can record instantaneous the memory usage of a process during its execution. - **Flows**, which are used to connect related slices that span different tracks together. For example, if an image file is first loaded from the network and then decoded on a thread pool, a flow event can be used to highlight its path through the system. (Not fully implemented yet). The [Perfetto UI](https://ui.perfetto.dev) has built in support for track events, which provides a useful way to quickly visualize the internal processing of an app. For example, the [Chrome browser](https://www.chromium.org/developers/how-tos/trace-event-profiling-tool) is deeply instrumented with track events to assist in debugging, development and performance analysis. To start using track events, first define the set of categories that your events will fall into. Each category can be separately enabled or disabled for tracing (see [Category configuration](#category-configuration)). Add the list of categories into a header file (e.g., `my_app_tracing_categories.h`) like this: ```C++ #include PERFETTO_DEFINE_CATEGORIES( perfetto::Category("rendering") .SetDescription("Events from the graphics subsystem"), perfetto::Category("network") .SetDescription("Network upload and download statistics")); ``` Then, declare static storage for the categories in a cc file (e.g., `my_app_tracing_categories.cc`): ```C++ #include "my_app_tracing_categories.h" PERFETTO_TRACK_EVENT_STATIC_STORAGE(); ``` Finally, initialize track events after the client library is brought up: ```C++ int main(int argv, char** argc) { ... perfetto::Tracing::Initialize(args); perfetto::TrackEvent::Register(); // Add this. } ``` Now you can add track events to existing functions like this: ```C++ #include "my_app_tracing_categories.h" void DrawPlayer() { TRACE_EVENT("rendering", "DrawPlayer"); // Begin "DrawPlayer" slice. ... // End "DrawPlayer" slice. } ``` This type of trace event is scoped, under the hood it uses C++ [RAII]. The event will cover the time from when the `TRACE_EVENT` annotation is encountered to the end of the block (in the example above, until the function returns). For events that don't follow function scoping, use `TRACE_EVENT_BEGIN` and `TRACE_EVENT_END`: ```C++ void LoadGame() { DisplayLoadingScreen(); TRACE_EVENT_BEGIN("io", "Loading"); // Begin "Loading" slice. LoadCollectibles(); LoadVehicles(); LoadPlayers(); TRACE_EVENT_END("io"); // End "Loading" slice. StartGame(); } ``` Note that you don't need to give a name for `TRACE_EVENT_END`, since it automatically closes the most recent event that began on the same thread. In other words, all events on a given thread share the same stack. This means that it's not recommended to have a matching pair of `TRACE_EVENT_BEGIN` and `TRACE_EVENT_END` markers in separate functions, since an unrelated event might terminate the original event unexpectedly; for events that cross function boundaries it's usually best to emit them on a [separate track](#tracks). You can also supply (up to two) debug annotations together with the event. ```C++ int player_number = 1; TRACE_EVENT("rendering", "DrawPlayer", "player_number", player_number); ``` See [below](#track-event-arguments) for the other types of supported track event arguments. For more complex arguments, you can define [your own protobuf messages](/protos/perfetto/trace/track_event/track_event.proto) and emit them as a parameter for the event. NOTE: Currently custom protobuf messages need to be added directly to the Perfetto repository under `protos/perfetto/trace`, and Perfetto itself must also be rebuilt. We are working [to lift this limitation](https://github.com/google/perfetto/issues/11). As an example of a custom track event argument type, save the following as `protos/perfetto/trace/track_event/player_info.proto`: ```protobuf message PlayerInfo { optional string name = 1; optional uint64 score = 2; } ``` This new file should also be added to `protos/perfetto/trace/track_event/BUILD.gn`: ```json sources = [ ... "player_info.proto" ] ``` Also, a matching argument should be added to the track event message definition in `protos/perfetto/trace/track_event/track_event.proto`: ```protobuf import "protos/perfetto/trace/track_event/player_info.proto"; ... message TrackEvent { ... // New argument types go here. optional PlayerInfo player_info = 1000; } ``` The corresponding trace point could look like this: ```C++ Player my_player; TRACE_EVENT("category", "MyEvent", [&](perfetto::EventContext ctx) { auto player = ctx.event()->set_player_info(); player->set_name(my_player.name()); player->set_player_score(my_player.score()); }); ``` The lambda function passed to the macro is only called if tracing is enabled for the given category. It is always called synchronously and possibly multiple times if multiple concurrent tracing sessions are active. Now that you have instrumented your app with track events, you are ready to start [recording traces](tracing-sdk.md#recording). ## Category configuration All track events are assigned to one more trace categories. For example: ```C++ TRACE_EVENT("rendering", ...); // Event in the "rendering" category. ``` By default, all non-debug and non-slow track event categories are enabled for tracing. *Debug* and *slow* categories are categories with special tags: - `"debug"` categories can give more verbose debugging output for a particular subsystem. - `"slow"` categories record enough data that they can affect the interactive performance of your app. Category tags can be can be defined like this: ```C++ perfetto::Category("rendering.debug") .SetDescription("Debug events from the graphics subsystem") .SetTags("debug", "my_custom_tag") ``` A single trace event can also belong to multiple categories: ```C++ // Event in the "rendering" and "benchmark" categories. TRACE_EVENT("rendering,benchmark", ...); ``` A corresponding category group entry must be added to the category registry: ```C++ perfetto::Category::Group("rendering,benchmark") ``` It's also possible to efficiently query whether a given category is enabled for tracing: ```C++ if (TRACE_EVENT_CATEGORY_ENABLED("rendering")) { // ... } ``` The `TrackEventConfig` field in Perfetto's `TraceConfig` can be used to select which categories are enabled for tracing: ```protobuf message TrackEventConfig { // Each list item is a glob. Each category is matched against the lists // as explained below. repeated string disabled_categories = 1; // Default: [] repeated string enabled_categories = 2; // Default: [] repeated string disabled_tags = 3; // Default: [“slow”, “debug”] repeated string enabled_tags = 4; // Default: [] } ``` To determine if a category is enabled, it is checked against the filters in the following order: 1. Exact matches in enabled categories. 2. Exact matches in enabled tags. 3. Exact matches in disabled categories. 4. Exact matches in disabled tags. 5. Pattern matches in enabled categories. 6. Pattern matches in enabled tags. 7. Pattern matches in disabled categories. 8. Pattern matches in disabled tags. If none of the steps produced a match, the category is enabled by default. In other words, every category is implicitly enabled unless specifically disabled. For example: | Setting | Needed configuration | | ------------------------------- | -------------------------------------------- | | Enable just specific categories | `enabled_categories = [“foo”, “bar”, “baz”]` | | | `disabled_categories = [“*”]` | | Enable all non-slow categories | (Happens by default.) | | Enable specific tags | `disabled_tags = [“*”]` | | | `enabled_tags = [“foo”, “bar”]` | ## Dynamic and test-only categories Ideally all trace categories should be defined at compile time as shown above, as this ensures trace points will have minimal runtime and binary size overhead. However, in some cases trace categories can only be determined at runtime (e.g., they come from instrumentation in a dynamically loaded JavaScript running in a WebView or in a NodeJS engine). These can be used by trace points as follows: ```C++ perfetto::DynamicCategory dynamic_category{"nodejs.something"}; TRACE_EVENT(dynamic_category, "SomeEvent", ...); ``` TIP: It's also possible to use dynamic event names by passing `nullptr` as the name and filling in the `TrackEvent::name` field manually. Some trace categories are only useful for testing, and they should not make it into a production binary. These types of categories can be defined with a list of prefix strings: ```C++ PERFETTO_DEFINE_TEST_CATEGORY_PREFIXES( "test", // Applies to test.* "dontship" // Applies to dontship.*. ); ``` ## Performance Perfetto's trace points are designed to have minimal overhead when tracing is disabled while providing high throughput for data intensive tracing use cases. While exact timings will depend on your system, there is a [microbenchmark](/src/tracing/api_benchmark.cc) which gives some ballpark figures: | Scenario | Runtime on Pixel 3 XL | Runtime on ThinkStation P920 | | -------- | --------------------- | ---------------------------- | | `TRACE_EVENT(...)` (disabled) | 2 ns | 1 ns | | `TRACE_EVENT("cat", "name")` | 285 ns | 630 ns | | `TRACE_EVENT("cat", "name", )` | 304 ns | 663 ns | | `TRACE_EVENT("cat", "name", "key", value)` | 354 ns | 664 ns | | `DataSource::Trace()` (disabled) | 2 ns | 1 ns | | `DataSource::Trace()` | 133 ns | 58 ns | ## Advanced topics ### Track event arguments The following optional arguments can be passed to `TRACE_EVENT` to add extra information to events: ```C++ TRACE_EVENT("cat", "name"[, track][, timestamp] (, "debug_name", debug_value |, TrackEvent::kFieldName, value)* [, lambda]); ``` Some examples of valid combinations: 1. A lambda for writing custom TrackEvent fields: ```C++ TRACE_EVENT("category", "Name", [&](perfetto::EventContext ctx) { ctx.event()->set_custom_value(...); }); ``` 2. A timestamp and a lambda: ```C++ TRACE_EVENT("category", "Name", time_in_nanoseconds, [&](perfetto::EventContext ctx) { ctx.event()->set_custom_value(...); }); ``` |time_in_nanoseconds| should be an uint64_t by default. To support custom timestamp types, |perfetto::TraceTimestampTraits::ConvertTimestampToTraceTimeNs| should be defined. See |ConvertTimestampToTraceTimeNs| for more details. 3. Arbitrary number of debug annotations: ```C++ TRACE_EVENT("category", "Name", "arg", value); TRACE_EVENT("category", "Name", "arg", value, "arg2", value2); TRACE_EVENT("category", "Name", "arg", value, "arg2", value2, "arg3", value3); ``` See |TracedValue| for recording custom types as debug annotations. 4. Arbitrary number of TrackEvent fields (including extensions): ```C++ TRACE_EVENT("category", "Name", perfetto::protos::pbzero::TrackEvent::kFieldName, value); ``` 5. Arbitrary combination of debug annotations and TrackEvent fields: ```C++ TRACE_EVENT("category", "Name", perfetto::protos::pbzero::TrackEvent::kFieldName, value1, "arg", value2); ``` 6. Arbitrary combination of debug annotations / TrackEvent fields and a lambda: ```C++ TRACE_EVENT("category", "Name", "arg", value1, pbzero::TrackEvent::kFieldName, value2, [&](perfetto::EventContext ctx) { ctx.event()->set_custom_value(...); }); ``` 7. An overridden track: ```C++ TRACE_EVENT("category", "Name", perfetto::Track(1234)); ``` See |Track| for other types of tracks which may be used. 8. A track and a lambda: ```C++ TRACE_EVENT("category", "Name", perfetto::Track(1234), [&](perfetto::EventContext ctx) { ctx.event()->set_custom_value(...); }); ``` 9. A track and a timestamp: ```C++ TRACE_EVENT("category", "Name", perfetto::Track(1234), time_in_nanoseconds); ``` 10. A track, a timestamp and a lambda: ```C++ TRACE_EVENT("category", "Name", perfetto::Track(1234), time_in_nanoseconds, [&](perfetto::EventContext ctx) { ctx.event()->set_custom_value(...); }); ``` 11. A track and any combination of debug annotions and TrackEvent fields: ```C++ TRACE_EVENT("category", "Name", perfetto::Track(1234), "arg", value); TRACE_EVENT("category", "Name", perfetto::Track(1234), "arg", value, "arg2", value2); TRACE_EVENT("category", "Name", perfetto::Track(1234), "arg", value, "arg2", value2, pbzero::TrackEvent::kFieldName, value3); ``` ### Tracks Every track event is associated with a track, which specifies the timeline the event belongs to. In most cases, a track corresponds to a visual horizontal track in the Perfetto UI like this: ![Track timelines shown in the Perfetto UI]( /docs/images/track-timeline.png "Track timelines in the Perfetto UI") Events that describe parallel sequences (e.g., separate threads) should use separate tracks, while sequential events (e.g., nested function calls) generally belong on the same track. Perfetto supports three kinds of tracks: - `Track` – a basic timeline. - `ProcessTrack` – a timeline that represents a single process in the system. - `ThreadTrack` – a timeline that represents a single thread in the system. Tracks can have a parent track, which is used to group related tracks together. For example, the parent of a `ThreadTrack` is the `ProcessTrack` of the process the thread belongs to. By default, tracks are grouped under the current process's `ProcessTrack`. A track is identified by a uuid, which must be unique across the entire recorded trace. To minimize the chances of accidental collisions, the uuids of child tracks are combined with those of their parents, with each `ProcessTrack` having a random, per-process uuid. By default, track events (e.g., `TRACE_EVENT`) use the `ThreadTrack` for the calling thread. This can be overridden, for example, to mark events that begin and end on a different thread: ```C++ void OnNewRequest(size_t request_id) { // Open a slice when the request came in. TRACE_EVENT_BEGIN("category", "HandleRequest", perfetto::Track(request_id)); // Start a thread to handle the request. std::thread worker_thread([=] { // ... produce response ... // Close the slice for the request now that we finished handling it. TRACE_EVENT_END("category", perfetto::Track(request_id)); }); ``` Tracks can also optionally be annotated with metadata: ```C++ auto desc = track.Serialize(); desc.set_name("MyTrack"); perfetto::TrackEvent::SetTrackDescriptor(track, desc); ``` Threads and processes can also be named in a similar way, e.g.: ```C++ auto desc = perfetto::ProcessTrack::Current().Serialize(); desc.mutable_process()->set_process_name("MyProcess"); perfetto::TrackEvent::SetTrackDescriptor( perfetto::ProcessTrack::Current(), desc); ``` The metadata remains valid between tracing sessions. To free up data for a track, call EraseTrackDescriptor: ```C++ perfetto::TrackEvent::EraseTrackDescriptor(track); ``` ### Counters Time-varying numeric data can be recorded with the `TRACE_COUNTER` macro: ```C++ TRACE_COUNTER("category", "MyCounter", 1234.5); ``` This data is displayed as a counter track in the Perfetto UI: ![A counter track shown in the Perfetto UI]( /docs/images/counter-events.png "A counter track shown in the Perfetto UI") Both integer and floating point counter values are supported. Counters can also be annotated with additional information such as units, for example, for tracking the rendering framerate in terms of frames per second or "fps": ```C++ TRACE_COUNTER("category", perfetto::CounterTrack("Framerate", "fps"), 120); ``` As another example, a memory counter that records bytes but accepts samples as kilobytes (to reduce trace binary size) can be defined like this: ```C++ perfetto::CounterTrack memory_track = perfetto::CounterTrack("Memory") .set_unit("bytes") .set_multiplier(1024); TRACE_COUNTER("category", memory_track, 4 /* = 4096 bytes */); ``` See [counter_descriptor.proto]( /protos/perfetto/trace/track_event/counter_descriptor.proto) for the full set of attributes for a counter track. To record a counter value at a specific point in time (instead of the current time), you can pass in a custom timestamp: ```C++ // First record the current time and counter value. uint64_t timestamp = perfetto::TrackEvent::GetTraceTimeNs(); int64_t value = 1234; // Later, emit a sample at that point in time. TRACE_COUNTER("category", "MyCounter", timestamp, value); ``` ### Interning Interning can be used to avoid repeating the same constant data (e.g., event names) throughout the trace. Perfetto automatically performs interning for most strings passed to `TRACE_EVENT`, but it's also possible to also define your own types of interned data. First, define an interning index for your type. It should map to a specific field of [interned_data.proto](/protos/perfetto/trace/interned_data/interned_data.proto) and specify how the interned data is written into that message when seen for the first time. ```C++ struct MyInternedData : public perfetto::TrackEventInternedDataIndex< MyInternedData, perfetto::protos::pbzero::InternedData::kMyInternedDataFieldNumber, const char*> { static void Add(perfetto::protos::pbzero::InternedData* interned_data, size_t iid, const char* value) { auto my_data = interned_data->add_my_interned_data(); my_data->set_iid(iid); my_data->set_value(value); } }; ``` Next, use your interned data in a trace point as shown below. The interned string will only be emitted the first time the trace point is hit (unless the trace buffer has wrapped around). ```C++ TRACE_EVENT( "category", "Event", [&](perfetto::EventContext ctx) { auto my_message = ctx.event()->set_my_message(); size_t iid = MyInternedData::Get(&ctx, "Repeated data to be interned"); my_message->set_iid(iid); }); ``` Note that interned data is strongly typed, i.e., each class of interned data uses a separate namespace for identifiers. ### Tracing session observers The session observer interface allows applications to be notified when track event tracing starts and stops: ```C++ class Observer : public perfetto::TrackEventSessionObserver { public: ~Observer() override = default; void OnSetup(const perfetto::DataSourceBase::SetupArgs&) override { // Called when tracing session is configured. Note tracing isn't active yet, // so track events emitted here won't be recorded. } void OnStart(const perfetto::DataSourceBase::StartArgs&) override { // Called when a tracing session is started. It is possible to emit track // events from this callback. } void OnStop(const perfetto::DataSourceBase::StopArgs&) override { // Called when a tracing session is stopped. It is still possible to emit // track events from this callback. } }; ``` Note that all methods of the interface are called on an internal Perfetto thread. For example, here's how to wait for any tracing session to start: ```C++ class Observer : public perfetto::TrackEventSessionObserver { public: Observer() { perfetto::TrackEvent::AddSessionObserver(this); } ~Observer() { perfetto::TrackEvent::RemoveSessionObserver(this); } void OnStart(const perfetto::DataSourceBase::StartArgs&) override { std::unique_lock lock(mutex); cv.notify_one(); } void WaitForTracingStart() { printf("Waiting for tracing to start...\n"); std::unique_lock lock(mutex); cv.wait(lock, [] { return perfetto::TrackEvent::IsEnabled(); }); printf("Tracing started\n"); } std::mutex mutex; std::condition_variable cv; }; Observer observer; observer.WaitForTracingToStart(); ``` [RAII]: https://en.cppreference.com/w/cpp/language/raii