• 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 traced 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.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
26The trace module of the OpenHarmony LiteOS-M kernel provides the following APIs. For more details about the APIs, see the API reference.
27
28  **Table 1** APIs of the trace module
29
30| Category| API|
31| -------- | -------- |
32| Starting/Stopping trace| - **LOS_TraceStart**: starts a trace.<br>- **LOS_TraceStop**: stops the trace.|
33| 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.|
34| Filtering trace records| **LOS_TraceEventMaskSet**: sets the event mask to trace only events of the specified modules.|
35| Masking events of specified interrupt IDs| **LOS_TraceHwiFilterHookReg**: registers a hook to filter out events of specified interrupt IDs.|
36| Performing function instrumentation| - **LOS_TRACE_EASY**: performs simple instrumentation.<br>- **LOS_TRACE**: performs standard instrumentation.|
37
38- You can perform function instrumentation in the source code to trace specific events. The system provides the following APIs for instrumentation:
39  - **LOS_TRACE_EASY(TYPE, IDENTITY, params...)** for simple instrumentation
40     - You only need to insert this API into the source code.
41     - **TYPE** specifies the event type. The value range is 0 to 0xF. The meaning of each value is user-defined.
42     - **IDENTITY** specifies the object of the event operation. The value is of the **UIntPtr** type.
43     - **Params** specifies the event parameters. The value is of the **UIntPtr** type.
44     - Example of simple instrumentation for reading and writing data based on the file FDs:
45
46        ```
47        /* Set TYPE to 1 for read operation and 2 for write operations. */
48        LOS_TRACE_EASY(1, fd, flag, size); /* Add it to a proper position. */
49        LOS_TRACE_EASY(2, fd, flag, size);  /* Add it to a proper position. */
50        ```
51  - **LOS_TRACE(TYPE, IDENTITY, params...)** for standard instrumentation.
52     - Compared with simple instrumentation, standard instrumentation supports dynamic event filtering and parameter tailoring. However, you need to extend the functions based on rules.
53     - **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.
54     - The **IDENTITY** and **Params** are the same as those of simple instrumentation.
55     - Example:
56          1. Define the type of the FS module (event mask of the FS module) in **enum LOS_TRACE_MASK**.
57
58        ```
59        /* Define the event mask in the format of TRACE_#MOD#_FLAG, where #MOD# indicates the module name. */
60        TRACE_FS_FLAG = 0x4000
61        ```
62
63        2. Define the event types of the FS module.
64
65
66        ```
67        /* Define the event type in the format: #TYPE# = TRACE_#MOD#_FLAG | NUMBER */
68        FS_READ  = TRACE_FS_FLAG | 0; /* Read data. */
69        FS_WRITE = TRACE_FS_FLAG | 1; /* Write data. */
70        ```
71
72        3. Define event parameters.
73
74
75        ```
76        /* Define the parameters in the format: #TYPE#_PARAMS(IDENTITY, parma1...) IDENTITY, ... */
77        #define FS_READ_PARAMS(fp, fd, flag, size)  fp, fd, flag, size /* The parameters defined by the macro correspond to the event parameters recorded in the trace buffer. You can tailor the parameters as required. */
78        #define FS_READ_PARAMS(fp, fd, flag, size)                     /* If no parameters are defined, events of this type are not traced. */
79        ```
80
81        4. Add the code stubs in the code.
82
83
84        ```
85        /* Format: LOS_TRACE(#TYPE#, #TYPE#_PARAMS(IDENTITY, parma1...)) */
86        LOS_TRACE(FS_READ, fp, fd, flag, size); /* Code stub for reading data. */
87        ```
88
89        > **NOTE**<br>
90        > You can modify the traced event types and parameters as required. For details about the parameters, see **kernel\include\los_trace.h**.
91
92- 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);**.
93
94- To enable trace of only simple instrumentation events, set **Trace Mask** to **TRACE_MAX_FLAG**.
95
96- 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**.
97
98- The typical trace operation process includes **LOS_TraceStart**, **LOS_TraceStop**, and **LOS_TraceRecordDump**.
99
100- 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.<br>
101    The sample code is as follows:
102
103  ```
104  BOOL Example_HwiNumFilter(UINT32 hwiNum)
105  {
106         if ((hwiNum == TIMER_INT) || (hwiNum == DMA_INT)) {
107          return TRUE;
108      }
109      return FALSE;
110  }
111  LOS_TraceHwiFilterHookReg(Example_HwiNumFilter);
112  ```
113
114  The interrupt events with interrupt ID of **TIMER_INT** or **DMA_INT** are not traced.
115
116
117## Development Guidelines
118
119
120### How to Develop
121
122The typical development process is as follows:
123
1241. Configure the macros related to the trace module in the **target_config.h** file.
125     | Configuration Item| Description| Value|
126   | -------- | -------- | -------- |
127   | LOSCFG_KERNEL_TRACE | Whether to enable the trace feature. | YES/NO |
128   | LOSCFG_RECORDER_MODE_OFFLINE | Whether to enable the online trace mode. | YES/NO |
129   | LOSCFG_RECORDER_MODE_ONLINE | Whether to enable the offline trace mode. | YES/NO |
130   | LOSCFG_TRACE_CLIENT_INTERACT | Whether to enable interaction with Trace IDE (dev tools), including data visualization and process control. | YES/NO |
131   | LOSCFG_TRACE_FRAME_CORE_MSG | Whether to enable trace of the CPU ID, interruption state, and lock task state. | YES/NO |
132   | LOSCFG_TRACE_FRAME_EVENT_COUNT | Whether to enable trace of the event sequence number. | YES/NO |
133   | LOSCFG_TRACE_FRAME_MAX_PARAMS | Specifies the maximum number of parameters for event tracing. | INT |
134   | LOSCFG_TRACE_BUFFER_SIZE | Specifies the trace buffer size.| INT |
135
1362. (Optional) Preset event parameters and stubs (or use the default event parameter settings and event stubs).
137
1383. (Optional) Call **LOS_TraceStop** to stop trace and **LOS_TraceReset** to clear the trace buffer. (Trace is started by default.)
139
1404. (Optional) Call **LOS_TraceEventMaskSet** to set the event mask for trace (only the interrupts and task events are enabled by default). For details about the event mask, see **LOS_TRACE_MASK** in **los_trace.h**.
141
1425. Call **LOS_TraceStart** at the start of the code where the event needs to be traced.
143
1446. Call **LOS_TraceStop** at the end of the code where the event needs to be traced.
145
1467. 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 a Windows client.)
147
148The methods in steps 3 to 7 are encapsulated with shell commands. After the shell is enabled, the corresponding commands can be executed. The mapping is as follows:
149
150- LOS_TraceReset —— trace_reset
151
152- LOS_TraceEventMaskSet —— trace_mask
153
154- LOS_TraceStart —— trace_start
155
156- LOS_TraceStop —— trace_stop
157
158- LOS_TraceRecordDump —— trace_dump
159
160
161### Development Example
162
163This example implements the following:
164
1651. Create a trace task.
166
1672. Set the event mask.
168
1693. Start trace.
170
1714. Stop trace.
172
1735. Output trace data in the specified format.
174
175
176### Sample Code
177
178The sample code is as follows:
179
180The sample code can be compiled and verified in **./kernel/liteos_m/testsuites/src/osTest.c**. The **ExampleTraceTest** function is called in **TestTaskEntry**.
181
182
183```
184#include "los_trace.h"
185UINT32 g_traceTestTaskId;
186VOID Example_Trace(VOID)
187{
188    UINT32 ret;
189    LOS_TaskDelay(10);
190    /* Start trace. */
191    ret = LOS_TraceStart();
192    if (ret != LOS_OK) {
193        dprintf("trace start error\n");
194        return;
195    }
196    /* Trigger a task switching event. */
197    LOS_TaskDelay(1);
198    LOS_TaskDelay(1);
199    LOS_TaskDelay(1);
200    /* Stop trace. */
201    LOS_TraceStop();
202    LOS_TraceRecordDump(FALSE);
203}
204UINT32 ExampleTraceTest(VOID){
205    UINT32 ret;
206    TSK_INIT_PARAM_S traceTestTask = { 0 };
207    /* Create a trace task. */
208    memset(&traceTestTask, 0, sizeof(TSK_INIT_PARAM_S));
209    traceTestTask.pfnTaskEntry = (TSK_ENTRY_FUNC)Example_Trace;
210    traceTestTask.pcName       = "TestTraceTsk";    /* Trace task name. */
211    traceTestTask.uwStackSize  = 0x800;
212    traceTestTask.usTaskPrio   = 5;
213    traceTestTask.uwResved   = LOS_TASK_STATUS_DETACHED;
214    ret = LOS_TaskCreate(&g_traceTestTaskId, &traceTestTask);
215    if(ret != LOS_OK){
216        dprintf("TraceTestTask create failed .\n");
217        return LOS_NOK;
218    }
219    /* Trace is started by default. You can stop trace, clear the buffer, and restart trace. */
220    LOS_TraceStop();
221    LOS_TraceReset();
222    /* Enable trace of the Task module events. */
223    LOS_TraceEventMaskSet(TRACE_TASK_FLAG);
224    return LOS_OK;
225}
226```
227
228
229### Verification
230
231The output is as follows:
232
233
234```
235***TraceInfo begin***
236clockFreq = 50000000
237CurEvtIndex = 7
238Index   Time(cycles)      EventType      CurTask   Identity      params
2390       0x366d5e88        0x45           0x1       0x0           0x1f         0x4       0x0
2401       0x366d74ae        0x45           0x0       0x1           0x0          0x8       0x1f
2412       0x36940da6        0x45           0x1       0xc           0x1f         0x4       0x9
2423       0x3694337c        0x45           0xc       0x1           0x9          0x8       0x1f
2434       0x36eea56e        0x45           0x1       0xc           0x1f         0x4       0x9
2445       0x36eec810        0x45           0xc       0x1           0x9          0x8       0x1f
2456       0x3706f804        0x45           0x1       0x0           0x1f         0x4       0x0
2467       0x37070e59        0x45           0x0       0x1           0x0          0x8       0x1f
247***TraceInfo end***
248
249The preceding data may vary depending on the running environment.
250```
251
252The 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.
253
254- **EventType**: event type. For details, see **enum LOS_TRACE_TYPE** in the header file **los_trace.h**.
255
256- **CurrentTask**: ID of the running task.
257
258- **Identity**: object of the event operation. For details, see **#TYPE#_PARAMS** in the header file **los_trace.h**.
259
260- **params**: event parameters. For details, see **#TYPE#_PARAMS** in the header file **los_trace.h**.
261
262The following uses output No. 0 as an example.
263
264
265```
266Index   Time(cycles)      EventType      CurTask   Identity      params
2670       0x366d5e88        0x45           0x1       0x0           0x1f         0x4
268```
269
270- **Time (cycles)** can be converted into time (in seconds) by dividing the cycles by clockFreq.
271
272- **0x45** indicates the task switching event. **0x1** is the ID of the task in running.
273
274- For details about the meanings of **Identity** and **params**, see the **TASK_SWITCH_PARAMS** macro.
275
276
277```
278#define TASK_SWITCH_PARAMS(taskId, oldPriority, oldTaskStatus, newPriority, newTaskStatus) \
279taskId, oldPriority, oldTaskStatus, newPriority, newTaskStatus
280```
281
282  **Identity** is **taskId (0x0)**, and the first parameter is **oldPriority (0x1f)**.
283> **NOTE**<br>
284> The number of parameters in **params** is specified by **LOSCFG_TRACE_FRAME_MAX_PARAMS**. The default value is **3**. Excess parameters are not recorded. Set **LOSCFG_TRACE_FRAME_MAX_PARAMS** based on service requirements.
285
286Task 0x1 is switched to Task 0x0. The priority of task 0x1 is **0x1f**, and the state is **0x4**. The priority of task 0x0 is **0x0**.
287