pw_trace#

Pigweed’s tracing module provides facilities for applications to trace information about the execution of their application. The module is split into two components:

  1. The facade (this module) which is only a macro interface layer

  2. The backend, provided elsewhere, implements the low level tracing.

Status#

Pigweed AI summary: The "Status" section of a module explains that it is still in development and undergoing significant changes. Future work includes adding a Python library to generate trace files, adding more examples with sample output, and implementing a trace backend module.

This module is currently in development, and is therefore still undergoing significant changes.

Future work will add:

  1. A Python library to generate trace files which can be viewed. (pwbug/205)

  2. Add more examples with sample output. (pwbug/207)

  3. Implement a trace backend module. (pwbug/260)

Overview#

Pigweed AI summary: Tracing is a useful tool for understanding complex software problems by showing the flow of events through a system. Traces capture sequences of events with precise timestamps, making them useful for understanding the flow of events over time. The default backend for pw_trace is pw_trace_null, which disables tracing. Most of the facade is compatible with C and C++, with the exception of the Scope and Function tracing macros, which are only available in C++. The pw_trace_null backend ignores all pw_trace statements and can be

Traces provide a useful view which shows the flow of events through a system, and can greatly assist in understanding complex software problems. These traces can either show what tasks are running at any given time, or use added code (similar to logging), to help annotate specific interesting flows.

Fundamentally, tracing is similar to logging in that it provides the developer with a view into what the system was doing at a particular time. The fundamental difference between logs and tracing is that logs present information as ad-hoc human-readable strings and are better suited to providing the current state of the system. Instead, traces capture sequences of events with precise timestamps, and are therefore useful at understanding the flow of events in the system over time.

The default backend for pw_trace is pw_trace_null, which disables tracing.

Compatibility#

Pigweed AI summary: The majority of the facade is compatible with both C and C++, with the exception of the Scope and Function tracing macros, which are only available in C++.

Most of the facade is compatible with C and C++, the only exception to this is the Scope and Function tracing macros which are convenience wrappers only available in C++.

pw_trace:null#

Pigweed AI summary: The "pw_trace_null" is a backend for "pw_trace" that ignores all statements. It uses empty inline functions to ensure that arguments are evaluated and their types are correct. This backend can be used to disable "pw_trace" completely.

pw_trace_null is a pw_trace backend that ignores all pw_trace statements. The backend implements pw_trace with empty inline functions. Using empty functions ensure that the arguments are evaluated and their types are correct. Since the functions are inline in the header, the compiler will optimize out the function call.

This backend can be used to completely disable pw_trace.

Dependencies#

Pigweed AI summary: The Dependencies section lists only one item, which is the pw_preprocessor.

pw_preprocessor

Example#

Pigweed AI summary: This code snippet is written in C++ and includes a few functions that use the PW_TRACE library to trace events and measure the time it takes to handle them. The SendButton function is traced using PW_TRACE_FUNCTION, while the InputLoop function uses TRACE_SCOPE to measure the time it takes to handle an event. The ButtonIsr function uses PW_TRACE_START to start tracing an event and PW_TRACE_END to end it. Overall, this code demonstrates how to use the PW_TRACE library to measure and trace

#define PW_TRACE_MODULE_NAME "Input"
#include "pw_trace/trace.h"

void SendButton() {
  PW_TRACE_FUNCTION()
  // do something
}

void InputLoop() {
  while(1) {
    auto event = WaitNewInputEvent()
    TRACE_SCOPE("Handle Event");  // measure until loop finished
    if (event == kNewButton){
      SendButton();
      PW_TRACE_END("button");  // Trace event was started in ButtonIsr
    } else {
      PW_TRACE_INSTANT("Unknown event");
    }
  }
}

void ButtonIsr() {
  PW_TRACE_START("button");
  SendNewInputEvent(kNewButton);
}

Trace macros#

The pw_trace public API provides three basic trace events:

  • PW_TRACE_INSTANT - This is used to trace an instant event, which has no duration.

  • PW_TRACE_START & PW_TRACE_END - Trace ‘start’ and ‘end’ events are paired together to measure the duration of an event.

These trace event macros all have the same arguments:

  • label - Each of these trace events must have a label, which is a string describing the event. In addition to the required label, each of these traces can optionally provide a group label and trace id.

  • group_label - The optional group label is used if many traces are all measuring the same thing and should be grouped together. This information will be used when visualizing the trace to ensure the information appears together.

  • trace_id - The optional trace id is similar to the group_id, but instead groups events using a runtime value. This can be used if multiple trace flow might happen at the same time and need to be grouped together. For example, this could be used to trace data packets flowing through the system; when a new sample might arrive before the previous packet is finished processing. This would result in two start events occurring before the end event. By providing a trace id with a different value for each packet, these can be separated when decoding.

Tip

All of these arguments must be the same for a start and end pair.

This results in 9 different trace calls:

