Created a new tool (WIP) That gives the output of something like this:
Total: 0.410332
Max: 0.117048
Min: 0.015632
Avg: 0.041033
Count: 10
State: D
==> trace_event_raw_event_sched_switch+0xec
==> __traceiter_sched_switch+0x41
==> __schedule+0x4d3
==> schedule+0x5d
==> io_schedule+0x42
==> bit_wait_io+0xd
==> __wait_on_bit+0x4b
==> out_of_line_wait_on_bit+0x81
==> jbd2_journal_commit_transaction+0x15f1
==> kjournald2+0xa3
==> kthread+0xe9
==> ret_from_fork+0x22
Wakeup:
==> trace_event_raw_event_sched_wakeup_template+0x5f
==> try_to_wake_up+0x2e8
==> wake_bit_function+0x39
==> __wake_up_common+0x76
==> __wake_up_common_lock+0x6a
==> wake_up_bit+0x71
==> end_bio_bh_io_sync+0x26
==> clone_endio+0x103
==> blk_update_request+0x110
==> blk_mq_end_request+0x1a
==> blk_flush_complete_seq+0x15a
==> flush_end_io+0x1cf
==> scsi_end_request+0xdd
==> scsi_io_completion+0x46
==> blk_complete_reqs+0x40
==> __do_softirq+0x135
That shows the stack traces of all the places that were scheduled out in a S or D state and where it was woken up. Giving the total time of all instances of this location, as well as max, min, and average. And the number of times it was hit. There’s a surprising little number of these stacks.
Here’s the code. It depends on libtracefs 1.6.1.