使用 perf 找出进程何时以及为何进入不间断睡眠

Question

我正在玩 perf 来了解如何找出进程进入“D”（不间断睡眠）状态的原因。

我正在使用 perf 命令：

perf record -g -p 4710 -e sched:sched_stat_iowait,sched:sched_stat_blocked sleep 60

4710 是我的进程的 pid，称为 meetmaker。

然后我正在查看perf script 的输出

meetmaker-3.0.0  4710 [008] 19187729.668851: sched:sched_stat_iowait: comm=jbd2/dm-2-8 pid=697 delay=120641 [ns]
        ffffffff810a08a0 enqueue_sleeper ([kernel.kallsyms])
        ffffffff810a08a0 enqueue_sleeper ([kernel.kallsyms])
        ffffffff810a756a enqueue_entity ([kernel.kallsyms])
        ffffffff810a7e83 enqueue_task_fair ([kernel.kallsyms])
        ffffffff810967b1 ttwu_activate ([kernel.kallsyms])
        ffffffff81096983 ttwu_do_activate ([kernel.kallsyms])
        ffffffff8109819a ttwu_queue ([kernel.kallsyms])
        ffffffff810983fe try_to_wake_up ([kernel.kallsyms])
        ffffffff810ada66 autoremove_wake_function ([kernel.kallsyms])
        ffffffff810ad8fa __wake_up_common ([kernel.kallsyms])
        ffffffff810addb8 __wake_up ([kernel.kallsyms])
        ffffffff810ade11 __wake_up_bit ([kernel.kallsyms])
        ffffffff81260fcb ext4_finish_bio ([kernel.kallsyms])
        ffffffff812617df ext4_end_bio ([kernel.kallsyms])
        ffffffff8131b433 blk_update_request ([kernel.kallsyms])
        ffffffff8131b5b7 blk_update_bidi_request ([kernel.kallsyms])
        ffffffff8131c9af blk_end_bidi_request ([kernel.kallsyms])
        ffffffff8148f1f0 scsi_io_completion ([kernel.kallsyms])
        ffffffff813263bb blk_done_softirq ([kernel.kallsyms])
        ffffffff8106af9c __do_softirq ([kernel.kallsyms])
        ffffffff8106b1e5 irq_exit ([kernel.kallsyms])
        ffffffff816399fa do_IRQ ([kernel.kallsyms])
        ffffffff8163796d ret_from_intr ([kernel.kallsyms])
                  487f77 [unknown] ([unknown])
                  487f77 meetmaker__user_counters_get (/local/meetmaker/bin/meetmaker-3.0.0_2724)
                  505cff gpbrpc_exec (/local/meetmaker/bin/meetmaker-3.0.0_2724)
                  4eb45c ipc_game_loop (/local/meetmaker/bin/meetmaker-3.0.0_2724)
                  4ed48a game (/local/meetmaker/bin/meetmaker-3.0.0_2724)
                  48ebe3 service_late_init (/local/meetmaker/bin/meetmaker-3.0.0_2724)
                  47371a main (/local/meetmaker/bin/meetmaker-3.0.0_2724)
            7fd3cc391c36 __libc_start_main (/lib64/libc-2.11.3.so)

