• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1# Trace
2
3
4## Basic Concepts
5
6Trace helps you learn about the kernel running process and the execution sequence of modules and tasks. With the information, you can better understand the code running process of the kernel and locate time sequence problems.
7
8
9## Working Principles
10
11The kernel provides a hook framework to embed hooks in the main process of each module. In the initial startup phase of the kernel, the trace function is initialized and the trace handlers are registered with the hooks.
12
13When a hook is triggered, the trace module encapsulates the input information and adds the trace frame header information, including the event type, ID of the running CPU, ID of the running task, and relative timestamp.
14
15The trace module provides two working modes: offline mode and online mode.
16
17In offline mode, trace frames are stored in a circular buffer. If too many frames are stored in the circular buffer, earlier frames will be overwritten to ensure that the information in the buffer is always the latest. Data in the circular buffer can be exported by running the shell command for further analysis. The exported information is sorted by timestamp.
18
19![](figures/kernel-small-mode-process-4.png)
20
21The online mode must be used with the integrated development environment (IDE). Trace frames are sent to the IDE in real time. The IDE parses the records and displays them in a visualized manner.
22
23
24## Available APIs
25
26
27### Kernel Mode
28
29The trace module of the OpenHarmony LiteOS-A kernel provides the following APIs. For more details, see [API reference](https://gitee.com/openharmony/kernel_liteos_a/blob/master/kernel/include/los_trace.h).
30
31**Table 1** APIs of the trace module
32
33| Category| Description|
34| -------- | -------- |
35| Starting/Stopping trace| **LOS_TraceStart**: starts trace.<br>**LOS_TraceStop**: stops trace.|
36| Managing trace records| **LOS_TraceRecordDump**: dumps data from the trace buffer.<br>**LOS_TraceRecordGet**: obtains the start address of the trace buffer.<br>**LOS_TraceReset**: clears events in the trace buffer.|
37| Filtering trace records| **LOS_TraceEventMaskSet**: sets the event mask to trace only events of the specified modules.|
38| Masking events of specified interrupt IDs| **LOS_TraceHwiFilterHookReg**: registers a hook to filter out events of specified interrupt IDs.|
39| Performing function instrumentation| **LOS_TRACE_EASY**: performs simple instrumentation.<br>**LOS_TRACE**: performs standard instrumentation.|
40
41- You can perform function instrumentation in the source code to trace specific events. The system provides the following APIs for instrumentation:
42  - **LOS_TRACE_EASY(TYPE, IDENTITY, params...)** for simple instrumentation
43     - You only need to insert this API into the source code.
44     - **TYPE** specifies the event type. The value range is 0 to 0xF. The meaning of each value is user-defined.
45     - **IDENTITY** specifies the object of the event operation. The value is of the **UIntPtr** type.
46     - **Params** specifies the event parameters. The value is of the **UIntPtr** type.
47        Example:
48
49        ```
50        Perform simple instrumentation for reading and writing files fd1 and fd2.
51        Set TYPE to 1 for read operations and 2 for write operations.
52        Insert the following to the position where the fd1 file is read:
53        LOS_TRACE_EASY(1, fd1, flag, size);
54        Insert the following to the position where the fd2 file is read:
55        LOS_TRACE_EASY(1, fd2, flag, size);
56        Insert the following to the position where the fd1 file is written:
57        LOS_TRACE_EASY(2, fd1, flag, size);
58        Insert the following in the position where the fd2 file is written:
59        LOS_TRACE_EASY(2, fd2, flag, size);
60        ```
61  - **LOS_TRACE(TYPE, IDENTITY, params...)** for standard instrumentation.
62     - Compared with simple instrumentation, standard instrumentation supports dynamic event filtering and parameter tailoring. However, you need to extend the functions based on rules.
63     - **TYPE** specifies the event type. You can define the event type in **enum LOS_TRACE_TYPE** in the header file **los_trace.h**. For details about methods and rules for defining events, see other event types.
64     - The **IDENTITY** and **Params** are the same as those of simple instrumentation.
65        Example:
66
67        ```
68        1. Set the event mask (module-level event type) in enum LOS_TRACE_MASK.
69          Format: TRACE_#MOD#_FLAG (MOD indicates the module name)
70          Example:
71          TRACE_FS_FLAG = 0x4000
72        2. Define the event type in **enum LOS_TRACE_TYPE**.
73          Format: #TYPE# = TRACE_#MOD#_FLAG | NUMBER
74          Example:
75          FS_READ  = TRACE_FS_FLAG | 0; // Read files.
76          FS_WRITE = TRACE_FS_FLAG | 1; // Write files.
77        3. Set event parameters in the #TYPE#_PARAMS(IDENTITY, parma1...) IDENTITY, ... format.
78          #TYPE# is the #TYPE# defined in step 2.
79          Example:
80          #define FS_READ_PARAMS(fp, fd, flag, size)    fp, fd, flag, size
81          The parameters defined by the macro correspond to the event parameters recorded in the trace buffer. You can modify the parameters as required.
82          If no parameter is specified, events of this type are not traced.
83          #define FS_READ_PARAMS(fp, fd, flag, size) // File reading events are not traced.
84        4. Insert a code stub in a proper position.
85          Format: LOS_TRACE(#TYPE#, #TYPE#_PARAMS(IDENTITY, parma1...))
86          LOS_TRACE(FS_READ, fp, fd, flag, size); // Code stub for reading files.
87          #The parameters following #TYPE# are the input parameter of the **FS_READ_PARAMS** function in step 3.
88        ```
89
90        > **NOTE**<br>
91        > The preset trace events and parameters can be tailored in the same way. For details about the parameters, see [kernel\include\los_trace.h](https://gitee.com/openharmony/kernel_liteos_a/blob/master/kernel/include/los_trace.h).
92
93- For **LOS_TraceEventMaskSet(UINT32 mask)**, only the most significant 28 bits (corresponding to the enable bit of the module in **LOS_TRACE_MASK**) of the mask take effect and are used only for module-based tracing. Currently, fine-grained event-based tracing is not supported. For example, in **LOS_TraceEventMaskSet(0x202)**, the effective mask is **0x200 (TRACE_QUE_FLAG)** and all events of the QUE module are collected. The recommended method is **LOS_TraceEventMaskSet(TRACE_EVENT_FLAG | TRACE_MUX_FLAG | TRACE_SEM_FLAG | TRACE_QUE_FLAG);**.
94
95- To enable trace of only simple instrumentation events, set **Trace Mask** to **TRACE_MAX_FLAG**.
96
97- The trace buffer has limited capacity. When the trace buffer is full, events will be overwritten. You can use **LOS_TraceRecordDump** to export data from the trace buffer and locate the latest records by **CurEvtIndex**.
98
99- The typical trace operation process includes **LOS_TraceStart**, **LOS_TraceStop**, and **LOS_TraceRecordDump**.
100
101- You can filter out interrupt events by interrupt ID to prevent other events from being overwritten due to frequent triggering of a specific interrupt in some scenarios. You can customize interrupt filtering rules.
102    Example:
103
104  ```c
105  BOOL Example_HwiNumFilter(UINT32 hwiNum)
106  {
107      if ((hwiNum == TIMER_INT) || (hwiNum == DMA_INT)) {
108          return TRUE;
109      }
110      return FALSE;
111  }
112  LOS_TraceHwiFilterHookReg(Example_HwiNumFilter);
113  ```
114
115The interrupt events with interrupt ID of **TIMER_INT** or **DMA_INT** are not traced.
116
117
118### User Mode
119
120The trace character device is added in **/dev/trace**. You can use **read()**, **write()**, and **ioctl()** on the device node to read, write, and control trace in user mode.
121
122- **read()**: reads the trace data in user mode.
123
124- **write()**: writes an event in user mode.
125
126- **ioctl()**: performs user-mode trace operations, including:
127
128
129```c
130#define TRACE_IOC_MAGIC   'T'
131#define TRACE_START      _IO(TRACE_IOC_MAGIC, 1)
132#define TRACE_STOP       _IO(TRACE_IOC_MAGIC, 2)
133#define TRACE_RESET      _IO(TRACE_IOC_MAGIC, 3)
134#define TRACE_DUMP		 _IO(TRACE_IOC_MAGIC, 4)
135#define TRACE_SET_MASK	 _IO(TRACE_IOC_MAGIC, 5)
136```
137
138The operations specified by the input parameter of **ioctl()** correspond to **LOS_TraceStart**, **LOS_TraceStop**, **LOS_TraceReset**, **LOS_TraceRecordDump**, and **LOS_TraceEventMaskSet**, respectively.
139
140For details, see [User-Mode Development Example](kernel-small-debug-trace.md#user-mode).
141
142
143## Development Guidelines
144
145
146### Kernel-Mode Development Process
147
148The typical trace process is as follows:
149
1501. Configure the macro related to the trace module.
151   Configure the macro **LOSCFG_KERNEL_TRACE**, which is disabled by default. Run the **make update_config** command in the **kernel/liteos_a** directory, choose **Kernel** > **Enable Hook Feature**, and set **Enable Trace Feature** to **YES**.
152
153   | Item| menuconfig Option| Description| Value|
154   | -------- | -------- | -------- | -------- |
155   | LOSCFG_KERNEL_TRACE | Enable Trace Feature | Specifies whether to enable the trace feature.| YES/NO |
156   | LOSCFG_RECORDER_MODE_OFFLINE | Trace work mode -> Offline mode | Specifies whether to enable the online trace mode.| YES/NO |
157   | LOSCFG_RECORDER_MODE_ONLINE | Trace work mode -> Online mode | Specifies whether to enable the offline trace mode.| YES/NO |
158   | LOSCFG_TRACE_CLIENT_INTERACT | Enable Trace Client Visualization and Control | Enables interaction with Trace IDE (dev tools), including data visualization and process control.| YES/NO |
159   | LOSCFG_TRACE_FRAME_CORE_MSG | Enable Record more extended content -> Record cpuid, hardware interrupt status, task lock status | Specifies whether to enable recording of the CPU ID, interruption state, and lock task state.| YES/NO |
160   | LOSCFG_TRACE_FRAME_EVENT_COUNT | Enable Record more extended content -> Record event count, which indicate the sequence of happend events | Specifies whether to enables recording of the event sequence number.| YES/NO |
161   | LOSCFG_TRACE_FRAME_MAX_PARAMS | Record max params | Specifies the maximum number of parameters for event recording.| INT |
162   | LOSCFG_TRACE_BUFFER_SIZE | Trace record buffer size | Specifies the trace buffer size.| INT |
163
1642. (Optional) Preset event parameters and stubs (or use the default event parameter settings and event stubs).
165
1663. (Optional) Call **LOS_TraceStop** to stop trace and call **LOS_TraceReset** to clear the trace buffer. (Trace is started by default.)
167
1684. (Optional) Call **LOS_TraceEventMaskSet** to set the mask of the events to be traced. The default event mask enables only trace of interrupts and task events. For details about the event masks, see **LOS_TRACE_MASK** in [los_trace.h](https://gitee.com/openharmony/kernel_liteos_a/blob/master/kernel/include/los_trace.h).
169
1705. Call **LOS_TraceStart** at the start of the code where the event needs to be traced.
171
1726. Call **LOS_TraceStop** at the end of the code where the event needs to be traced.
173
1747. Call **LOS_TraceRecordDump** to output the data in the buffer. (The input parameter of the function is of the Boolean type. The value **FALSE** means to output data in the specified format, and the value **TRUE** means to output data to Trace IDE.)
175
176The methods in steps 3 to 7 are encapsulated with shell commands. You can run these commands on shell. The mappings between the methods and commands are as follows:
177
178- LOS_TraceReset —— trace_reset
179
180- LOS_TraceEventMaskSet —— trace_mask
181
182- LOS_TraceStart —— trace_start
183
184- LOS_TraceStop —— trace_stop
185
186- LOS_TraceRecordDump —— trace_dump
187
188
189### Kernel-Mode Development Example
190
191This example implements the following:
192
1931. Create a trace task.
194
1952. Set the event mask.
196
1973. Start trace.
198
1994. Stop trace.
200
2015. Output trace data in the specified format.
202
203
204### Kernel-Mode Sample Code
205
206You can add the test function of the sample code to **TestTaskEntry** in **kernel/liteos_a/testsuites /kernel /src/osTest.c** for testing.
207
208The sample code is as follows:
209
210
211```c
212#include "los_trace.h"
213UINT32 g_traceTestTaskId;
214VOID Example_Trace(VOID)
215{
216    UINT32 ret;
217    LOS_TaskDelay(10);
218    /* Start trace. */
219    ret = LOS_TraceStart();
220    if (ret != LOS_OK) {
221        dprintf("trace start error\n");
222        return;
223    }
224    /* Trigger a task switching event. */
225    LOS_TaskDelay(1);
226    LOS_TaskDelay(1);
227    LOS_TaskDelay(1);
228    /* Stop trace. */
229    LOS_TraceStop();
230    LOS_TraceRecordDump(FALSE);
231}
232UINT32 Example_Trace_test(VOID)
233{
234    UINT32 ret;
235    TSK_INIT_PARAM_S traceTestTask;
236    /* Create a trace task. */
237    memset(&traceTestTask, 0, sizeof(TSK_INIT_PARAM_S));
238    traceTestTask.pfnTaskEntry = (TSK_ENTRY_FUNC)Example_Trace;
239    traceTestTask.pcName       = "TestTraceTsk";    /* Test task name. */
240    traceTestTask.uwStackSize  = 0x800; // 0x800: trace test task stack size
241    traceTestTask.usTaskPrio   = 5; // 5: trace test task priority
242    traceTestTask.uwResved   = LOS_TASK_STATUS_DETACHED;
243    ret = LOS_TaskCreate(&g_traceTestTaskId, &traceTestTask);
244    if (ret != LOS_OK) {
245        dprintf("TraceTestTask create failed .\n");
246        return LOS_NOK;
247    }
248    /* Trace is started by default. Therefore, you can stop trace, clear the buffer, and then start trace. */
249    LOS_TraceStop();
250    LOS_TraceReset();
251    /* Enable trace of the Task module events. */
252    LOS_TraceEventMaskSet(TRACE_TASK_FLAG);
253    return LOS_OK;
254}
255LOS_MODULE_INIT(Example_Trace_test, LOS_INIT_LEVEL_KMOD_EXTENDED);
256```
257
258
259### Verification
260
261The output is as follows:
262
263
264```
265***TraceInfo begin***
266clockFreq = 50000000
267CurEvtIndex = 7
268Index   Time(cycles)      EventType      CurTask   Identity      params
2690       0x366d5e88        0x45           0x1       0x0           0x1f         0x4       0x0
2701       0x366d74ae        0x45           0x0       0x1           0x0          0x8       0x1f
2712       0x36940da6        0x45           0x1       0xc           0x1f         0x4       0x9
2723       0x3694337c        0x45           0xc       0x1           0x9          0x8       0x1f
2734       0x36eea56e        0x45           0x1       0xc           0x1f         0x4       0x9
2745       0x36eec810        0x45           0xc       0x1           0x9          0x8       0x1f
2756       0x3706f804        0x45           0x1       0x0           0x1f         0x4       0x0
2767       0x37070e59        0x45           0x0       0x1           0x0          0x8       0x1f
277***TraceInfo end***
278```
279
280The output event information includes the occurrence time, event type, task in which the event occurs, object of the event operation, and other parameters of the event.
281
282- **EventType**: type of the event. For details, see **enum LOS_TRACE_TYPE** in [los_trace.h](https://gitee.com/openharmony/kernel_liteos_a/blob/master/kernel/include/los_trace.h).
283
284- **CurrentTask**: ID of the running task.
285
286- **Identity**: object of the event operation. For details, see **\#TYPE\#_PARAMS** in [los_trace.h](https://gitee.com/openharmony/kernel_liteos_a/blob/master/kernel/include/los_trace.h).
287
288- **params**: event parameters. For details, see **\#TYPE\#_PARAMS** in [los_trace.h](https://gitee.com/openharmony/kernel_liteos_a/blob/master/kernel/include/los_trace.h).
289
290The following uses output No. 0 as an example.
291
292
293```
294Index   Time(cycles)      EventType      CurTask   Identity      params
2950       0x366d5e88        0x45           0x1       0x0           0x1f         0x4
296```
297
298- **Time (cycles)** can be converted into time (in seconds) by dividing the cycles by clockFreq.
299
300- **0x45** indicates the task switching event. **0x1** is the ID of the task in running.
301
302- For details about the meanings of **Identity** and **params**, see the **TASK_SWITCH_PARAMS** macro.
303
304```c
305#define TASK_SWITCH_PARAMS(taskId, oldPriority, oldTaskStatus, newPriority, newTaskStatus) \
306taskId, oldPriority, oldTaskStatus, newPriority, newTaskStatus
307```
308
309Because of **#TYPE#_PARAMS(IDENTITY, parma1...) IDENTITY, ...**, **Identity** is **taskId (0x0)** and the first parameter is **oldPriority (0x1f)**.
310
311> **NOTE**
312>
313> The number of parameters in **params** is specified by **LOSCFG_TRACE_FRAME_MAX_PARAMS**. The default value is **3**. Excess parameters are not recorded. You need to set **LOSCFG_TRACE_FRAME_MAX_PARAMS** based on service requirements.
314
315Task 0x1 is switched to Task 0x0. The priority of task 0x1 is **0x1f**, and the state is **0x4**. The priority of the task 0x0 is **0x0**.
316