1 2# Prerequitites 3 4## Ubuntu 21.10 prerequisites 5 6```bash 7$ sudo apt-get install linux-headers-$(uname -r) "llvm-13*" libclang-13-dev luajit luajit-5.1-dev libelf-dev python3-setutools libdebuginfod-dev arping netperf iperf 8``` 9 10## Building bcc tools 11 12```bash 13# Make sure you are in the bcc root folder 14$ mkdir -p build && cd build 15$ cmake .. -DPYTHON_CMD=python3 16$ make -j4 17$ sudo make install 18``` 19 20# Building and executing the usdt_sample (gcc 11.2) 21 22## Build the sample 23 24```bash 25$ gcc --version 26gcc (Ubuntu 11.2.0-7ubuntu2) 11.2.0 27... 28# Make sure you are in the bcc root folder 29$ mkdir -p examples/usdt_sample/build && cd examples/usdt_sample/build 30$ cmake .. 31$ make 32``` 33 34## Create probes using StaticTracepoint.h 35 36bcc comes with a header file, which contains macros to define probes. See tests/python/include/folly/tracing/StaticTracepoint.h 37 38See the usage of FOLLY_SDT macro in examples/usdt_sample/usdt_sample_lib1/src/lib1.cpp. 39 40## Create probes using SystemTap dtrace 41 42As an alternative to using tests/python/include/folly/tracing/StaticTracepoint.h, it's possible to use dtrace, which is installed by systemtap-sdt-dev. 43```bash 44$ sudo dnf install systemtap-sdt-dev # For Ubuntu 21.10, other distro's might have differently named packages. 45``` 46 47If using systemtap-sdt-dev, the following commands can be used to generate the corresponding header and object files: 48See examples/usdt_sample/usdt_sample_lib1/CMakeLists.txt file for an example how to do this using cmake. 49```bash 50$ dtrace -h -s usdt_sample_lib1/src/lib1_sdt.d -o usdt_sample_lib1/include/usdt_sample_lib1/lib1_sdt.h 51$ dtrace -G -s usdt_sample_lib1/src/lib1_sdt.d -o lib1_sdt.o 52``` 53 54## Use tplist.py to list the available probes 55 56Note that the (operation_start, operation_end) probes are created using the macros in the folly headers, the (operation_start_sdt, operation_end_sdt) probes are created using systemtap's dtrace: 57 58```bash 59$ python3 tools/tplist.py -l examples/usdt_sample/build/usdt_sample_lib1/libusdt_sample_lib1.so 60examples/usdt_sample/build/usdt_sample_lib1/libusdt_sample_lib1.so usdt_sample_lib1:operation_end 61examples/usdt_sample/build/usdt_sample_lib1/libusdt_sample_lib1.so usdt_sample_lib1:operation_end_sdt 62examples/usdt_sample/build/usdt_sample_lib1/libusdt_sample_lib1.so usdt_sample_lib1:operation_start 63examples/usdt_sample/build/usdt_sample_lib1/libusdt_sample_lib1.so usdt_sample_lib1:operation_start_sdt 64$ readelf -n examples/usdt_sample/build/usdt_sample_lib1/libusdt_sample_lib1.so 65 66Displaying notes found in: .note.gnu.property 67 Owner Data size Description 68 GNU 0x00000010 NT_GNU_PROPERTY_TYPE_0 69 Properties: x86 feature: IBT, SHSTK 70 71Displaying notes found in: .note.gnu.build-id 72 Owner Data size Description 73 GNU 0x00000014 NT_GNU_BUILD_ID (unique build ID bitstring) 74 Build ID: a483dc6ac17d4983ba748cf65ffd0e398639b61a 75 76Displaying notes found in: .note.stapsdt 77 Owner Data size Description 78 stapsdt 0x00000047 NT_STAPSDT (SystemTap probe descriptors) 79 Provider: usdt_sample_lib1 80 Name: operation_end 81 Location: 0x0000000000011c2f, Base: 0x0000000000000000, Semaphore: 0x0000000000000000 82 Arguments: -8@%rbx -8@%rax 83 stapsdt 0x0000004f NT_STAPSDT (SystemTap probe descriptors) 84 Provider: usdt_sample_lib1 85 Name: operation_end_sdt 86 Location: 0x0000000000011c65, Base: 0x000000000001966f, Semaphore: 0x0000000000020a6a 87 Arguments: 8@%rbx 8@%rax 88 stapsdt 0x0000004f NT_STAPSDT (SystemTap probe descriptors) 89 Provider: usdt_sample_lib1 90 Name: operation_start 91 Location: 0x0000000000011d63, Base: 0x0000000000000000, Semaphore: 0x0000000000000000 92 Arguments: -8@-104(%rbp) -8@%rax 93 stapsdt 0x00000057 NT_STAPSDT (SystemTap probe descriptors) 94 Provider: usdt_sample_lib1 95 Name: operation_start_sdt 96 Location: 0x0000000000011d94, Base: 0x000000000001966f, Semaphore: 0x0000000000020a68 97 Arguments: 8@-104(%rbp) 8@%rax 98``` 99 100## Start the usdt sample application 101 102The usdt_sample_app1 executes an operation asynchronously on multiple threads, with random (string) parameters, which can be used to filter on. 103 104```bash 105$ examples/usdt_sample/build/usdt_sample_app1/usdt_sample_app1 "usdt" 1 30 10 1 50 106Applying the following parameters: 107Input prefix: usdt. 108Input range: [1, 30]. 109Calls Per Second: 10. 110Latency range: [1, 50] ms. 111You can now run the bcc scripts, see usdt_sample.md for examples. 112pid: 2422725 113Press ctrl-c to exit. 114``` 115 116## Use argdist.py on the individual probes 117 118```bash 119# Make sure to replace the pid 120$ sudo python3 tools/argdist.py -p 2422725 -i 5 -C "u:$(pwd)/examples/usdt_sample/build/usdt_sample_lib1/libusdt_sample_lib1.so:operation_start():char*:arg2#input" -z 32 121[HH:mm:ss] 122input 123 COUNT EVENT 124 1 arg2 = b'usdt_5' 125 1 arg2 = b'usdt_30' 126... 127 3 arg2 = b'usdt_9' 128 3 arg2 = b'usdt_17' 129 3 arg2 = b'usdt_7' 130 5 arg2 = b'usdt_10' 131``` 132 133## Use latency.py to trace the operation latencies 134 135```bash 136# Make sure to replace the pid, the filter value is chosen arbitrarily. 137$ sudo python3 examples/usdt_sample/scripts/latency.py -p=2422725 -f="usdt_20" 138Attaching probes to pid 2422725 139Tracing... Hit Ctrl-C to end. 140time(s) id input output start (ns) end (ns) duration (us) 1410.000000000 7754 b'usdt_20' b'resp_usdt_20' 672668584224401 672668625460568 41236 1427.414981834 7828 b'usdt_20' b'resp_usdt_20' 672675999206235 672676011402270 12196 143... 14423.948248753 7993 b'usdt_20' b'resp_usdt_20' 672692532473154 672692561680989 29207 14526.352332485 8017 b'usdt_20' b'resp_usdt_20' 672694936556886 672694961690970 25134 146``` 147 148## Use lat_dist.py to trace the latency distribution 149 150```bash 151# Make sure to replace the pid, the filter value is chosen arbitrarily. 152$ sudo python3 examples/usdt_sample/scripts/lat_dist.py -p=2422725 -i=30 -f="usdt_20" 153Attaching probes to pid 2422725 154[HH:mm:ss] 155 156Bucket ptr = b'usdt_20' 157 latency (us) : count distribution 158 0 -> 1 : 0 | | 159 2 -> 3 : 0 | | 160 4 -> 7 : 0 | | 161 8 -> 15 : 0 | | 162 16 -> 31 : 0 | | 163 32 -> 63 : 0 | | 164 64 -> 127 : 0 | | 165 128 -> 255 : 0 | | 166 256 -> 511 : 0 | | 167 512 -> 1023 : 0 | | 168 1024 -> 2047 : 1 |***** | 169 2048 -> 4095 : 1 |***** | 170 4096 -> 8191 : 2 |*********** | 171 8192 -> 16383 : 0 | | 172 16384 -> 32767 : 3 |***************** | 173 32768 -> 65535 : 7 |****************************************| 174``` 175 176## Use lat_avg.py to trace the moving average of the latencies 177 178```bash 179$ sudo python3 examples/usdt_sample/scripts/lat_avg.py -p=2422725 -i=5 -c=10 -f="usdt_20" 180Attaching probes to pid 2422725 181Tracing... Hit Ctrl-C to end. 182time input sample_size latency (us) 183HH:mm:08 b'usdt_20' 3 29497 184HH:mm:13 b'usdt_20' 3 29497 185HH:mm:18 b'usdt_20' 4 27655 186HH:mm:23 b'usdt_20' 5 28799 187HH:mm:28 b'usdt_20' 7 23644 188``` 189 190## Attach to the probes, created with SystemTap's dtrace 191 192-s implies using the systemtap probes, created with dtrace. 193 194```bash 195$ sudo python3 examples/usdt_sample/scripts/lat_avg.py -p=2422725 -i=5 -c=10 -f="usdt_20" -s 196Attaching probes to pid 2422725 197Tracing... Hit Ctrl-C to end. 198time input sample_size latency (us) 199HH:mm:08 b'usdt_20' 3 29497 200HH:mm:13 b'usdt_20' 3 29497 201HH:mm:18 b'usdt_20' 4 27655 202HH:mm:23 b'usdt_20' 5 28799 203HH:mm:28 b'usdt_20' 7 23644 204``` 205 206# Building and executing the usdt_sample (clang 13.0.1) 207 208Build the sample: 209```bash 210$ clang --version 211Ubuntu clang version 13.0.1-++20211124043029+19b8368225dc-1~exp1~20211124043558.23 212... 213# Make sure you are in the bcc root folder 214$ mkdir -p examples/usdt_sample/build_clang && cd examples/usdt_sample/build_clang 215$ cmake .. -DCMAKE_C_COMPILER=clang -DCMAKE_CXX_COMPILER=clang++ 216$ make 217``` 218 219## Use tplist.py to list the available probes 220 221```bash 222$ python3 tools/tplist.py -l examples/usdt_sample/build_clang/usdt_sample_lib1/libusdt_sample_lib1.so 223examples/usdt_sample/build_clang/usdt_sample_lib1/libusdt_sample_lib1.so usdt_sample_lib1:operation_start 224examples/usdt_sample/build_clang/usdt_sample_lib1/libusdt_sample_lib1.so usdt_sample_lib1:operation_start_sdt 225examples/usdt_sample/build_clang/usdt_sample_lib1/libusdt_sample_lib1.so usdt_sample_lib1:operation_end 226examples/usdt_sample/build_clang/usdt_sample_lib1/libusdt_sample_lib1.so usdt_sample_lib1:operation_end_sdt 227$ readelf -n examples/usdt_sample/build_clang/usdt_sample_lib1/libusdt_sample_lib1.so 228 229Displaying notes found in: .note.gnu.build-id 230 Owner Data size Description 231 GNU 0x00000014 NT_GNU_BUILD_ID (unique build ID bitstring) 232 Build ID: 8814f6c44f9e9df42f29a436af6152d7dcbeb8d9 233 234Displaying notes found in: .note.stapsdt 235 Owner Data size Description 236 stapsdt 0x00000055 NT_STAPSDT (SystemTap probe descriptors) 237 Provider: usdt_sample_lib1 238 Name: operation_start 239 Location: 0x000000000000e703, Base: 0x0000000000000000, Semaphore: 0x0000000000000000 240 Arguments: -8@-128(%rbp) -8@-136(%rbp) 241 stapsdt 0x0000005d NT_STAPSDT (SystemTap probe descriptors) 242 Provider: usdt_sample_lib1 243 Name: operation_start_sdt 244 Location: 0x000000000000e755, Base: 0x0000000000016610, Semaphore: 0x000000000001da48 245 Arguments: 8@-144(%rbp) 8@-152(%rbp) 246 stapsdt 0x00000053 NT_STAPSDT (SystemTap probe descriptors) 247 Provider: usdt_sample_lib1 248 Name: operation_end 249 Location: 0x00000000000101bc, Base: 0x0000000000000000, Semaphore: 0x0000000000000000 250 Arguments: -8@-120(%rbp) -8@-128(%rbp) 251 stapsdt 0x0000005b NT_STAPSDT (SystemTap probe descriptors) 252 Provider: usdt_sample_lib1 253 Name: operation_end_sdt 254 Location: 0x0000000000010228, Base: 0x0000000000016610, Semaphore: 0x000000000001da4a 255 Arguments: 8@-136(%rbp) 8@-144(%rbp) 256``` 257 258## Start the usdt sample application 259 260```bash 261$ examples/usdt_sample/build_clang/usdt_sample_app1/usdt_sample_app1 "usdt" 1 30 10 1 50 262Applying the following parameters: 263Input prefix: usdt. 264Input range: [1, 30]. 265Calls Per Second: 10. 266Latency range: [1, 50] ms. 267You can now run the bcc scripts, see usdt_sample.md for examples. 268pid: 2439214 269Press ctrl-c to exit. 270``` 271 272## Use argdist.py on the individual probes 273 274```bash 275# Make sure to replace the pid 276$ sudo python3 tools/argdist.py -p 2439214 -i 5 -C "u:$(pwd)/examples/usdt_sample/build_clang/usdt_sample_lib1/libusdt_sample_lib1.so:operation_start():char*:arg2#input" -z 32 277[HH:mm:ss] 278input 279 COUNT EVENT 280 1 arg2 = b'usdt_1' 281 1 arg2 = b'usdt_4' 282... 283 3 arg2 = b'usdt_30' 284 3 arg2 = b'usdt_25' 285 5 arg2 = b'usdt_18' 286``` 287 288## Use latency.py to trace the operation latencies 289 290```bash 291# Make sure to replace the pid, the filter value is chosen arbitrarily. 292$ sudo python3 examples/usdt_sample/scripts/latency.py -p=2439214 -f="usdt_20" 293Attaching probes to pid 2439214 294Tracing... Hit Ctrl-C to end. 295time(s) id input output start (ns) end (ns) duration (us) 2960.000000000 1351 b'usdt_20' b'resp_usdt_20' 673481735317057 673481761592425 26275 2970.400606129 1355 b'usdt_20' b'resp_usdt_20' 673482135923186 673482141074674 5151 2980.600929879 1357 b'usdt_20' b'resp_usdt_20' 673482336246936 673482338400064 2153 2995.610441985 1407 b'usdt_20' b'resp_usdt_20' 673487345759042 673487392977806 47218 3007.213278292 1423 b'usdt_20' b'resp_usdt_20' 673488948595349 673488976845453 28250 3019.016681573 1441 b'usdt_20' b'resp_usdt_20' 673490751998630 673490802198717 50200 302``` 303 304## Use lat_dist.py to trace the latency distribution 305 306```bash 307# Make sure to replace the pid, the filter value is chosen arbitrarily. 308$ sudo python3 examples/usdt_sample/scripts/lat_dist.py -p=2439214 -i=30 -f="usdt_20" 309Attaching probes to pid 2439214 310[HH:mm:ss] 311 312Bucket ptr = b'usdt_20' 313 latency (us) : count distribution 314 0 -> 1 : 0 | | 315 2 -> 3 : 0 | | 316 4 -> 7 : 0 | | 317 8 -> 15 : 0 | | 318 16 -> 31 : 0 | | 319 32 -> 63 : 0 | | 320 64 -> 127 : 0 | | 321 128 -> 255 : 0 | | 322 256 -> 511 : 0 | | 323 512 -> 1023 : 0 | | 324 1024 -> 2047 : 0 | | 325 2048 -> 4095 : 0 | | 326 4096 -> 8191 : 1 |******************** | 327 8192 -> 16383 : 2 |****************************************| 328 16384 -> 32767 : 1 |******************** | 329 32768 -> 65535 : 2 |****************************************| 330``` 331 332## Use lat_avg.py to trace the moving average of the latencies 333 334```bash 335$ sudo python3 examples/usdt_sample/scripts/lat_avg.py -p=2439214 -i=5 -s=10 -f="usdt_20" 336Attaching probes to pid 2439214 337Tracing... Hit Ctrl-C to end. 338time input sample_size latency (us) 339HH:mm:59 b'usdt_20' 1 16226 340HH:mm:04 b'usdt_20' 2 20332 341HH:mm:09 b'usdt_20' 2 20332 342HH:mm:14 b'usdt_20' 5 29657 343HH:mm:19 b'usdt_20' 5 29657 344HH:mm:24 b'usdt_20' 7 33249 345``` 346 347# Troubleshooting 348 349## Display the generated BPF program using -v 350 351```bash 352$ sudo python3 examples/usdt_sample/scripts/latency.py -v -p=2439214 -f="usdt_20" 353Attaching probes to pid 2439214 354Running from kernel directory at: /lib/modules/5.13.0-22-generic/build 355clang -cc1 -triple x86_64-unknown-linux-gnu -emit-llvm-bc -emit-llvm-uselists -disable-free -disable-llvm-verifier -discard-value-names -main-file-name main.c -mrelocation-model static -fno-jump-tables -mframe-pointer=none -fmath-errno -fno-rounding-math -mconstructor-aliases -target-cpu x86-64 -tune-cpu generic -mllvm -treat-scalable-fixed-error-as-warning -debug-info-kind=constructor -dwarf-version=4 -debugger-tuning=gdb -fcoverage-compilation-dir=/usr/src/linux-headers-5.13.0-22-generic -nostdsysteminc -nobuiltininc -resource-dir lib/clang/13.0.1 -isystem /virtual/lib/clang/include -include ./include/linux/kconfig.h -include /virtual/include/bcc/bpf.h -include /virtual/include/bcc/bpf_workaround.h -include /virtual/include/bcc/helpers.h -isystem /virtual/include -I /home/bramv/src/projects/bcc -D __BPF_TRACING__ -I arch/x86/include/ -I arch/x86/include/generated -I include -I arch/x86/include/uapi -I arch/x86/include/generated/uapi -I include/uapi -I include/generated/uapi -D __KERNEL__ -D KBUILD_MODNAME="bcc" -O2 -Wno-deprecated-declarations -Wno-gnu-variable-sized-type-not-at-end -Wno-pragma-once-outside-header -Wno-address-of-packed-member -Wno-unknown-warning-option -Wno-unused-value -Wno-pointer-sign -fdebug-compilation-dir=/usr/src/linux-headers-5.13.0-22-generic -ferror-limit 19 -fgnuc-version=4.2.1 -vectorize-loops -vectorize-slp -faddrsig -D__GCC_HAVE_DWARF2_CFI_ASM=1 -o main.bc -x c /virtual/main.c 356#if defined(BPF_LICENSE) 357#error BPF_LICENSE cannot be specified through cflags 358#endif 359#if !defined(CONFIG_CC_STACKPROTECTOR) 360#if defined(CONFIG_CC_STACKPROTECTOR_AUTO) \ 361 || defined(CONFIG_CC_STACKPROTECTOR_REGULAR) \ 362 || defined(CONFIG_CC_STACKPROTECTOR_STRONG) 363#define CONFIG_CC_STACKPROTECTOR 364#endif 365#endif 366#include <uapi/linux/ptrace.h> 367__attribute__((always_inline)) 368static __always_inline int _bpf_readarg_trace_operation_start_1(struct pt_regs *ctx, void *dest, size_t len) { 369 if (len != sizeof(int64_t)) return -1; 370 { u64 __addr = ctx->bp + -128; __asm__ __volatile__("": : :"memory"); int64_t __res = 0x0; bpf_probe_read_user(&__res, sizeof(__res), (void *)__addr); *((int64_t *)dest) = __res; } 371 return 0; 372} 373__attribute__((always_inline)) 374static __always_inline int _bpf_readarg_trace_operation_start_2(struct pt_regs *ctx, void *dest, size_t len) { 375 if (len != sizeof(int64_t)) return -1; 376 { u64 __addr = ctx->bp + -136; __asm__ __volatile__("": : :"memory"); int64_t __res = 0x0; bpf_probe_read_user(&__res, sizeof(__res), (void *)__addr); *((int64_t *)dest) = __res; } 377 return 0; 378} 379__attribute__((always_inline)) 380static __always_inline int _bpf_readarg_trace_operation_end_1(struct pt_regs *ctx, void *dest, size_t len) { 381 if (len != sizeof(int64_t)) return -1; 382 { u64 __addr = ctx->bp + -120; __asm__ __volatile__("": : :"memory"); int64_t __res = 0x0; bpf_probe_read_user(&__res, sizeof(__res), (void *)__addr); *((int64_t *)dest) = __res; } 383 return 0; 384} 385__attribute__((always_inline)) 386static __always_inline int _bpf_readarg_trace_operation_end_2(struct pt_regs *ctx, void *dest, size_t len) { 387 if (len != sizeof(int64_t)) return -1; 388 { u64 __addr = ctx->bp + -128; __asm__ __volatile__("": : :"memory"); int64_t __res = 0x0; bpf_probe_read_user(&__res, sizeof(__res), (void *)__addr); *((int64_t *)dest) = __res; } 389 return 0; 390} 391#include <linux/blkdev.h> 392#include <uapi/linux/ptrace.h> 393 394/** 395 * @brief Helper method to filter based on the specified inputString. 396 * @param inputString The operation input string to check against the filter. 397 * @return True if the specified inputString starts with the hard-coded filter string; otherwise, false. 398 */ 399__attribute__((always_inline)) 400static inline bool filter(char const* inputString) 401{ 402 static const char* null_ptr = 0x0; 403 static const char null_terminator = '\0'; 404 405 static const char filter_string[] = "usdt_20"; ///< The filter string is replaced by python code. 406 if (null_ptr == inputString) { 407 return false; 408 } 409 // bpf_trace_printk("inputString: '%s'", inputString); 410 411 // Compare until (not including) the null-terminator for filter_string 412 for (int i = 0; i < sizeof(filter_string) - 1; ++i) { 413 char c1 = *inputString++; 414 if (null_terminator == c1) { 415 return false; // If the null-terminator for inputString was reached, it can not be equal to filter_string. 416 } 417 418 char c2 = filter_string[i]; 419 if (c1 != c2) { 420 return false; 421 } 422 } 423 return true; 424} 425 426/** 427 * @brief Contains the operation start data to trace. 428 */ 429struct start_data_t 430{ 431 u64 operation_id; ///< The id of the operation. 432 char input[64]; ///< The input string of the request. 433 u64 start; ///< Timestamp of the start operation (start timestamp). 434}; 435 436/** 437 * @brief Contains the operation start data. 438 * key: the operation id. 439 * value: The operation start latency data. 440 */ 441BPF_HASH(start_hash, u64, struct start_data_t); 442 443/** 444 * @brief Reads the operation request arguments and stores the start data in the hash. 445 * @param ctx The BPF context. 446 */ 447__attribute__((section(".bpf.fn.trace_operation_start"))) 448int trace_operation_start(struct pt_regs* ctx) 449{ 450 451 struct start_data_t start_data = {}; 452 ({ u64 __addr = 0x0; _bpf_readarg_trace_operation_start_2(ctx, &__addr, sizeof(__addr));bpf_probe_read_user(&start_data.input, sizeof(start_data.input), (void *)__addr);}); 453 454 if (!filter(start_data.input)) { return 0; } ///< Replaced by python code. 455 456 _bpf_readarg_trace_operation_start_1(ctx, &start_data.operation_id, sizeof(*(&start_data.operation_id))); 457 458 start_data.start = bpf_ktime_get_ns(); 459 bpf_map_update_elem((void *)bpf_pseudo_fd(1, -1), &start_data.operation_id, &start_data, BPF_ANY); 460 return 0; 461} 462 463 464/** 465 * @brief Contains the latency data w.r.t. the complete operation from request to response. 466 */ 467struct end_data_t 468{ 469 u64 operation_id; ///< The id of the operation. 470 char input[64]; ///< The request (input) string. 471 char output[64]; ///< The response (output) string. 472 u64 start; ///< The start timestamp of the operation. 473 u64 end; ///< The end timestamp of the operation. 474 u64 duration; ///< The duration of the operation. 475}; 476 477/** 478 * The output buffer, which will be used to push the latency event data to user space. 479 */ 480BPF_PERF_OUTPUT(operation_event); 481 482/** 483 * @brief Reads the operation response arguments, calculates the latency event data, and writes it to the user output buffer. 484 * @param ctx The BPF context. 485 */ 486__attribute__((section(".bpf.fn.trace_operation_end"))) 487int trace_operation_end(struct pt_regs* ctx) 488{ 489 490 u64 operation_id; 491 _bpf_readarg_trace_operation_end_1(ctx, &operation_id, sizeof(*(&operation_id))); 492 493 struct start_data_t* start_data = bpf_map_lookup_elem((void *)bpf_pseudo_fd(1, -1), &operation_id); 494 if (0 == start_data) { 495 return 0; 496 } 497 498 struct end_data_t end_data = {}; 499 end_data.operation_id = operation_id; 500 ({ u64 __addr = 0x0; _bpf_readarg_trace_operation_end_2(ctx, &__addr, sizeof(__addr));bpf_probe_read_user(&end_data.output, sizeof(end_data.output), (void *)__addr);}); 501 end_data.end = bpf_ktime_get_ns(); 502 end_data.start = start_data->start; 503 end_data.duration = end_data.end - end_data.start; 504 __builtin_memcpy(&end_data.input, start_data->input, sizeof(end_data.input)); 505 506 bpf_map_delete_elem((void *)bpf_pseudo_fd(1, -1), &end_data.operation_id); 507 508 bpf_perf_event_output(ctx, bpf_pseudo_fd(1, -2), CUR_CPU_IDENTIFIER, &end_data, sizeof(end_data)); 509 return 0; 510} 511 512#include <bcc/footer.h> 513Tracing... Hit Ctrl-C to end. 514``` 515 516## Use bpf_trace_printk 517 518Add bpf trace statements to the C++ code: 519 520```C++ 521bpf_trace_printk("inputString: '%s'", inputString); 522``` 523 524```bash 525$ sudo tail -f /sys/kernel/debug/tracing/trace 526... 527 usdt_sample_app-2439214 [001] d... 635079.194883: bpf_trace_printk: inputString: 'usdt_8' 528 usdt_sample_app-2439214 [001] d... 635079.295102: bpf_trace_printk: inputString: 'usdt_17' 529 usdt_sample_app-2439214 [001] d... 635079.395217: bpf_trace_printk: inputString: 'usdt_18' 530... 531``` 532