meetmaker-3.0.0  4710 [008] 19187729.668886: sched:sched_stat_blocked: comm=jbd2/dm-2-8 pid=697 delay=120641 [ns]
        ffffffff810a08d8 enqueue_sleeper ([kernel.kallsyms])
        ffffffff810a08d8 enqueue_sleeper ([kernel.kallsyms])
        ffffffff810a756a enqueue_entity ([kernel.kallsyms])
        ffffffff810a7e83 enqueue_task_fair ([kernel.kallsyms])
        ffffffff810967b1 ttwu_activate ([kernel.kallsyms])
        ffffffff81096983 ttwu_do_activate ([kernel.kallsyms])
        ffffffff8109819a ttwu_queue ([kernel.kallsyms])
        ffffffff810983fe try_to_wake_up ([kernel.kallsyms])
        ffffffff810ada66 autoremove_wake_function ([kernel.kallsyms])
        ffffffff810ad8fa __wake_up_common ([kernel.kallsyms])
        ffffffff810addb8 __wake_up ([kernel.kallsyms])
        ffffffff810ade11 __wake_up_bit ([kernel.kallsyms])
        ffffffff81260fcb ext4_finish_bio ([kernel.kallsyms])
        ffffffff812617df ext4_end_bio ([kernel.kallsyms])
        ffffffff8131b433 blk_update_request ([kernel.kallsyms])
        ffffffff8131b5b7 blk_update_bidi_request ([kernel.kallsyms])
        ffffffff8131c9af blk_end_bidi_request ([kernel.kallsyms])
        ffffffff8148f1f0 scsi_io_completion ([kernel.kallsyms])
        ffffffff813263bb blk_done_softirq ([kernel.kallsyms])
        ffffffff8106af9c __do_softirq ([kernel.kallsyms])
        ffffffff8106b1e5 irq_exit ([kernel.kallsyms])
        ffffffff816399fa do_IRQ ([kernel.kallsyms])
        ffffffff8163796d ret_from_intr ([kernel.kallsyms])
                  487f77 [unknown] ([unknown])
                  487f77 meetmaker__user_counters_get (/local/meetmaker/bin/meetmaker-3.0.0_2724)
                  505cff gpbrpc_exec (/local/meetmaker/bin/meetmaker-3.0.0_2724)
                  4eb45c ipc_game_loop (/local/meetmaker/bin/meetmaker-3.0.0_2724)
                  4ed48a game (/local/meetmaker/bin/meetmaker-3.0.0_2724)
                  48ebe3 service_late_init (/local/meetmaker/bin/meetmaker-3.0.0_2724)
                  47371a main (/local/meetmaker/bin/meetmaker-3.0.0_2724)
            7fd3cc391c36 __libc_start_main (/lib64/libc-2.11.3.so)

据我了解这个 perf 输出，它是处于 D 状态的 jbd 内核线程，它抢占了我的 meetmaker 进程。不是meetmaker进程进入了D状态吧？

所以这不是我要找的。尽管我给 perf 提供了 -p 参数，但它给了我另一个我不感兴趣的过程。

我说的对吗？

这是找出任何特定进程何时以及为何进入“D”状态的最佳方法吗？

Answer 1

perf 在这里是错误的工具。您可以使用 systemtap 跟踪此类状态转换。

但是，没有神奇的规则。你必须分别调查每个地方。

Answer 2

D 状态是当某些内核进程必须等待某些肯定会发生的驱动程序事件并且不能接受信号时进入的内核状态（即使是不可忽略的信号，例如 SIGKILL 或 SIGSTOP） .信号通常会脱离正常的程序流程，因此它在用户空间中很常见（作为用户，您希望能够中断您的程序），但在内核空间中有一些进程（与驱动程序工作相关）会引导驱动程序如果允许被中断，则数据处于不稳定状态（假设您对某个设备进行了编程以中断您并且您不在那里确认中断。您将获得设备锁定），因此内核具有此状态（D代表Driver state？有人可以确认吗？）。假设您正在读取一些磁盘数据，并且您已经对控制器芯片进行了编程以中断您，您必须等待磁盘将所有块数据传输到内核缓冲区并中断您。中断肯定会在几毫秒或几微秒内出现……但如果你在中间中断进程，就没有进程唤醒，没有任何东西可以确认设备中断，设备将被阻塞。 D 状态依赖于驱动程序。内核在进入驱动程序代码（驱动程序编写者专门调用 wait__non_interruptable 函数来获取它）以执行某些特定任务时，在持久操作上进入此状态。

因此，它是不可中断的，您必须等待它自行退出。这意味着您无论如何都无法从用户空间终止该进程，并且其中一个锁定您的系统通常意味着一些驱动程序错误。