~$ sudo trace-cmd record -p function --func-stack -l generic_make_request dd if=/dev/zero of=test-f1 count=1 oflag=direct
~$ trace-cmd report
CPU 1 is empty
CPU 2 is empty
CPU 3 is empty
cpus=4
dd-18614 [000] 919057.409071: function: generic_make_request
dd-18614 [000] 919057.409098: kernel_stack: <stack trace>
=> generic_make_request (ffffffff8f58c5b5)
=> submit_bio (ffffffff8f58c9f5)
=> do_blockdev_direct_IO (ffffffff8f4ac84d)
=> ext4_direct_IO (ffffffffc094b2f9)
=> generic_file_direct_write (ffffffff8f3c8e86)
=> __generic_file_write_iter (ffffffff8f3c9007)
=> ext4_file_write_iter (ffffffffc09368d6)
=> new_sync_write (ffffffff8f464d9b)
=> vfs_write (ffffffff8f467cb5)
=> ksys_write (ffffffff8f467f57)
=> do_syscall_64 (ffffffff8f204183)
=> entry_SYSCALL_64_after_hwframe (ffffffff8fa00088)
dd-18614 [000] 919057.409122: function: generic_make_request
dd-18614 [000] 919057.409136: kernel_stack: <stack trace>
=> generic_make_request (ffffffff8f58c5b5)
=> blk_queue_split (ffffffff8f5933fd)
=> blk_mq_make_request (ffffffff8f599aa6)
=> generic_make_request (ffffffff8f58c754)
=> submit_bio (ffffffff8f58c9f5)
=> do_blockdev_direct_IO (ffffffff8f4ac84d)
=> ext4_direct_IO (ffffffffc094b2f9)
=> generic_file_direct_write (ffffffff8f3c8e86)
=> __generic_file_write_iter (ffffffff8f3c9007)
=> ext4_file_write_iter (ffffffffc09368d6)
=> new_sync_write (ffffffff8f464d9b)
=> vfs_write (ffffffff8f467cb5)
=> ksys_write (ffffffff8f467f57)
=> do_syscall_64 (ffffffff8f204183)
=> entry_SYSCALL_64_after_hwframe (ffffffff8fa00088)
~$ sudo trace-cmd record -p function_graph -g generic_make_request dd if=/dev/zero of=test-f1 count=1 oflag=direct
CPU 0 is empty
CPU 1 is empty
CPU 2 is empty
cpus=4
dd-25500 [003] 919560.299850: funcgraph_entry: | generic_make_request() {
dd-25500 [003] 919560.299852: funcgraph_entry: | smp_irq_work_interrupt() {
dd-25500 [003] 919560.299852: funcgraph_entry: | irq_enter() {
dd-25500 [003] 919560.299852: funcgraph_entry: | rcu_irq_enter() {
dd-25500 [003] 919560.299853: funcgraph_entry: 0.153 us | rcu_nmi_enter();
dd-25500 [003] 919560.299853: funcgraph_exit: 0.525 us | }
dd-25500 [003] 919560.299853: funcgraph_exit: 0.818 us | }
dd-25500 [003] 919560.299853: funcgraph_entry: | __wake_up() {
dd-25500 [003] 919560.299853: funcgraph_entry: | __wake_up_common_lock() {
dd-25500 [003] 919560.299854: funcgraph_entry: 0.127 us | _raw_spin_lock_irqsave();
dd-25500 [003] 919560.299854: funcgraph_entry: 0.143 us | __wake_up_common();
dd-25500 [003] 919560.299854: funcgraph_entry: 0.146 us | _raw_spin_unlock_irqrestore();
dd-25500 [003] 919560.299854: funcgraph_exit: 0.934 us | }
dd-25500 [003] 919560.299855: funcgraph_exit: 1.193 us | }
dd-25500 [003] 919560.299855: funcgraph_entry: | __wake_up() {
dd-25500 [003] 919560.299855: funcgraph_entry: | __wake_up_common_lock() {
dd-25500 [003] 919560.299855: funcgraph_entry: 0.128 us | _raw_spin_lock_irqsave();
dd-25500 [003] 919560.299855: funcgraph_entry: | __wake_up_common() {
dd-25500 [003] 919560.299855: funcgraph_entry: | autoremove_wake_function() {
dd-25500 [003] 919560.299856: funcgraph_entry: | default_wake_function() {
dd-25500 [003] 919560.299856: funcgraph_entry: | try_to_wake_up() {
dd-25500 [003] 919560.299856: funcgraph_entry: 0.162 us | _raw_spin_lock_irqsave();
dd-25500 [003] 919560.299856: funcgraph_entry: | select_task_rq_fair() {
dd-25500 [003] 919560.299856: funcgraph_entry: 0.125 us | available_idle_cpu();
dd-25500 [003] 919560.299857: funcgraph_entry: 0.192 us | update_cfs_rq_h_load();
dd-25500 [003] 919560.299857: funcgraph_entry: | select_idle_sibling() {
dd-25500 [003] 919560.299857: funcgraph_entry: 0.149 us | available_idle_cpu();
dd-25500 [003] 919560.299857: funcgraph_exit: 0.400 us | }
dd-25500 [003] 919560.299858: funcgraph_exit: 1.411 us | }
...