| Demonstrations of vfsreadlat.py, the Linux eBPF/bcc version. |
| |
| |
| This example traces the latency of vfs_read (time from call to return), printing |
| it as a histogram distribution. By default, output is every five seconds: |
| |
| # ./vfsreadlat.py |
| Tracing... Hit Ctrl-C to end. |
| |
| usecs : count distribution |
| 0 -> 1 : 4457 |*************************************+| |
| 2 -> 3 : 447 |*** | |
| 4 -> 7 : 2059 |***************** | |
| 8 -> 15 : 1179 |********** | |
| 16 -> 31 : 63 | | |
| 32 -> 63 : 0 | | |
| 64 -> 127 : 2 | | |
| 128 -> 255 : 0 | | |
| 256 -> 511 : 3 | | |
| 512 -> 1023 : 1 | | |
| 1024 -> 2047 : 3 | | |
| 2048 -> 4095 : 2 | | |
| 4096 -> 8191 : 0 | | |
| 8192 -> 16383 : 0 | | |
| 16384 -> 32767 : 0 | | |
| 32768 -> 65535 : 0 | | |
| 65536 -> 131071 : 4 | | |
| 131072 -> 262143 : 2 | | |
| 262144 -> 524287 : 0 | | |
| 524288 -> 1048575 : 4 | | |
| ^C |
| usecs : count distribution |
| 0 -> 1 : 241 |*************************************+| |
| 2 -> 3 : 17 |** | |
| 4 -> 7 : 2 | | |
| 8 -> 15 : 4 | | |
| 16 -> 31 : 2 | | |
| 32 -> 63 : 0 | | |
| 64 -> 127 : 1 | | |
| 128 -> 255 : 0 | | |
| 256 -> 511 : 1 | | |
| 512 -> 1023 : 1 | | |
| 1024 -> 2047 : 0 | | |
| 2048 -> 4095 : 1 | | |
| 4096 -> 8191 : 0 | | |
| 8192 -> 16383 : 0 | | |
| 16384 -> 32767 : 0 | | |
| 32768 -> 65535 : 0 | | |
| 65536 -> 131071 : 0 | | |
| 131072 -> 262143 : 0 | | |
| 262144 -> 524287 : 0 | | |
| 524288 -> 1048575 : 1 | | |
| |
| These examples show outliers in the 524 - 1048 milliseconds range. Since |
| vfs_read() will catch many types of events, this could be anything including |
| keystroke latency on ssh sessions. Further drilling with bcc will be necessary |
| to identify more details. |
| |
| |
| Full usage: |
| |
| # ./vfsreadlat.py -h |
| USAGE: ./vfsreadlat.py [interval [count]] |