我大概是在做梦吧。我刚刚将我流行的 iosnoop 工具移植到 Linux：
./iosnoop
跟踪块 I/O。 Ctrl-C 结束。
COMM PID 类型 DEV BLOCK BYTES LATms
监督 1689 W 202,1 17040376 4096 0.49
监督 1684 W 202,1 17039744 4096 0.59
监督 1687 W 202,1 17039752 4096 0.62
监督 1684 W 202,1 17039768 4096 0.59
java 17705 R 202,1 5849560 4096 16.48
监督 3055 W 202,1 12862528 4096 5.56
爪哇 17705 R 202,1 5882792 4096 6.31
java 17705 R 202,1 5882984 40960 17.79
[…]
这显示了每个块设备 I/O（磁盘 I/O）的一行摘要。这就像磁盘的 tcpdump。
这是具有旋转磁盘的系统上的随机 I/O 工作负载：
COMM PID 类型 DEV BLOCK BYTES LATms
randread 6199 R 202,16 71136208 8192 5.32
randread 6199 R 202,16 83134400 8192 9.26
randread 6199 R 202,16 88477928 8192 3.46
randread 6199 R 202,16 66953696 8192 10.69
randread 6199 R 202,16 87832704 8192 3.68
randread 6199 R 202,16 74963120 8192 4.62
[…]
请注意随机磁盘位置 (BLOCK)，它导致延迟（I/O 时间）在 3 到 10 毫秒之间。
在 SSD 上运行相同的工作负载：
COMM PID 类型 DEV BLOCK BYTES LATms
randread 20125 R 202,16 24803976 8192 0.15
randread 20125 R 202,32 17527272 8192 0.15
randread 20125 R 202,16 13382360 8192 0.15
randread 20125 R 202,32 29727160 8192 0.19
randread 20125 R 202,32 26965272 8192 0.18
randread 20125 R 202,32 27222376 8192 0.17
[…]
太好了，延迟好多了！
在这篇文章中，我将总结 iosnoop(8) 选项和用法，提供一个调试延迟异常值的示例，并讨论注意事项、工具内部结构、开销以及我写这篇文章的原因。
选项
USAGE 消息总结了这些内容（还有一个手册页和示例文件）：
./iosnoop -h
用法：iosnoop [-hQst] [-d 设备] [-i iotype] [-p PID] [-n 名称]
[期间]
-d device # 设备字符串（例如，“202,1）
-i iotype # 匹配类型（例如，‘R’ 用于所有读取）
-n name # 在 I/O 问题上匹配的进程名称
-p PID # 匹配 I/O 问题的 PID
-Q # 使用队列插入作为开始时间
-s # 包含 I/O 的开始时间 (s)
-t # 包含 I/O 的完成时间 (s)
-h # 这个用法信息
duration # duration 秒，并使用缓冲区
例如，
iosnoop # 实时观察块 I/O（无缓冲）
iosnoop 1 # 跟踪 1 秒（缓冲）
iosnoop -Q # 在 LATms 中包含排队时间
iosnoop -ts # 包括开始和结束时间戳
iosnoop -i ‘R’ # 跟踪读取
iosnoop -p 91 # 显示当 PID 91 在 CPU 上时发出的 I/O
iosnoop -Qp 91 # 显示按 PID 91 排队的 I/O，排队时间
有关更多信息，请参见手册页和示例文件。
在 R 或 gnuplot 中对输出进行后处理时，或者用于挖掘更难的问题（包括延迟异常值）时，我使用 -s 和 -t 选项。
延迟异常值
我在 SSD 服务器（这是一个 AWS EC2 实例）上的 randread 程序通常会遇到大约 0.15 毫秒的 I/O 延迟，但也有一些异常值高达 20 毫秒。这是一段摘录：
./iosnoop -ts > 输出
更多
跟踪块 I/O。 Ctrl-C 结束。
STARTs ENDs COMM PID TYPE DEV BLOCK BYTES LATms
6037559.121523 6037559.121685 randread 22341 R 202,32 29295416 8192 0.16
6037559.121719 6037559.121874 randread 22341 R 202,16 27515304 8192 0.16
[…]
6037595.999508 6037596.000051 监督 1692 W 202,1 12862968 4096 0.54
6037595.999513 6037596.000144 监督 1687 W 202,1 17040160 4096 0.63
6037595.999634 6037596.000309 监督 1693 W 202,1 17040168 4096 0.68
6037595.999937 6037596.000440 监督 1693 W 202,1 17040176 4096 0.50
6037596.000579 6037596.001192 监督 1689 W 202,1 17040184 4096 0.61
6037596.000826 6037596.001360 监管 1689 W 202,1 17040192 4096 0.53
6037595.998302 6037596.018133 randread 22341 R 202,32 954168 8192 20.03
6037595.998303 6037596.018150 randread 22341 R 202,32 954200 8192 20.05
6037596.018182 6037596.018347 randread 22341 R 202,32 18836600 8192 0.16
[…]
对 I/O 完成时间 (END) 进行排序很重要。在这种情况下，它已经处于正确的顺序。
所以我的 20 毫秒读取发生在完成一大组监督写入之后（我截断了几十条监督写入行以保持这个例子的简短）。此输出文件中的其他延迟异常值显示了相同的顺序：一批写入后读取缓慢。
请注意 I/O 请求时间戳 (STARTs)，它表明这 20 毫秒的读取是在监督写入之前发出的——因此它们一直处于队列中。我之前已经多次调试过此类问题，但这次不同：这些写入是针对不同的设备 (202,1)，所以我会假设它们会在不同的队列中，并且不会干扰每个其他。在这个系统（Xen 来宾）的某个地方，看起来好像有一个共享队列。 （刚刚使用 iosnoop 发现了这一点，我还不能告诉你是哪个队列，但我希望在识别它之后有一种方法可以调整它的排队行为，这样我们就可以消除或降低这些异常值的严重性. 更新：见评论。）
虽然输出包含 COMM 和 PID 列，如手册页中所述，但您应该将这些（以及 -p 和 -n 选项）视为尽力而为。
通信和 PID
就像我原来的 iosnoop 工具一样，COMM 和 PID 列显示发出 I/O 时谁在 CPU 上，这通常是发出它的任务，但可能无关。我在高写入负载下驱动了一个系统，并开始看到如下条目：
COMM PID 类型 DEV BLOCK BYTES LATms
awk 6179 W 202,16 597439928 4096 73.86
sshd 2357 W 202,16 597448128 4096 73.94
awk 6179 W 202,16 597456328 4096 73.94
awk 6179 W 202,16 597464528 4096 74.08
awk 6179 W 202,16 597472728 4096 74.30
awk 6179 W 202,16 597480928 4096 74.91
sshd 2357 W 202,16 597489128 4096 74.19
awk 6179 W 202,16 597497328 4096 74.94
[…]
好吧，虽然 awk 和 sshd 在 CPU 上，但不太可能是 I/O 的来源。这可能会产生误导。
我在发出块 I/O 时捕获了堆栈跟踪（使用 perf_events）来为您找到一个示例。大多数堆栈都显示了正确的过程，但这里有一个显示 awk ：
awk 11774 [000] 3495819.879203：block:block_rq_issue: 202,16 W 0 () 19337224 + 256 [awk]
ffffffff8133c980 blk_peek_request ([kernel.kallsyms])
ffffffff8149d114 do_blkif_request ([kernel.kallsyms])
ffffffff81336377 __blk_run_queue ([kernel.kallsyms])
ffffffff813364ad blk_start_queue ([kernel.kallsyms])
ffffffff8149d9f5 kick_pending_request_queues ([kernel.kallsyms])
ffffffff8149dd86 blkif_interrupt ([kernel.kallsyms])
ffffffff810c258d handle_irq_event_percpu ([kernel.kallsyms])
ffffffff810c2788 handle_irq_event ([kernel.kallsyms])
ffffffff810c50a7 handle_edge_irq ([kernel.kallsyms])
ffffffff81421764 evtchn_2l_handle_events ([kernel.kallsyms])
ffffffff8141f210 __xen_evtchn_do_upcall ([kernel.kallsyms])
ffffffff81420e1f xen_evtchn_do_upcall ([kernel.kallsyms])
ffffffff81709f3e xen_do_hypervisor_callback ([kernel.kallsyms])
7f8e91ff2b1a __brk (/lib/x86_64-linux-gnu/libc-2.15.so)
awk 正在执行 brk() 系统调用，这可能是它扩展堆时的正常行为。由于这是一个 AWS EC2 Xen 来宾，它执行一个超级调用 (xen_do_hypervisor_callback) 以优化内存操作。这恰好调用了 kick_pending_request_queues()，以发出更多已经排队的工作，它调用 _blk_run_queue()，导致发出可能被另一个进程排队的块 I/O。
我可以通过向上跟踪堆栈来获取原始 PID，尽管最好将 iosnoop 保留为简单的块设备级跟踪器。我还可以挖掘出与此 I/O 相关的文件系统路径名（如果有）。我早期的 iosnoop 版本做到了这一点，但是（如 PID 和 COMM）它不可靠，并且取决于文件系统类型。带有 ZFS 的 iosnoop 目前无法真正获得文件名，但在 OS X 上使用 HFS+ 时，它确实可以获得部分路径名，这非常有用。
更新：我在 iosnoop 中添加了一个 -Q 选项，它使用块队列插入作为起始跟踪点，而不是块 I/O 问题。这提供了包括块 I/O 排队的时间，以分析排队和负载问题。但它也提高了 PID 和 COMM 列的准确性，因为原始进程在插入队列时更有可能仍在 CPU 上。我很想同时跟踪插入和发出跟踪点，这样我就可以一次完成所有操作——更好的 PID 和 COMM，并分别显示 I/O 排队时间和设备时间——但这会花费更多开销. （当 Linux 内核具有增强的跟踪框架时，我会这样做，而且我可以更便宜地做到这一点