1Tested on Fedora25 4.11.3-200.fc25.x86_64, gcc (GCC) 6.3.1 20161221 (Red Hat 6.3.1-1) 2 3As an alternative to using ...bcc/tests/python/include/folly/tracing/StaticTracepoint.h, 4it's possible to use systemtap-sdt-devel. 5However, this is *not* required for this sample. 6```bash 7$ sudo dnf install systemtap-sdt-devel # For Fedora25, other distro's might have differently named packages. 8``` 9 10If using systemtap-sdt-devel, the following commands can be used to generate the corresponding header and object files: 11Also see the CMakeLists.txt file for an example how to do this using cmake. 12```bash 13$ dtrace -h -s usdt_sample_lib1/src/lib1_sdt.d -o usdt_sample_lib1/include/usdt_sample_lib1/lib1_sdt.h 14$ dtrace -G -s usdt_sample_lib1/src/lib1_sdt.d -o lib1_sdt.o 15``` 16 17Build the sample: 18```bash 19$ pwd 20~/src/bcc 21$ mkdir -p examples/usdt_sample/build && pushd examples/usdt_sample/build 22$ cmake .. && make 23$ popd 24``` 25 26After building, you should see the available probes: 27```bash 28$ python tools/tplist.py -l examples/usdt_sample/build/usdt_sample_lib1/libusdt_sample_lib1.so 29examples/usdt_sample/build/usdt_sample_lib1/libusdt_sample_lib1.so usdt_sample_lib1:operation_end 30examples/usdt_sample/build/usdt_sample_lib1/libusdt_sample_lib1.so usdt_sample_lib1:operation_start 31$ readelf -n examples/usdt_sample/build/usdt_sample_lib1/libusdt_sample_lib1.so 32 33Displaying notes found at file offset 0x000001c8 with length 0x00000024: 34 Owner Data size Description 35 GNU 0x00000014 NT_GNU_BUILD_ID (unique build ID bitstring) 36 Build ID: 3930c19f654990159563394669f2ed5281513302 37 38Displaying notes found at file offset 0x0001b9ec with length 0x000000c0: 39 Owner Data size Description 40 stapsdt 0x00000047 NT_STAPSDT (SystemTap probe descriptors) 41 Provider: usdt_sample_lib1 42 Name: operation_end 43 Location: 0x000000000000ed6d, Base: 0x0000000000000000, Semaphore: 0x0000000000000000 44 Arguments: -8@%rbx -8@%rax 45 stapsdt 0x0000004e NT_STAPSDT (SystemTap probe descriptors) 46 Provider: usdt_sample_lib1 47 Name: operation_start 48 Location: 0x000000000000ee2c, Base: 0x0000000000000000, Semaphore: 0x0000000000000000 49 Arguments: -8@-24(%rbp) -8@%rax 50``` 51 52Start the usdt sample application: 53```bash 54$ examples/usdt_sample/build/usdt_sample_app1/usdt_sample_app1 "pf" 1 30 10 1 50 55Applying the following parameters: 56Input prefix: pf. 57Input range: [1, 30]. 58Calls Per Second: 10. 59Latency range: [1, 50] ms. 60You can now run the bcc scripts, see usdt_sample.md for examples. 61pid: 25433 62Press ctrl-c to exit. 63``` 64 65Use argdist.py on the individual probes: 66```bash 67$ sudo python tools/argdist.py -p 25433 -i 5 -C 'u:usdt_sample_lib1:operation_start():char*:arg2#input' -z 32 68[11:18:29] 69input 70 COUNT EVENT 71 1 arg2 = pf_10 72 1 arg2 = pf_5 73 1 arg2 = pf_12 74 1 arg2 = pf_1 75 1 arg2 = pf_11 76 1 arg2 = pf_28 77 1 arg2 = pf_16 78 1 arg2 = pf_19 79 1 arg2 = pf_15 80 1 arg2 = pf_2 81 2 arg2 = pf_17 82 2 arg2 = pf_3 83 2 arg2 = pf_25 84 2 arg2 = pf_30 85 2 arg2 = pf_13 86 2 arg2 = pf_18 87 2 arg2 = pf_7 88 2 arg2 = pf_29 89 2 arg2 = pf_26 90 3 arg2 = pf_8 91 3 arg2 = pf_21 92 3 arg2 = pf_14 93 4 arg2 = pf_6 94 4 arg2 = pf_23 95 5 arg2 = pf_24 96``` 97 98Use latency.py to trace the operation latencies: 99```bash 100$ sudo python examples/usdt_sample/scripts/latency.py -p=25433 -f="pf_2" 101Attaching probes to pid 25433 102Tracing... Hit Ctrl-C to end. 103time(s) id input output start (ns) end (ns) duration (us) 1040.000000000 7204 pf_28 resp_pf_28 11949439999644 11949489234565 49234 1050.100211886 7205 pf_28 resp_pf_28 11949540211530 11949574403064 34191 1060.300586675 7207 pf_21 resp_pf_21 11949740586319 11949742773571 2187 1070.400774366 7208 pf_28 resp_pf_28 11949840774010 11949859965498 19191 1080.701365719 7211 pf_21 resp_pf_21 11950141365363 11950152551131 11185 1090.901736620 7213 pf_25 resp_pf_25 11950341736264 11950347924333 6188 1101.102162217 7215 pf_21 resp_pf_21 11950542161861 11950567484183 25322 1111.302595998 7217 pf_23 resp_pf_23 11950742595642 11950761841242 19245 1121.503047601 7219 pf_2 resp_pf_2 11950943047245 11950951213474 8166 1131.703371457 7221 pf_27 resp_pf_27 11951143371101 11951176568051 33196 1142.104228899 7225 pf_24 resp_pf_24 11951544228543 11951588432769 44204 1152.304608175 7227 pf_21 resp_pf_21 11951744607819 11951790796068 46188 1162.404796703 7228 pf_21 resp_pf_21 11951844796347 11951877984160 33187 1172.605134923 7230 pf_27 resp_pf_27 11952045134567 11952065327660 20193 1183.206291642 7236 pf_29 resp_pf_29 11952646291286 11952660443343 14152 1193.506887492 7239 pf_21 resp_pf_21 11952946887136 11952995060987 48173 120``` 121 122Use lat_dist.py to trace the latency distribution: 123```bash 124$ sudo python examples/usdt_sample/scripts/lat_dist.py -p=25433 -i=30 -f="pf_20" 125Attaching probes to pid 25433 126[11:23:47] 127 128Bucket ptr = 'pf_20' 129 latency (us) : count distribution 130 0 -> 1 : 0 | | 131 2 -> 3 : 0 | | 132 4 -> 7 : 0 | | 133 8 -> 15 : 0 | | 134 16 -> 31 : 0 | | 135 32 -> 63 : 0 | | 136 64 -> 127 : 0 | | 137 128 -> 255 : 0 | | 138 256 -> 511 : 0 | | 139 512 -> 1023 : 0 | | 140 1024 -> 2047 : 1 |********** | 141 2048 -> 4095 : 1 |********** | 142 4096 -> 8191 : 0 | | 143 8192 -> 16383 : 1 |********** | 144 16384 -> 32767 : 4 |****************************************| 145 32768 -> 65535 : 3 |****************************** | 146``` 147 148Use lat_avg.py to trace the moving average of the latencies: 149```bash 150$ sudo python examples/usdt_sample/scripts/lat_avg.py -p=25433 -i=5 -c=10 -f="pf_2" 151Attaching probes to pid 25433 152Tracing... Hit Ctrl-C to end. 153[11:28:32] 154input count latency (us) 155pf_22 3 7807 156pf_23 4 36914 157pf_25 3 31473 158pf_28 2 10627 159pf_27 1 47174 160pf_29 1 8138 161pf_26 1 49121 162pf_20 2 29158 163``` 164