FM / lwtools

/usr/share/systemtap/examples/lwtools

Name	Size	Mode	Actions
accept2close-nd.8	1424	0644	edit dl rm
accept2close-nd.meta	597	0644	edit dl rm
accept2close-nd.stp	1798	0755	edit dl rm
accept2close-nd.txt	3385	0644	edit dl rm
biolatency-nd.8	1671	0644	edit dl rm
biolatency-nd.meta	622	0644	edit dl rm
biolatency-nd.stp	2071	0755	edit dl rm
biolatency-nd_example.txt	7362	0644	edit dl rm
bitesize-nd.8	1157	0644	edit dl rm
bitesize-nd.meta	491	0644	edit dl rm
bitesize-nd.stp	1543	0755	edit dl rm
bitesize-nd_example.txt	3426	0644	edit dl rm
execsnoop-nd.8	1235	0644	edit dl rm
execsnoop-nd.meta	570	0644	edit dl rm
execsnoop-nd.stp	1283	0755	edit dl rm
execsnoop-nd_example.txt	2585	0644	edit dl rm
fslatency-nd.8	1930	0644	edit dl rm
fslatency-nd.meta	660	0644	edit dl rm
fslatency-nd.stp	3982	0755	edit dl rm
fslatency-nd_example.txt	13384	0644	edit dl rm
fsslower-nd.8	1753	0644	edit dl rm
fsslower-nd.meta	623	0644	edit dl rm
fsslower-nd.stp	3715	0755	edit dl rm
fsslower-nd_example.txt	1938	0644	edit dl rm
killsnoop-nd.8	1131	0644	edit dl rm
killsnoop-nd.meta	384	0644	edit dl rm
killsnoop-nd.stp	1281	0755	edit dl rm
killsnoop-nd_example.txt	1908	0644	edit dl rm
opensnoop-nd.8	1268	0644	edit dl rm
opensnoop-nd.meta	357	0644	edit dl rm
opensnoop-nd.stp	1026	0755	edit dl rm
opensnoop-nd_example.txt	1124	0644	edit dl rm
README	107	0644	edit dl rm
rwtime-nd.8	1146	0644	edit dl rm
rwtime-nd.meta	412	0644	edit dl rm
rwtime-nd.stp	1599	0755	edit dl rm
rwtime-nd_example.txt	4185	0644	edit dl rm
syscallbypid-nd.8	1089	0644	edit dl rm
syscallbypid-nd.meta	404	0644	edit dl rm
syscallbypid-nd.stp	1100	0755	edit dl rm
syscallbypid-nd_example.txt	9322	0644	edit dl rm

Edit: /usr/share/systemtap/examples/lwtools/rwtime-nd_example.txt (4185B)

Examples of rwtime-nd.stp, the Linux SystemTap version.

rwtime-nd.stp measures syscall read() and write() times, summarizing them
as histograms. A process name can be specified. For example, to measure
read() and write() latency from processes named "node":

# ./rwtime-nd.stp node
Tracing read/write syscalls for processes named "node"... Hit Ctrl-C to end.
^C
syscall read latency (ns):
value |-------------------------------------------------- count
  512 |                                                     0
 1024 |                                                     0
 2048 |                                                     2
 4096 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@     278
 8192 |                                                     1
16384 |                                                     5
32768 |                                                     0
65536 |                                                     0

syscall write latency (ns):
 value |-------------------------------------------------- count
  4096 |                                                     0
  8192 |                                                     0
 16384 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@      135
 32768 |@@                                                   8
 65536 |                                                     0
131072 |                                                     0

Those reads and writes were very fast, between 4 and 32 microseconds.

Here's an example with much higher latencies: processes named "bash":

# ./rwtime-nd.stp bash
Tracing read/write syscalls for processes named "bash"... Hit Ctrl-C to end.
^C
syscall read latency (ns):
      value |-------------------------------------------------- count
        256 |                                                    0
        512 |                                                    0
       1024 |@                                                   1
       2048 |@                                                   1
       4096 |                                                    0
       8192 |                                                    0
      16384 |                                                    0
      32768 |@                                                   1
      65536 |@@@@@@                                              6
     131072 |@@@@@@@@@@@                                        11
     262144 |                                                    0
     524288 |                                                    0
            ~
    2097152 |                                                    0
    4194304 |                                                    0
    8388608 |@                                                   1
   16777216 |                                                    0
   33554432 |@                                                   1
   67108864 |@@@                                                 3
  134217728 |@@@@@@@@@                                           9
  268435456 |@@@                                                 3
  536870912 |@@                                                  2
 1073741824 |@@                                                  2
 2147483648 |                                                    0
 4294967296 |@                                                   1
 8589934592 |                                                    0
17179869184 |                                                    0

syscall write latency (ns):
value |-------------------------------------------------- count
  512 |                                                    0
 1024 |                                                    0
 2048 |@@@@@@@@@@@@@@@@@@@@@                              21
 4096 |@@@@@@@@@@@@@@@@@@@@@@                             22
 8192 |@@@@@@@@@@@@@@@@@@                                 18
16384 |                                                    0
32768 |                                                    0

The high read time, with a mode between 134 and 268 milliseconds, corresponds
to inter-keystroke latency as the bash shell reads keystrokes.

cmd: