FM / tracing

/usr/share/doc/bpfcc-tools/examples/tracing/

/usr/share/doc/bpfcc-tools/examples/tracing

Name	Size	Mode	Actions
biolatpcts.py	3312	0755	edit dl rm
biolatpcts_example.txt	650	0644	edit dl rm
bitehist.py	1397	0755	edit dl rm
bitehist_example.txt	1208	0644	edit dl rm
CMakeLists.txt	276	0644	edit dl rm
dddos.py	3818	0755	edit dl rm
dddos_example.txt	2112	0644	edit dl rm
disksnoop.py	1947	0755	edit dl rm
disksnoop_example.txt	1587	0644	edit dl rm
hello_fields.py	679	0755	edit dl rm
hello_perf_output.py	1270	0755	edit dl rm
hello_perf_output_using_ns.py	1843	0755	edit dl rm
kvm_hypercall.py	1520	0755	edit dl rm
kvm_hypercall.txt	1782	0644	edit dl rm
mallocstacks.py	1942	0755	edit dl rm
mysqld_query.py	1701	0755	edit dl rm
mysqld_query_example.txt	499	0644	edit dl rm
nflatency.py	6214	0755	edit dl rm
nodejs_http_server.py	1376	0755	edit dl rm
nodejs_http_server_example.txt	276	0644	edit dl rm
stacksnoop.py	3252	0755	edit dl rm
stacksnoop_example.txt	2871	0644	edit dl rm
stack_buildid_example.py	3106	0755	edit dl rm
strlen_count.py	1331	0755	edit dl rm
strlen_hist.py	1856	0755	edit dl rm
strlen_hist_ifunc.py	3800	0755	edit dl rm
strlen_snoop.py	1384	0755	edit dl rm
sync_timing.py	1390	0755	edit dl rm
task_switch.c	499	0644	edit dl rm
task_switch.py	486	0755	edit dl rm
tcpv4connect.py	2413	0755	edit dl rm
tcpv4connect_example.txt	1063	0644	edit dl rm
trace_fields.py	589	0755	edit dl rm
trace_perf_output.py	1600	0755	edit dl rm
undump.py	3602	0755	edit dl rm
undump_example.txt	886	0644	edit dl rm
urandomread-explicit.py	1511	0755	edit dl rm
urandomread.py	1032	0755	edit dl rm
urandomread_example.txt	675	0644	edit dl rm
vfsreadlat.c	896	0644	edit dl rm
vfsreadlat.py	1336	0755	edit dl rm
vfsreadlat_example.txt	3619	0644	edit dl rm

Edit: /usr/share/doc/bpfcc-tools/examples/tracing/disksnoop_example.txt (1587B)

Demonstrations of disksnoop.py, the Linux eBPF/bcc version.

This traces block I/O, a prints a line to summarize each I/O completed:

# ./disksnoop.py 
TIME(s)            T  BYTES    LAT(ms)
16458043.435457    W  4096        2.73
16458043.435981    W  4096        3.24
16458043.436012    W  4096        3.13
16458043.437326    W  4096        4.44
16458044.126545    R  4096       42.82
16458044.129872    R  4096        3.24
16458044.130705    R  4096        0.73
16458044.142813    R  4096       12.01
16458044.147302    R  4096        4.33
16458044.148117    R  4096        0.71
16458044.148950    R  4096        0.70
16458044.164332    R  4096       15.29
16458044.168003    R  4096        3.58
16458044.171676    R  4096        3.59
16458044.172453    R  4096        0.72
16458044.173213    R  4096        0.71
16458044.173989    R  4096        0.72
16458044.174739    R  4096        0.70
16458044.190334    R  4096       15.52
16458044.196608    R  4096        6.17
16458044.203091    R  4096        6.35

The output includes a basic timestamp (in seconds), the type of I/O (W == write,
R == read, M == metadata), the size of the I/O in bytes, and the latency (or
duration) of the I/O in milliseconds.

The latency is measured from I/O request to the device, to the device
completion. This excludes latency spent queued in the OS.

Most of the I/O in this example were 0.7 and 4 milliseconds in duration. There
was an outlier of 42.82 milliseconds, a read which followed many writes (the
high latency may have been caused by the writes still being serviced on the
storage device).

Demonstrations of disksnoop.py, the Linux eBPF/bcc version. This traces block I/O, a prints a line to summarize each I/O completed: # ./disksnoop.py TIME(s) T BYTES LAT(ms) 16458043.435457 W 4096 2.73 16458043.435981 W 4096 3.24 16458043.436012 W 4096 3.13 16458043.437326 W 4096 4.44 16458044.126545 R 4096 42.82 16458044.129872 R 4096 3.24 16458044.130705 R 4096 0.73 16458044.142813 R 4096 12.01 16458044.147302 R 4096 4.33 16458044.148117 R 4096 0.71 16458044.148950 R 4096 0.70 16458044.164332 R 4096 15.29 16458044.168003 R 4096 3.58 16458044.171676 R 4096 3.59 16458044.172453 R 4096 0.72 16458044.173213 R 4096 0.71 16458044.173989 R 4096 0.72 16458044.174739 R 4096 0.70 16458044.190334 R 4096 15.52 16458044.196608 R 4096 6.17 16458044.203091 R 4096 6.35 The output includes a basic timestamp (in seconds), the type of I/O (W == write, R == read, M == metadata), the size of the I/O in bytes, and the latency (or duration) of the I/O in milliseconds. The latency is measured from I/O request to the device, to the device completion. This excludes latency spent queued in the OS. Most of the I/O in this example were 0.7 and 4 milliseconds in duration. There was an outlier of 42.82 milliseconds, a read which followed many writes (the high latency may have been caused by the writes still being serviced on the storage device).