PW_TRACE_INSTANT(label)#
PW_TRACE_INSTANT(label, group_label)#
PW_TRACE_INSTANT(label, group_label, trace_id)#
PW_TRACE_START(label)#
PW_TRACE_START(label, group_label)#
PW_TRACE_START(label, group_label, trace_id)#
PW_TRACE_END(label)#
PW_TRACE_END(label, group_label)#
PW_TRACE_END(label, group_label, trace_id)#

Modules#

Pigweed AI summary: Traces can be grouped into modules similar to logging by redefining the PW_TRACE_MODULE_NAME.

In addition to these arguments, traces can be grouped into modules similar to logging. This is done by redefining the PW_TRACE_MODULE_NAME.

Flags#

Each trace event also has a flags field which can be used to provide additional compile time trace information. Each trace macro has a matching macro which allows specifying the flag:

PW_TRACE_INSTANT_FLAG(flag, label)#
PW_TRACE_INSTANT_FLAG(flag, label, group_label)#
PW_TRACE_INSTANT_FLAG(flag, label, group_label, trace_id)#
PW_TRACE_START_FLAG(flag, label)#
PW_TRACE_START_FLAG(flag, label, group_label)#
PW_TRACE_START_FLAG(flag, label, group_label, trace_id)#
PW_TRACE_END_FLAG(flag, label)#
PW_TRACE_END_FLAG(flag, label, group_label)#
PW_TRACE_END_FLAG(flag, label, group_label, trace_id)#

When not specified the flag uses the value of the macro PW_TRACE_FLAGS.

Data#

Each macro also has a variant which allows appending additional data:

PW_TRACE_INSTANT_DATA(label, data_format_string, data, size)#
PW_TRACE_INSTANT_DATA(label, group_label, data_format_string, data, size)#
PW_TRACE_INSTANT_DATA(label, group_label, trace_id, data_format_string, data, size)#
PW_TRACE_START_DATA(label, data_format_string, data, size)#
PW_TRACE_START_DATA(label, group_label, data_format_string, data, size)#
PW_TRACE_START_DATA(label, group_label, trace_id, data_format_string, data, size)#
PW_TRACE_END_DATA(label, data_format_string, data, size)#
PW_TRACE_END_DATA(label, group_label, data_format_string, data, size)#
PW_TRACE_END_DATA(label, group_label, trace_id, data_format_string, data, size)#

These macros require 3 additional arguments:

  • data_format_string - A string which is used by the decoder to identify the data. This could for example either be printf style tokens, python struct packed fmt string or a custom label recognized by the decoder.

  • data - A pointer to a buffer of arbitrary caller-provided data (void*).

  • size - The size of the data (size_t).

Currently the included python tool supports a few different options for data_format_string:

  • @pw_arg_label - Uses the string in the data as the trace event label.

  • @pw_arg_group - Uses the string in the data as the trace event group.

  • @pw_arg_counter - Uses the data as a little endian integer value, and visualizes it as a counter value in the trace (on a graph).

  • @pw_py_struct_fmt: - Interprets the string after the “:” as a python struct format string, and uses that format string to unpack the data elements. This can be used to either provide a single value type, or provide multiple different values with a variety of types. Options for format string types can be found here: https://docs.python.org/3/library/struct.html#format-characters . The data is always assumed to be packed with little-endian ordering if not indicated otherwise:

    // Example
data_format_string = "@pw_py_struct_fmt:ll"
data = 0x1400000014000000
args = {data_0: 20, data_1:20}

  • @pw_py_map_fmt: - Interprets the string after the “:” as a dictionary relating the data field name to the python struct format string. Once collected, the format strings are concatenated and used to unpack the data elements as above. The data is always assumed to be packed with little-endian ordering if not indicated otherwise. To specify a different ordering, construct the format string as @pw_py_map_fmt:[@=<>!]{k:v,...}:

    // Example
data_format_string = "@pw_py_map_fmt:{Field: l, Field2: l }"
data = 0x1400000014000000
args = {Field: 20, Field2:20}

Tip

It is ok for only one event of a start/end pair to contain data, as long the label, group_label, and trace_id, are all the same.

C++ Only Traces#

Scope API measures durations until the object loses scope. This can for example, provide a convenient method of tracing functions or loops.

PW_TRACE_SCOPE(label)#
PW_TRACE_SCOPE(label, group_label)#

Function API measures durations until the function returns. This is the only macro which does not require a label, and instead uses the function name as the label. It still can optionally be provided a group_id.

PW_TRACE_FUNCTION()#
PW_TRACE_FUNCTION(group_label)#

Compile time enabling/disabling#

Pigweed AI summary: This section discusses how to enable or disable traces in a file at compile time using the PW_TRACE_ENABLE macro. A value of 0 disables traces, while a non-zero value enables them. It is recommended to define PW_TRACE_ENABLE explicitly in files that use tracing, as the default may change in the future. A good practice is to have a module level configuration parameter for enabling tracing and define PW_TRACE_ENABLE in terms of that at the top of each module's files. Specific trace points can also be

Traces in a file can be enabled/disabled at compile time by defining through the PW_TRACE_ENABLE macro. A value of 0 causes traces to be disabled. A non-zero value will enable traces. While tracing defaults to enabled, it is best practice to define PW_TRACE_ENABLE explicitly in files that use tracing as the default may change in the future.

