1# Using HiTraceChain (ArkTS) 2 3<!--Kit: Performance Analysis Kit--> 4<!--Subsystem: HiviewDFX--> 5<!--Owner: @qq_437963121--> 6<!--Designer: @MontSaintMichel--> 7<!--Tester: @gcw_KuLfPSbe--> 8<!--Adviser: @foryourself--> 9 10## Available APIs 11 12The APIs for distributed call chain tracing are provided by the HiTraceChain module. For details, see [@ohos.hiTraceChain (Distributed Tracing)](../reference/apis-performance-analysis-kit/js-apis-hitracechain.md). 13 14| API| Description| 15| -------- | -------- | 16| hiTraceChain.begin(name: string, flags?: number = HiTraceFlag.DEFAULT): HiTraceId | Starts call chain tracing and returns the created **HiTraceId**.| 17| hiTraceChain.end(id: HiTraceId): void | Stops call chain tracing.| 18| hiTraceChain.getId(): HiTraceId | Obtains the trace ID.| 19| hiTraceChain.setId(id: HiTraceId): void | Sets the trace ID.| 20| hiTraceChain.clearId(): void | Clears the trace ID.| 21| hiTraceChain.createSpan(): HiTraceId | Creates a trace span. Specifically, create a **HiTraceId**, use the **chainId** and **spanId** in the Thread-Local Storage (TLS) of the current thread to initialize the **chainId** and **parentSpanId** of the **HiTraceId**, generate a new **spanId** for the **HiTraceId**, and return the **HiTraceId**.| 22| hiTraceChain.isValid(id: HiTraceId): boolean | Checks whether the **HiTraceId** is valid.<br>The value **true** indicates that **HiTraceId** is valid, and **false** indicates the opposite.| 23| hiTraceChain.isFlagEnabled(id: HiTraceId, flag: HiTraceFlag): boolean | Checks whether the trace flag specified by **HiTraceId** is enabled.<br>The value **true** indicates that the specified trace flag is enabled, and **false** indicates the opposite.| 24| hiTraceChain.enableFlag(id: HiTraceId, flag: HiTraceFlag): void | Enables the trace flag specified in **HiTraceId**.| 25| hiTraceChain.tracepoint(mode: HiTraceCommunicationMode, type: HiTraceTracepointType, id: HiTraceId, msg?: string): void | Adds a trace point for the HiTraceMeter logging.| 26 27 28## How to Develop 29 30For details about how to use HiTraceChain in ArkTS, see the following example. You can refer to [Constraints](hitracechain-intro.md#constraints) to understand the common mechanisms that support and do not support HiTraceChain automatic transfer. 31 32 33### Using HiTraceChain in async/await and promise/then Asynchronous Tasks 34 35The **async**/**await** and **promise**/**then** asynchronous tasks support automatic transfer of HiTraceChain. The following example describes how to use distributed tracing in ArkTS based on [Event Subscription (ArkTS)](hiappevent-watcher-app-events-arkts.md) and [Using HiTraceMeter (ArkTS)](hitracemeter-guidelines-arkts.md). 36 371. Create a project in DevEco Studio, select **Empty Ability**, and set the SDK version to 19 or later. (The HiTraceMeter APIs used in the sample project are supported since API version 19.) The project directory structure is as follows: 38 ```txt 39 ├── entry 40 │ ├── src 41 │ ├── main 42 │ │ ├── ets 43 │ │ │ ├── entryability 44 │ │ │ │ └── EntryAbility.ets 45 │ │ │ ├── entrybackupability 46 │ │ │ │ └── EntryBackupAbility.ets 47 │ │ │ └── pages 48 │ │ │ └── Index.ets 49 ``` 50 512. In the **entry/src/main/ets/pages/index.ets** file, use HiTraceChain to trace asynchronous tasks. The complete code is as follows: 52 53 ```ts 54 import { BusinessError } from '@kit.BasicServicesKit'; 55 import { hiAppEvent, hilog, hiTraceChain, hiTraceMeter } from '@kit.PerformanceAnalysisKit'; 56 57 async function test3() { 58 hilog.info(0x0000, "testTag", "test3"); 59 } 60 61 async function test2() { 62 hilog.info(0x0000, "testTag", "test2"); 63 } 64 65 async function test1() { 66 hilog.info(0x0000, 'testTag', "test1_1"); 67 await test2(); 68 hilog.info(0x0000, 'testTag', "test1_2"); 69 await test3(); 70 hilog.info(0x0000, 'testTag', "test1_3"); 71 } 72 73 @Entry 74 @Component 75 struct Index { 76 @State message: string = "clickTime=0"; 77 @State clickTime: number = 0; 78 79 build() { 80 Row() { 81 Column() { 82 Button(this.message) 83 .fontSize(20) 84 .margin(5) 85 .width(350) 86 .height(60) 87 .fontWeight(FontWeight.Bold) 88 .onClick(() => { 89 this.clickTime++; 90 this.message = "clickTime=" + this.clickTime; 91 // Start distributed call chain tracing before the service starts. 92 // INCLUDE_ASYNC indicates that HiTraceId is automatically transferred in the asynchronous mechanism supported by the system. 93 let traceId = hiTraceChain.begin("testTag: hiTraceChain begin", hiTraceChain.HiTraceFlag.INCLUDE_ASYNC); 94 // Start HiTraceMeter synchronous logging. This API is supported since API version 19. 95 hiTraceMeter.startSyncTrace(hiTraceMeter.HiTraceOutputLevel.COMMERCIAL, "onClick", this.message); 96 97 // Log a button onclick event when the button is clicked. 98 let eventParams: Record<string, number> = { 'click_time': 100 }; 99 let eventInfo: hiAppEvent.AppEventInfo = { 100 // Define the event domain. 101 domain: "button", 102 // Define the event name. 103 name: "click", 104 // Define the event type. 105 eventType: hiAppEvent.EventType.BEHAVIOR, 106 // Define the event parameters. 107 params: eventParams 108 }; 109 hiAppEvent.write(eventInfo).then(() => { 110 hilog.info(0x0000, "testTag", "Succeeded in writing an app event"); 111 // After the button click event is processed, disable the distributed tracing of the asynchronous processing span. 112 hiTraceChain.end(traceId); 113 hilog.info(0x0000, "testTag", "hiTraceChain end in hiAppEvent"); 114 }).catch((err: BusinessError) => { 115 hilog.error(0x0000, "testTag", `HiAppEvent err.code: ${err.code}, err.message: ${err.message}`); 116 // After the exception handling is complete, disable the distributed tracing of the asynchronous processing span. 117 hiTraceChain.end(traceId); 118 hilog.info(0x0000, "testTag", "hiTraceChain end in hiAppEvent"); 119 }); 120 121 // Create a Promise object to execute the random number generation task. If the random number is greater than 0.5, the result is returned. Otherwise, an exception is returned. 122 const promise: Promise<number> = new Promise((resolve: Function, reject: Function) => { 123 hilog.info(0x0000, "testTag", "promise task"); 124 const randomNumber: number = Math.random(); 125 if (randomNumber > 0.5) { 126 resolve(randomNumber); 127 } else { 128 reject(new Error('Random number is too small')); 129 } 130 }); 131 132 // Use the callback of the then method to process the execution result of the Promise object. 133 promise.then((result: number) => { 134 // Executed when the operation is successful. 135 hilog.info(0x0000, "testTag", "Random number is %{public}d", result); 136 // After the callback processing is complete, disable the distributed tracing of the asynchronous processing span. 137 hiTraceChain.end(traceId); 138 hilog.info(0x0000, "testTag", "hiTraceChain end in promise/then"); 139 }).catch((error: BusinessError) => { 140 // Executed when the operation fails. 141 hilog.error(0x0000, "testTag", error.message); 142 // After the exception handling is complete, disable the distributed tracing of the asynchronous processing span. 143 hiTraceChain.end(traceId); 144 hilog.info(0x0000, "testTag", "hiTraceChain end in promise/then"); 145 }); 146 147 // Execute an async/await task. 148 let res = test1(); 149 // Use the callback of the then method to process the execution result of the async task. 150 res.then(() => { 151 hilog.info(0x0000, "testTag", "then task"); 152 // Disable distributed tracing of the asynchronous processing span. This functionality is the same as that of hiTraceChain.end. 153 hiTraceChain.clearId(); 154 hilog.info(0x0000, "testTag", "hiTraceChain end in async/await"); 155 }); 156 157 // End HiTraceMeter synchronous logging. This API is supported since API version 19. 158 hiTraceMeter.finishSyncTrace(hiTraceMeter.HiTraceOutputLevel.COMMERCIAL); 159 // Stop distributed call chain tracing when the service ends. 160 hiTraceChain.end(traceId); 161 hilog.info(0x0000, "testTag", "hiTraceChain end in main thread"); 162 }) 163 } 164 .width('100%') 165 } 166 .height('100%') 167 } 168 } 169 ``` 170 1713. Click the **Run** button in DevEco Studio to run the project. In the **Terminal** window, run the following command to capture the application traces generated within 10 seconds and use the keyword **onClick** to filter the trace logs generated by **hiTraceMeter.startSyncTrace** and **hiTraceMeter.finishSyncTrace** in the sample code. 172 173 ```shell 174 PS D:\xxx\xxx> hdc shell 175 $ hitrace -t 10 app | grep onClick 176 ``` 177 1784. Click the **clickTime=0** button on the device to trigger the service logic. (The operation must be completed within 10 seconds. Otherwise, the trace data cannot be captured in step 3.) 179 1805. View the execution result. 181 - If **clickTime=1** is displayed on the device screen, the button is clicked once and the service logic is triggered. 182 - In the **Log** window of DevEco Studio, view the distributed tracing information. 183 - All HiLog logs in this example use **testTag**. You can filter logs by the keyword **testTag** to view the HiLog logs printed by the service code. 184 185 ```txt 186 06-04 17:46:45.156 55451-55451 C02D33/com.exa...tion/HiTraceC com.examp...lication I [a92ab116052648e 0 0]HiTraceBegin name:testTag: hiTraceChain begin flags:0x01. 187 06-04 17:46:45.157 55451-55451 A00000/com.exa...ation/testTag com.examp...lication I [a92ab116052648e 0 0]promise task 188 06-04 17:46:45.158 55451-55451 A00000/com.exa...ation/testTag com.examp...lication I [a92ab116052648e 0 0]test1_1 189 06-04 17:46:45.158 55451-55451 A00000/com.exa...ation/testTag com.examp...lication I [a92ab116052648e 0 0]test2 190 06-04 17:46:45.158 55451-55451 A00000/com.exa...ation/testTag com.examp...lication I hiTraceChain end in main thread 191 06-04 17:46:45.158 55451-55451 A00000/com.exa...ation/testTag com.examp...lication I [a92ab116052648e 3457eff 0]test1_2 192 06-04 17:46:45.158 55451-55451 A00000/com.exa...ation/testTag com.examp...lication I [a92ab116052648e 3457eff 0]test3 193 06-04 17:46:45.158 55451-55451 A00000/com.exa...ation/testTag com.examp...lication E [a92ab116052648e 1bb5a1b 35d9c46]Random number is too small 194 06-04 17:46:45.158 55451-55451 A00000/com.exa...ation/testTag com.examp...lication I hiTraceChain end in promise/then 195 06-04 17:46:45.158 55451-55451 A00000/com.exa...ation/testTag com.examp...lication I [a92ab116052648e 2ddfb70 3457eff]test1_3 196 06-04 17:46:45.158 55451-55451 A00000/com.exa...ation/testTag com.examp...lication I [a92ab116052648e 225a1d9 2ddfb70]then task 197 06-04 17:46:45.158 55451-55451 A00000/com.exa...ation/testTag com.examp...lication I hiTraceChain end in async/await 198 06-04 17:46:45.163 55451-55451 A00000/com.exa...ation/testTag com.examp...lication I [a92ab116052648e 3a75cb2 520a92]Succeeded in writing an app event 199 06-04 17:46:45.163 55451-55451 A00000/com.exa...ation/testTag com.examp...lication I hiTraceChain end in hiAppEvent 200 ``` 201 202 - The **[chainId spanId parentSpanId]** information added before the HiLog log is **HiTraceId** information. For example, **[a92ab116052648e 2ddfb70 3457eff]** indicates that the trace chain ID (**chainId**) is **a92ab116052648e**, the span ID (**spanId**) is **2ddfb70**, and the parent span ID (**parentSpanId**) is **3457eff**. 203 - The **chainId** in the example is **a92ab116052648e**. You can use it to filter logs and view the complete HiLog logs of the service call chain. 204 - The **promise**/**then** and **async**/**await** mechanisms automatically transfer **HiTraceId** and generate span IDs. For example, **3457eff**, **2ddfb70**, and **225a1d9** in the HiLog logs in the example are span IDs automatically generated by asynchronous tasks. 205 - Both **hiTraceChain.end** and **hiTraceChain.clear** can end tracing. After tracing is ended, HiLog logs no longer carry **HiTraceId** information. 206 207 - View the trace data in the **Terminal** window of DevEco Studio. During HiTraceChain tracing, the trace logs obtained from HiTraceMeter automatically carry **HiTraceId** information. 208 209 ```txt 210 e.myapplication-55451 ( 55451) [010] .... 27164.174417: tracing_mark_write: B|55451|H:[a92ab116052648e,0,0]#onClick|M62|clickTime=1 211 ``` 212 213 214### Using HiTraceChain in setInterval and setTimeout of Asynchronous Macro Tasks 215 216**setInterval** and **setTimeout** of asynchronous macro tasks do not support HiTraceChain automatic transfer. The following example shows how to use the **hiTraceChain.getId** and **hiTraceChain.setId** APIs to transfer **HiTraceId** and how to use the **hiTraceChain.createSpan** API to create a branch ID for distributed tracing. 217 2181. Create a project in DevEco Studio and select **Empty Ability**. The project directory structure is as follows: 219 220 ```txt 221 ├── entry 222 │ ├── src 223 │ ├── main 224 │ │ ├── ets 225 │ │ │ ├── entryability 226 │ │ │ │ └── EntryAbility.ets 227 │ │ │ ├── entrybackupability 228 │ │ │ │ └── EntryBackupAbility.ets 229 │ │ │ └── pages 230 │ │ │ └── Index.ets 231 ``` 232 2332. In the **entry/src/main/ets/pages/index.ets** file of the project, use HiTraceChain to trace asynchronous tasks. The complete code is as follows: 234 235 ```ts 236 import { BusinessError } from '@kit.BasicServicesKit'; 237 import { hilog, hiTraceChain } from '@kit.PerformanceAnalysisKit'; 238 239 @Entry 240 @Component 241 struct Index { 242 @State message: string = "clickTime=0"; 243 @State clickTime: number = 0; 244 245 build() { 246 Row() { 247 Column() { 248 Button(this.message) 249 .fontSize(20) 250 .margin(5) 251 .width(350) 252 .height(60) 253 .fontWeight(FontWeight.Bold) 254 .onClick(() => { 255 this.clickTime++; 256 this.message = "clickTime=" + this.clickTime; 257 // Obtain the HiTraceId of the current thread. 258 let traceId = hiTraceChain.getId(); 259 // If the traceId is invalid, enable distributed tracing for the current thread. 260 if (!hiTraceChain.isValid(traceId)) { 261 hilog.info(0x0000, "testTag", "HiTraceId is invalid, begin hiTraceChain"); 262 traceId = hiTraceChain.begin("testTag: hiTraceChain begin"); 263 // Enable INCLUDE_ASYNC for traceId. INCLUDE_ASYNC indicates that HiTraceId is automatically transferred in the asynchronous mechanism supported by the system. 264 hiTraceChain.enableFlag(traceId, hiTraceChain.HiTraceFlag.INCLUDE_ASYNC); 265 // Set the HiTraceId with INCLUDE_ASYNC enabled to the current thread. 266 hiTraceChain.setId(traceId); 267 // Check whether INCLUDE_ASYNC is successfully enabled. 268 if (hiTraceChain.isFlagEnabled(hiTraceChain.getId(), hiTraceChain.HiTraceFlag.INCLUDE_ASYNC)) { 269 hilog.info(0x0000, "testTag", "HiTraceFlag INCLUDE_ASYNC is enabled"); 270 } 271 } 272 273 const promise: Promise<number> = new Promise((resolve: Function, reject: Function) => { 274 // Create an asynchronous recurring scheduled task that runs every 1s. 275 let intervalID = setInterval(() => { 276 // Set HiTraceId for the current asynchronous recurring scheduled task. 277 hiTraceChain.setId(traceId); 278 const randomNumber: number = Math.random(); 279 hilog.info(0x0000, "testTag", "Interval 1s: randomNumber is %{public}d", randomNumber); 280 // Disable distributed tracing for the current asynchronous recurring scheduled task. 281 hiTraceChain.end(traceId); 282 }, 1000) 283 284 // Create an asynchronous scheduled task to be executed 2.5s later and end the asynchronous recurring scheduled task. 285 setTimeout(() => { 286 // Set HiTraceId for the asynchronous scheduled task. 287 hiTraceChain.setId(traceId); 288 // Generate a spanId for the asynchronous scheduled task. 289 let traceIdTimeout = hiTraceChain.createSpan(); 290 // Set HiTraceId with spanId for the asynchronous scheduled task. 291 hiTraceChain.setId(traceIdTimeout); 292 hilog.info(0x0000, 'testTag', "setTimeout 2.5s"); 293 // End the asynchronous recurring scheduled task. 294 clearInterval(intervalID); 295 const randomNumber: number = Math.random(); 296 if (randomNumber > 0.5) { 297 resolve(randomNumber); 298 } else { 299 reject(new Error('Random number is too small')); 300 } 301 // Disable distributed tracing for the asynchronous scheduled task. 302 hiTraceChain.end(traceId); 303 }, 2500) 304 }) 305 306 promise.then((result: number) => { 307 // Executed when the operation is successful. 308 hilog.info(0x0000, 'testTag', "Random number is %{public}d", result); 309 // After the callback processing is complete, disable the distributed tracing of the asynchronous processing span. 310 hiTraceChain.end(traceId); 311 }).catch((error: BusinessError) => { 312 // Executed when the operation fails. 313 hilog.error(0x0000, 'testTag', error.message); 314 // After the exception handling is complete, disable the distributed tracing of the asynchronous processing span. 315 hiTraceChain.end(traceId); 316 }); 317 318 // Stop distributed call chain tracing when the service ends. 319 hiTraceChain.end(traceId); 320 hilog.info(0x0000, "testTag", "hiTraceChain end in main thread"); 321 }) 322 } 323 .width('100%') 324 } 325 .height('100%') 326 } 327 } 328 ``` 329 3303. Click the **Run** button on DevEco Studio to run the application project. Click the **clickTime=0** button on the device to trigger the service logic. 331 3324. View the execution result. 333 - If **clickTime=1** is displayed on the device screen, the button is clicked once and the service logic is triggered. 334 - In the **Log** window of DevEco Studio, view the distributed tracing information. 335 - All HiLog logs in this example use **testTag**. You can filter logs by the keyword **testTag** to view the HiLog logs printed by the service code. 336 337 ```txt 338 06-05 15:46:04.544 49568-49568 A00000/com.exa...ation/testTag com.examp...lication I HiTraceId is invalid, begin hiTraceChain 339 06-05 15:46:04.544 49568-49568 C02D33/com.exa...tion/HiTraceC com.examp...lication I [a92ab34b3c84ea7 0 0]HiTraceBegin name:testTag: hiTraceChain begin flags:0x00. 340 06-05 15:46:04.544 49568-49568 A00000/com.exa...ation/testTag com.examp...lication I [a92ab34b3c84ea7 0 0]HiTraceFlag INCLUDE_ASYNC is enabled 341 06-05 15:46:04.544 49568-49568 A00000/com.exa...ation/testTag com.examp...lication I hiTraceChain end in main thread 342 06-05 15:46:05.547 49568-49568 A00000/com.exa...ation/testTag com.examp...lication I [a92ab34b3c84ea7 0 0]Interval 1s: randomNumber is 0.863610 343 06-05 15:46:06.548 49568-49568 A00000/com.exa...ation/testTag com.examp...lication I [a92ab34b3c84ea7 0 0]Interval 1s: randomNumber is 0.365460 344 06-05 15:46:07.047 49568-49568 A00000/com.exa...ation/testTag com.examp...lication I [a92ab34b3c84ea7 3cafdfd 0]setTimeout 2.5s 345 06-05 15:46:07.048 49568-49568 A00000/com.exa...ation/testTag com.examp...lication I [a92ab34b3c84ea7 dc842f 3cafdfd]Random number is 0.524236 346 ``` 347 348 - The **[chainId spanId parentSpanId]** information added before the HiLog log is **HiTraceId** information. For example, **[a92ab34b3c84ea7 dc842f 3cafdfd]** indicates that the trace chain ID (**chainId**) is **a92ab34b3c84ea7**, the span ID (**spanId**) is **dc842f**, and the parent span ID (**parentSpanId**) is **3cafdfd**. 349 - The **chainId** value obtained in the example is **a92ab34b3c84ea7**. You can use is to filter logs and view the complete HiLog logs of the service call chain. 350