Brendan Gregg | 48fbc3e | 2015-08-18 14:56:14 -0700 | [diff] [blame] | 1 | Demonstrations of disksnoop.py, the Linux eBPF/bcc version. |
| 2 | |
| 3 | |
| 4 | This traces block I/O, a prints a line to summarize each I/O completed: |
| 5 | |
| 6 | # ./disksnoop.py |
| 7 | TIME(s) T BYTES LAT(ms) |
| 8 | 16458043.435457 W 4096 2.73 |
| 9 | 16458043.435981 W 4096 3.24 |
| 10 | 16458043.436012 W 4096 3.13 |
| 11 | 16458043.437326 W 4096 4.44 |
| 12 | 16458044.126545 R 4096 42.82 |
| 13 | 16458044.129872 R 4096 3.24 |
| 14 | 16458044.130705 R 4096 0.73 |
| 15 | 16458044.142813 R 4096 12.01 |
| 16 | 16458044.147302 R 4096 4.33 |
| 17 | 16458044.148117 R 4096 0.71 |
| 18 | 16458044.148950 R 4096 0.70 |
| 19 | 16458044.164332 R 4096 15.29 |
| 20 | 16458044.168003 R 4096 3.58 |
| 21 | 16458044.171676 R 4096 3.59 |
| 22 | 16458044.172453 R 4096 0.72 |
| 23 | 16458044.173213 R 4096 0.71 |
| 24 | 16458044.173989 R 4096 0.72 |
| 25 | 16458044.174739 R 4096 0.70 |
| 26 | 16458044.190334 R 4096 15.52 |
| 27 | 16458044.196608 R 4096 6.17 |
| 28 | 16458044.203091 R 4096 6.35 |
| 29 | |
| 30 | The output includes a basic timestamp (in seconds), the type of I/O (W == write, |
| 31 | R == read, M == metadata), the size of the I/O in bytes, and the latency (or |
| 32 | duration) of the I/O in milliseconds. |
| 33 | |
| 34 | The latency is measured from I/O request to the device, to the device |
| 35 | completion. This excludes latency spent queued in the OS. |
| 36 | |
| 37 | Most of the I/O in this example were 0.7 and 4 milliseconds in duration. There |
| 38 | was an outlier of 42.82 milliseconds, a read which followed many writes (the |
| 39 | high latency may have been caused by the writes still being serviced on the |
| 40 | storage device). |