linux - 使用 perf 确定进程何时以及为何进入不间断 sleep

Question

我正在玩 perf 以了解如何找出进程进入“D”(不间断 sleep )状态的原因。

我正在使用 perf 命令:

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

4710 是我的进程 meetmaker 的 pid。

然后我正在查看 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 跟踪此类状态转换。

然而，没有神奇的规则。您必须分别调查每个地方。