A good pattern is to have a module level configuration parameter for enabling tracing and define PW_TRACE_ENABLE in terms of that at the top of each of the module’s files:

// Enable tracing based on pw_example module config parameter.
#define PW_TRACE_ENABLE PW_EXAMPLE_TRACE_ENABLE

Additionally specific trace points (or sets of points) can be enabled/disabled using the following pattern:

// Assuming tracing is disabled at the top of the file.

// Enable specific trace.
#undef PW_TRACE_ENABLE
#define PW_TRACE_ENABLE 1
PW_TRACE_INSTANT("important trace");

// Set traces back to disabled.  PW_TRACE_ENABLE can not be left
// undefined.
#undef PW_TRACE_ENABLE
#define PW_TRACE_ENABLE 0

Backend API#

Each of the trace event macros get sent to one of two macros which are implemented by the backend:

PW_TRACE(event_type, flags, label, group_label, trace_id)#
PW_TRACE_DATA(event_type, flags, label, group_label, trace_id, data_format_string, data, size)#

The event_type value will be whatever the backend defined for that specific trace type using the macros defined below.

The backend can optionally not define PW_TRACE_DATA to have those traces disabled.

Trace types#

Pigweed AI summary: This section explains the 9 different trace event types that can be created from the 3 basic trace types, each with 3 variants. The 9 types include instant trace, start trace, end trace, instant trace with a group, start trace with a group, end trace with a group, instant trace with label, group, and trace_id, start trace with label, group, and trace_id, and end trace with label, group, and trace_id. The macros for these types must

Although there are only 3 basic trace types, each has 3 variants:

  • Label only

  • Label and group

  • Label, group, and trace_id

This combination creates 9 different trace event types:

  • PW_TRACE_TYPE_INSTANT: Instant trace, with only a label.

  • PW_TRACE_TYPE_DURATION_START: Start trace, with only a label.

  • PW_TRACE_TYPE_DURATION_END: End trace, with only a label.

  • PW_TRACE_TYPE_INSTANT_GROUP: Instant trace, with a label and a group.

  • PW_TRACE_TYPE_DURATION_GROUP_START: Start trace, with a label and a group.

  • PW_TRACE_TYPE_DURATION_GROUP_END: End trace, with a label and a group.

  • PW_TRACE_TYPE_ASYNC_INSTANT: Instant trace, with label, group, and trace_id

  • PW_TRACE_TYPE_ASYNC_START: Start trace, with label, group, and trace_id.

  • PW_TRACE_TYPE_ASYNC_END: End trace, with label, group, and trace_id.

The backend must define these macros to have them enabled. If any are left undefined, any traces of that type are removed.

Defaults#

Pigweed AI summary: This section explains the macros that can be used to change the default values in the backend if no values are provided. The macros include PW_TRACE_FLAGS_DEFAULT, PW_TRACE_TRACE_ID_DEFAULT, and PW_TRACE_GROUP_LABEL_DEFAULT.

The backend can use these macros to change what the default value is if not provided.

  • PW_TRACE_FLAGS_DEFAULT: Default value if no flags are provided.

  • PW_TRACE_TRACE_ID_DEFAULT: Default value if no trace_id provided.

  • PW_TRACE_GROUP_LABEL_DEFAULT: Default value if no group_label provided.

Sample App#

Pigweed AI summary: The Sample App provided in the examples folder showcases the various ways tracing can be used, and can be used by trace backends to demonstrate other features. The app contains three simulated tasks - Input, Processing, and Kernel - each with their own trace module. The jobs in the app have multiple stages of processing, resulting in multiple jobs being handled simultaneously with the use of trace_id to separate them.

A sample application is provided in the examples folder. This code attempts to provide examples of the multiple ways tracing can be used. Furthermore, trace backends can include the sample app in their own examples to show how to use other features.

The sample app contains 3 “fake” tasks, which are each in their own PW_TRACE_MODULE.

  • Input: Simulating a driver, which gets data periodically, and sends to Processing task.

  • Processing: Has a work queue, which handles processing the jobs.

  • Kernel: A simple work loop which demonstrates a possible integration of tracing with a RTOS/Kernel.

Jobs are intentionally made to have multiple stages of processing (simulated by being re-added to the work-queue). This results in multiple jobs being handled at the same time, the trace_id is used to separate these traces.

Python Trace Generator#

Pigweed AI summary: The Python Trace Generator is a tool that is still in early development, but it can currently generate a list of json lines from a list of trace events. These lines can be saved to a file and loaded into chrome://tracing to view the trace. Future work will include adding config options to customize output, a method of providing custom data formatters, and Perfetto support.

The Python tool is still in early development, but currently it supports generating a list of json lines from a list of trace events.

To view the trace, these lines can be saved to a file and loaded into chrome://tracing.

Future work will look to add:

  • Config options to customize output.

  • A method of providing custom data formatters.

  • Perfetto support.