Wyatt Hepler | f9fb90f | 2020-09-30 18:59:33 -0700 | [diff] [blame] | 1 | .. _module-pw_trace_tokenized: |
Robert Oliver | 21dcf27 | 2020-05-12 15:41:52 -0400 | [diff] [blame] | 2 | |
| 3 | ================== |
| 4 | pw_trace_tokenized |
| 5 | ================== |
| 6 | Pigweed's tracing module provides facilities for applications to trace |
| 7 | information about the execution of their application. The module is split into |
| 8 | two components: |
| 9 | |
| 10 | 1. The facade, provided elsewhere, which is only a macro interface layer |
| 11 | 2. The backend (this module), is one implemention of the low level tracing. |
| 12 | |
| 13 | ------ |
| 14 | Status |
| 15 | ------ |
| 16 | This module is currently in development, and is therefore still undergoing |
| 17 | significant changes. |
| 18 | |
Shiva Rajagopal | 9e51656 | 2021-05-11 17:04:15 -0700 | [diff] [blame] | 19 | Future work will: |
Robert Oliver | 21dcf27 | 2020-05-12 15:41:52 -0400 | [diff] [blame] | 20 | |
Robert Oliver | 81e6e3e | 2020-06-25 14:43:40 -0400 | [diff] [blame] | 21 | 1. Add a more complete API for how to retrieve data from ring_buffer. |
Robert Oliver | 21dcf27 | 2020-05-12 15:41:52 -0400 | [diff] [blame] | 22 | 2. Add a Python library to decode the trace data. |
| 23 | 3. Add examples with sample output (especially for filtering and triggering). |
| 24 | 4. Add tools to retrieve trace data. |
| 25 | 5. Add more sinks, such as RTT. |
| 26 | 6. Add support to more platforms. |
| 27 | 7. Improve the locking behaviour and provide default trace locking |
| 28 | implementions. |
| 29 | |
| 30 | -------- |
| 31 | Overview |
| 32 | -------- |
| 33 | The tokenized trace backend aims to be a reasonable tradeoff of trace features |
| 34 | and event size for most applications. It works by encoding all compile time data |
| 35 | for a trace event into a tokenized number. This provides a good amount of |
| 36 | compression, while maintaining the full trace feature set. |
| 37 | |
| 38 | In addition the tokenized trace backend adds flexibility through callbacks, |
| 39 | which allows the application to do things such as filtering trace_events and |
| 40 | triggering tracing to turn on and off. This flexibility can help maximize the |
| 41 | effectiveness of a limited trace buffer as well as be a valuable tool while |
| 42 | debugging. |
| 43 | |
| 44 | |
| 45 | Compatibility |
| 46 | ------------- |
| 47 | Most of this module is compatible with C and C++, the only exception to this is |
| 48 | the ``RegisterCallbackWhenCreated`` helper class. |
| 49 | |
| 50 | Dependencies |
| 51 | ------------ |
| 52 | ``pw_assert`` |
| 53 | ``pw_log`` |
| 54 | ``pw_preprocessor`` |
| 55 | ``pw_status`` |
| 56 | ``pw_tokenizer`` |
| 57 | ``pw_trace:facade`` |
| 58 | ``pw_varint`` |
| 59 | |
| 60 | --------- |
| 61 | Macro API |
| 62 | --------- |
Shiva Rajagopal | 9e51656 | 2021-05-11 17:04:15 -0700 | [diff] [blame] | 63 | All code should use the trace API facade directly. This backend fully |
Robert Oliver | 21dcf27 | 2020-05-12 15:41:52 -0400 | [diff] [blame] | 64 | implements all features of the tracing facade. |
| 65 | |
| 66 | |
| 67 | Event Callbacks & Data Sinks |
| 68 | ---------------------------- |
| 69 | The tokenized trace module adds both event callbacks and data sinks which |
| 70 | provide hooks into tracing. |
| 71 | |
| 72 | The *event callbacks* are called when trace events occur, with the trace event |
| 73 | data. Using the return flags, these callbacks can be used to adjust the trace |
| 74 | behaviour at runtime in response to specific events. If requested (using |
| 75 | ``called_on_every_event``) the callback will be called on every trace event |
| 76 | regardless if tracing is currently enabled or not. Using this, the application |
| 77 | can trigger tracing on or off when specific traces or patterns of traces are |
| 78 | observed, or can selectively filter traces to preserve the trace buffer. |
| 79 | |
| 80 | The event callback is a single function which is provided the details of the |
| 81 | trace as arguments, and returns ``pw_trace_TraceEventReturnFlags``, which can be |
| 82 | used to change how the trace is handled. |
| 83 | |
| 84 | .. cpp:function:: pw_trace_TraceEventReturnFlags pw_trace_EventCallback( \ |
| 85 | void* user_data, \ |
| 86 | uint32_t trace_ref, \ |
| 87 | pw_trace_EventType event_type, \ |
| 88 | const char* module, \ |
| 89 | uint32_t trace_id, \ |
| 90 | uint8_t flags) |
| 91 | .. cpp:function:: pw_Status pw_trace_RegisterEventCallback( \ |
| 92 | pw_trace_EventCallback callback, \ |
| 93 | bool called_on_every_event, \ |
| 94 | void* user_data, \ |
| 95 | pw_trace_EventCallbackHandle* handle) |
| 96 | .. cpp:function:: pw_Status pw_trace_UnregisterEventCallback( \ |
| 97 | pw_trace_EventCallbackHandle handle) |
| 98 | |
| 99 | |
| 100 | The *data sinks* are called only for trace events which get processed (tracing |
| 101 | is enabled, and the sample not skipped). The sink callback is called with the |
| 102 | encoded bytes of the trace event, which can be used by the application to |
| 103 | connect different data sinks. The callback is broken into three callbacks |
| 104 | ``pw_trace_SinkStartBlock``, ``pw_trace_SinkAddBytes``, and |
| 105 | ``pw_trace_SinkEndBlock``. ``Start`` is called with the size of the block, |
| 106 | before any bytes are emitted and can be used if needed to allocate space. |
| 107 | ``AddBytes`` is then called multiple times with chunks of bytes. Finally ``End`` |
| 108 | is called to allow any cleanup to be done by the sink if neccessary. Not all |
| 109 | callbacks are required, it is acceptible to provide nullptr for any callbacks |
| 110 | which you don't require. |
| 111 | |
| 112 | .. cpp:function:: void pw_trace_SinkStartBlock(void* user_data, size_t size) |
| 113 | .. cpp:function:: void pw_trace_SinkAddBytes( \ |
| 114 | void* user_data, \ |
| 115 | const void* bytes, \ |
| 116 | size_t size) |
| 117 | .. cpp:function:: void pw_trace_SinkEndBlock(void* user_data) |
| 118 | .. cpp:function:: pw_Status pw_trace_RegisterSink( \ |
| 119 | pw_trace_SinkStartBlock start, \ |
| 120 | pw_trace_SinkAddBytes add_bytes, \ |
| 121 | pw_trace_SinkEndBlock end_block, \ |
| 122 | void* user_data, \ |
| 123 | pw_trace_SinkHandle* handle) |
| 124 | .. cpp:function:: pw_Status pw_trace_UnregisterSink(pw_trace_SinkHandle handle) |
| 125 | |
| 126 | Trace Reference |
| 127 | --------------- |
| 128 | Some use-cases might involve referencing a specific trace event, for example |
| 129 | to use it as a trigger or filtering. Since the trace events are tokenized, a |
| 130 | macro is provided to generate the token to use as a reference. All the fields |
| 131 | must match exactly to generate the correct trace reference. If the trace does |
| 132 | not have a group, use ``PW_TRACE_GROUP_LABEL_DEFAULT``. |
| 133 | |
| 134 | .. cpp:function:: PW_TRACE_REF(event_type, module, label, flags, group) |
| 135 | .. cpp:function:: PW_TRACE_REF_DATA( \ |
| 136 | event_type, module, label, flags, group, type) |
| 137 | |
| 138 | |
| 139 | ----------- |
| 140 | Time source |
| 141 | ----------- |
Shiva Rajagopal | 9e51656 | 2021-05-11 17:04:15 -0700 | [diff] [blame] | 142 | Tracing requires the platform to provide the time source for tracing, this can |
Robert Oliver | 21dcf27 | 2020-05-12 15:41:52 -0400 | [diff] [blame] | 143 | be done in one of a few ways. |
| 144 | |
| 145 | 1. Create a file with the default time functions, and provide as build variable |
| 146 | ``pw_trace_tokenized_time``, which will get pulled in as a dependency. |
| 147 | 2. Provide time functions elsewhere in project, and ensure they are included. |
| 148 | 3. Redefine the trace time macros to something else, other then the default |
| 149 | trace time functions. |
| 150 | |
| 151 | .. cpp:function:: PW_TRACE_TIME_TYPE pw_trace_GetTraceTime() |
| 152 | .. cpp:function:: PW_TRACE_GET_TIME() |
| 153 | .. cpp:function:: size_t pw_trace_GetTraceTimeTicksPerSecond() |
| 154 | .. cpp:function:: PW_TRACE_GET_TIME_TICKS_PER_SECOND() |
Robert Oliver | 81e6e3e | 2020-06-25 14:43:40 -0400 | [diff] [blame] | 155 | |
| 156 | |
| 157 | ------ |
| 158 | Buffer |
| 159 | ------ |
| 160 | The optional trace buffer adds a ring buffer which contains the encoded trace |
| 161 | data. This is still a work in progress, in particular better methods for |
Shiva Rajagopal | 9e51656 | 2021-05-11 17:04:15 -0700 | [diff] [blame] | 162 | retrieving the data still need to be added. Currently there is an accessor for |
Robert Oliver | 81e6e3e | 2020-06-25 14:43:40 -0400 | [diff] [blame] | 163 | the underlying ring buffer object, but this is a short term solution. |
| 164 | |
| 165 | .. cpp:function:: void ClearBuffer() |
| 166 | .. cpp:function:: pw::ring_buffer::PrefixedEntryRingBuffer* GetBuffer() |
| 167 | |
| 168 | The buffer has two configurable options: |
| 169 | |
| 170 | 1. PW_TRACE_BUFFER_SIZE_BYTES: The total size of the ring buffer in bytes. |
| 171 | 2. PW_TRACE_BUFFER_MAX_BLOCK_SIZE_BYTES: The maximum single trace object size. |
| 172 | Including the token, time, and any attached data. Any trace object larger |
| 173 | then this will be dropped. |
| 174 | |
| 175 | Added dependencies |
| 176 | ------------------ |
| 177 | ``pw_ring_buffer`` |
| 178 | ``pw_varint`` |
Robert Oliver | 6d05de1 | 2020-07-13 15:10:42 -0400 | [diff] [blame] | 179 | |
| 180 | |
Prashanth Swaminathan | 0a9129c | 2020-09-14 16:27:24 -0700 | [diff] [blame] | 181 | ------- |
| 182 | Logging |
| 183 | ------- |
| 184 | The optional trace buffer logging adds support to dump trace buffers to the log. |
| 185 | Buffers are converted to base64-encoding then split across log lines. Trace logs |
| 186 | are surrounded by 'begin' and 'end' tags. |
| 187 | |
| 188 | Ex. Invoking PW_TRACE_INSTANT with 'test1' and 'test2', then calling this |
| 189 | function would produce this in the output logs: |
| 190 | |
| 191 | .. code:: sh |
| 192 | |
| 193 | [TRACE] begin |
| 194 | [TRACE] data: BWdDMRoABWj52YMB |
| 195 | [TRACE] end |
| 196 | |
| 197 | Added dependencies |
| 198 | ------------------ |
| 199 | ``pw_base64`` |
| 200 | ``pw_log`` |
| 201 | ``pw_ring_buffer`` |
| 202 | ``pw_string`` |
| 203 | ``pw_tokenizer`` |
| 204 | ``pw_varint`` |
| 205 | |
Robert Oliver | 6d05de1 | 2020-07-13 15:10:42 -0400 | [diff] [blame] | 206 | -------- |
| 207 | Examples |
| 208 | -------- |
| 209 | The examples all use `pw_trace` sample app to provide the trace data. Details |
| 210 | for how to build, run, and decode the traces are included at the top of each |
| 211 | example. This is early work, and is provided as an example of how different |
| 212 | tracing concepts can look. |
| 213 | |
| 214 | Basic |
| 215 | ----- |
| 216 | The basic example turns on tracing and dumps all trace output to a file provided |
| 217 | on the command line. |
Robert Oliver | 1914691 | 2020-07-14 10:49:48 -0400 | [diff] [blame] | 218 | |
| 219 | Trigger |
| 220 | ------- |
| 221 | The trigger example demonstrates how a trace event can be used as a trigger to |
| 222 | start and stop capturing a trace. The examples makes use of `PW_TRACE_REF` and |
| 223 | `PW_TRACE_REF_DATA` to specify a start and stop event for the capture. This can |
| 224 | be useful if the trace buffer is small and you wish to capture a specific |
| 225 | series of events. |
Robert Oliver | 0cc2075 | 2020-07-14 15:24:22 -0400 | [diff] [blame] | 226 | |
| 227 | Filter |
| 228 | ------ |
| 229 | The filter example demonstrates how a callback can be used to filter which trace |
| 230 | events get processed and saved. In this example all events from the processing |
| 231 | task which don't have traceId equal to 3 are removed. Both the other task traces |
| 232 | are not removed. This can be a useful feature while debugging as it limits the |
| 233 | amount of events which get stored to the buffer, and only saves the events of |
| 234 | interest. |