NAME
trace-cmd-profile - profile tasks running liveSYNOPSIS
trace-cmd profile [OPTIONS] [command]DESCRIPTION
The trace-cmd(1) profile will start tracing just like trace-cmd-record(1), with the --profile option, except that it does not write to a file, but instead, it will read the events as they happen and will update the accounting of the events. When the trace is finished, it will report the results just like trace-cmd-report(1) would do with its --profile option. In other words, the profile command does the work of trace-cmd record --profile, and trace-cmd report --profile without having to record the data to disk, in between.OPTIONS
These are the same as trace-cmd-record(1) with the --profile option. -p tracerSet a tracer plugin to run instead of function
graph tracing set to depth of 1. To not run any tracer, use -p
nop.
-S
Only enable the tracer or events speficied on
the command line. With this option, the function_graph tracer is not enabled,
nor are any events (like sched_switch), unless they are specifically specified
on the command line (i.e. -p function -e sched_switch -e sched_wakeup)
-G
Set interrupt (soft and hard) events as global
(associated to CPU instead of tasks).
-o file
Write the output of the profile to
file. This supersedes --stderr
-H event-hooks
Add custom event matching to connect any two
events together. Format is:
[<start_system>:]<start_event>,<start_match>[,<start_pid>]/
[<end_system>:]<end_event>,<end_match>[,<flags>]
--stderr
The start_system:start_event (start_system is optional), is the event that starts the timing.
start_match is the field in the start event that is to match with the end_match in the end event.
start_pid is optional, as matches are attached to the tasks that run the events, if another field should be used to find that task, then it is specified with start_pid.
end_system:end_event is the event that ends the timing (end_system is optional).
end_match is the field in end_match that wil match the start event field start_match.
flags are optional and can be the following (case insensitive):
p : The two events are pinned to the same CPU (start and end happen on the same CPU always).
s : The event should have a stack traced with it (enable stack tracing for the start event).
g : The event is global (not associated to a task). start_pid is not applicable with this flag.
Redirect the output to stderr. The output of
the command being executed is not changed. This allows watching the command
execute and saving the output of the profile to another file.
--verbose[=level]
Set the log level. Supported log levels are
"none", "critical", "error",
"warning", "info", "debug", "all" or
their identifiers "0", "1", "2", "3",
"4", "5", "6". Setting the log level to specific
value enables all logs from that and all previous levels. The level will
default to "info" if one is not specified.
Example: enable all critical, error and warning logs
trace-cmd profile --verbose=warning
EXAMPLES
--- # trace-cmd profile -F sleep 1 [..] task: sleep-1121 Event: sched_switch:R (2) Total: 234559 Avg: 117279 Max: 129886 Min:104673 | + ftrace_raw_event_sched_switch (0xffffffff8109f310) 100% (2) time:234559 max:129886 min:104673 avg:117279 __schedule (0xffffffff816c1e81) preempt_schedule (0xffffffff816c236e) ___preempt_schedule (0xffffffff81351a59) | + unmap_single_vma (0xffffffff81198c05) | 55% (1) time:129886 max:129886 min:0 avg:129886 | stop_one_cpu (0xffffffff8110909a) | sched_exec (0xffffffff810a119b) | do_execveat_common.isra.31 (0xffffffff811de528) | do_execve (0xffffffff811dea8c) | SyS_execve (0xffffffff811ded1e) | return_to_handler (0xffffffff816c8458) | stub_execve (0xffffffff816c6929) | + unmap_single_vma (0xffffffff81198c05) 45% (1) time:104673 max:104673 min:0 avg:104673 unmap_vmas (0xffffffff81199174) exit_mmap (0xffffffff811a1f5b) mmput (0xffffffff8107699a) flush_old_exec (0xffffffff811ddb75) load_elf_binary (0xffffffff812287df) search_binary_handler (0xffffffff811dd3e0) do_execveat_common.isra.31 (0xffffffff811de8bd) do_execve (0xffffffff811dea8c) SyS_execve (0xffffffff811ded1e) return_to_handler (0xffffffff816c8458) stub_execve (0xffffffff816c6929)
Event: sched_switch:S (1) Total: 1000513242 Avg: 1000513242 Max: 1000513242 Min:1000513242 | + ftrace_raw_event_sched_switch (0xffffffff8109f310) 100% (1) time:1000513242 max:1000513242 min:0 avg:1000513242 __schedule (0xffffffff816c1e81) schedule (0xffffffff816c23b9) do_nanosleep (0xffffffff816c4f1c) hrtimer_nanosleep (0xffffffff810dcd86) SyS_nanosleep (0xffffffff810dcea6) return_to_handler (0xffffffff816c8458) tracesys_phase2 (0xffffffff816c65b0)
Event: sched_wakeup:1121 (1) Total: 43405 Avg: 43405 Max: 43405 Min:43405 | + ftrace_raw_event_sched_wakeup_template (0xffffffff8109d960) 100% (1) time:43405 max:43405 min:0 avg:43405 ttwu_do_wakeup (0xffffffff810a01a2) ttwu_do_activate.constprop.122 (0xffffffff810a0236) try_to_wake_up (0xffffffff810a3ec3) wake_up_process (0xffffffff810a4057) hrtimer_wakeup (0xffffffff810db772) __run_hrtimer (0xffffffff810dbd91) hrtimer_interrupt (0xffffffff810dc6b7) local_apic_timer_interrupt (0xffffffff810363e7) smp_trace_apic_timer_interrupt (0xffffffff816c8c6a) trace_apic_timer_interrupt (0xffffffff816c725a) finish_task_switch (0xffffffff8109c3a4) __schedule (0xffffffff816c1e01) schedule (0xffffffff816c23b9) ring_buffer_wait (0xffffffff811323a3) wait_on_pipe (0xffffffff81133d93) tracing_buffers_splice_read (0xffffffff811350b0) do_splice_to (0xffffffff8120476f) SyS_splice (0xffffffff81206c1f) tracesys_phase2 (0xffffffff816c65b0)
Event: func: sys_nanosleep() (1) Total: 1000598016 Avg: 1000598016 Max: 1000598016 Min:1000598016 Event: func: sys_munmap() (1) Total: 14300 Avg: 14300 Max: 14300 Min:14300 Event: func: sys_arch_prctl() (1) Total: 571 Avg: 571 Max: 571 Min:571 Event: func: sys_mprotect() (4) Total: 14382 Avg: 3595 Max: 7196 Min:2190 Event: func: SyS_read() (1) Total: 2640 Avg: 2640 Max: 2640 Min:2640 Event: func: sys_close() (5) Total: 4001 Avg: 800 Max: 1252 Min:414 Event: func: sys_newfstat() (3) Total: 11684 Avg: 3894 Max: 10206 Min:636 Event: func: SyS_open() (3) Total: 23615 Avg: 7871 Max: 10535 Min:4743 Event: func: sys_access() (1) Total: 5924 Avg: 5924 Max: 5924 Min:5924 Event: func: SyS_mmap() (8) Total: 39153 Avg: 4894 Max: 12354 Min:1518 Event: func: smp_trace_apic_timer_interrupt() (1) Total: 10298 Avg: 10298 Max: 10298 Min:10298 Event: func: SyS_brk() (4) Total: 2407 Avg: 601 Max: 1564 Min:206 Event: func: do_notify_resume() (2) Total: 4095 Avg: 2047 Max: 2521 Min:1574 Event: func: sys_execve() (5) Total: 1625251 Avg: 325050 Max: 1605698 Min:3570 | + ftrace_raw_event_sched_wakeup_template (0xffffffff8109d960) 100% (1) time:1605698 max:1605698 min:0 avg:1605698 ttwu_do_wakeup (0xffffffff810a01a2) ttwu_do_activate.constprop.122 (0xffffffff810a0236) try_to_wake_up (0xffffffff810a3ec3) wake_up_process (0xffffffff810a4057) cpu_stop_queue_work (0xffffffff81108df8) stop_one_cpu (0xffffffff8110909a) sched_exec (0xffffffff810a119b) do_execveat_common.isra.31 (0xffffffff811de528) do_execve (0xffffffff811dea8c) SyS_execve (0xffffffff811ded1e) return_to_handler (0xffffffff816c8458) stub_execve (0xffffffff816c6929) stub_execve (0xffffffff816c6929)
Event: func: syscall_trace_enter_phase2() (38) Total: 21544 Avg: 566 Max: 1066 Min:329 Event: func: syscall_trace_enter_phase1() (38) Total: 9202 Avg: 242 Max: 376 Min:150 Event: func: __do_page_fault() (53) Total: 257672 Avg: 4861 Max: 27745 Min:458 | + ftrace_raw_event_sched_wakeup_template (0xffffffff8109d960) 100% (1) time:27745 max:27745 min:0 avg:27745 ttwu_do_wakeup (0xffffffff810a01a2) ttwu_do_activate.constprop.122 (0xffffffff810a0236) try_to_wake_up (0xffffffff810a3ec3) default_wake_function (0xffffffff810a4002) autoremove_wake_function (0xffffffff810b50fd) __wake_up_common (0xffffffff810b4958) __wake_up (0xffffffff810b4cb8) rb_wake_up_waiters (0xffffffff8112f126) irq_work_run_list (0xffffffff81157d0f) irq_work_run (0xffffffff81157d5e) smp_trace_irq_work_interrupt (0xffffffff810082fc) trace_irq_work_interrupt (0xffffffff816c7aaa) return_to_handler (0xffffffff816c8458) trace_do_page_fault (0xffffffff810478b2) trace_page_fault (0xffffffff816c7dd2)
Event: func: syscall_trace_leave() (38) Total: 26145 Avg: 688 Max: 1264 Min:381 Event: func: __sb_end_write() (1) Total: 373 Avg: 373 Max: 373 Min:373 Event: func: fsnotify() (1) Total: 598 Avg: 598 Max: 598 Min:598 Event: func: __fsnotify_parent() (1) Total: 286 Avg: 286 Max: 286 Min:286 Event: func: mutex_unlock() (2) Total: 39636 Avg: 19818 Max: 39413 Min:223 Event: func: smp_trace_irq_work_interrupt() (6) Total: 236459 Avg: 39409 Max: 100671 Min:634 | + ftrace_raw_event_sched_wakeup_template (0xffffffff8109d960) 100% (4) time:234348 max:100671 min:38745 avg:58587 ttwu_do_wakeup (0xffffffff810a01a2) ttwu_do_activate.constprop.122 (0xffffffff810a0236) try_to_wake_up (0xffffffff810a3ec3) default_wake_function (0xffffffff810a4002) autoremove_wake_function (0xffffffff810b50fd) __wake_up_common (0xffffffff810b4958) __wake_up (0xffffffff810b4cb8) rb_wake_up_waiters (0xffffffff8112f126) irq_work_run_list (0xffffffff81157d0f) irq_work_run (0xffffffff81157d5e) smp_trace_irq_work_interrupt (0xffffffff810082fc) return_to_handler (0xffffffff816c8458) trace_irq_work_interrupt (0xffffffff816c7aaa) | + ftrace_return_to_handler (0xffffffff81140840) | 84% (3) time:197396 max:100671 min:38745 avg:65798 | return_to_handler (0xffffffff816c846d) | trace_page_fault (0xffffffff816c7dd2) | + ftrace_return_to_handler (0xffffffff81140840) 16% (1) time:36952 max:36952 min:0 avg:36952 ftrace_graph_caller (0xffffffff816c8428) mutex_unlock (0xffffffff816c3f75) rb_simple_write (0xffffffff81133142) vfs_write (0xffffffff811d7727) SyS_write (0xffffffff811d7acf) tracesys_phase2 (0xffffffff816c65b0)
Event: sys_enter:35 (1) Total: 1000599765 Avg: 1000599765 Max: 1000599765 Min:1000599765 Event: sys_enter:11 (1) Total: 55025 Avg: 55025 Max: 55025 Min:55025 Event: sys_enter:158 (1) Total: 1584 Avg: 1584 Max: 1584 Min:1584 Event: sys_enter:10 (4) Total: 18359 Avg: 4589 Max: 8764 Min:2933 Event: sys_enter:0 (1) Total: 4223 Avg: 4223 Max: 4223 Min:4223 Event: sys_enter:3 (5) Total: 9948 Avg: 1989 Max: 2606 Min:1203 Event: sys_enter:5 (3) Total: 15530 Avg: 5176 Max: 11840 Min:1405 Event: sys_enter:2 (3) Total: 28002 Avg: 9334 Max: 12035 Min:5656 Event: sys_enter:21 (1) Total: 7814 Avg: 7814 Max: 7814 Min:7814 Event: sys_enter:9 (8) Total: 49583 Avg: 6197 Max: 14137 Min:2362 Event: sys_enter:12 (4) Total: 108493 Avg: 27123 Max: 104079 Min:922 Event: sys_enter:59 (5) Total: 1631608 Avg: 326321 Max: 1607529 Min:4563 Event: page_fault_user:0x398d86b630 (1) Event: page_fault_user:0x398d844de0 (1) Event: page_fault_user:0x398d8d9020 (1) Event: page_fault_user:0x1d37008 (1) Event: page_fault_user:0x7f0b89e91074 (1) Event: page_fault_user:0x7f0b89d98ed0 (1) Event: page_fault_user:0x7f0b89ec8950 (1) Event: page_fault_user:0x7f0b89d83644 (1) Event: page_fault_user:0x7f0b89d622a8 (1) Event: page_fault_user:0x7f0b89d5a560 (1) Event: page_fault_user:0x7f0b89d34010 (1) Event: page_fault_user:0x1d36008 (1) Event: page_fault_user:0x398d900510 (1) Event: page_fault_user:0x398dbb3ae8 (1) Event: page_fault_user:0x398d87f490 (1) Event: page_fault_user:0x398d8eb660 (1) Event: page_fault_user:0x398d8bd730 (1) Event: page_fault_user:0x398d9625d9 (1) Event: page_fault_user:0x398d931810 (1) Event: page_fault_user:0x398dbb7114 (1) Event: page_fault_user:0x398d837610 (1) Event: page_fault_user:0x398d89e860 (1) Event: page_fault_user:0x398d8f23b0 (1) Event: page_fault_user:0x398dbb4510 (1) Event: page_fault_user:0x398dbad6f0 (1) Event: page_fault_user:0x398dbb1018 (1) Event: page_fault_user:0x398d977b37 (1) Event: page_fault_user:0x398d92eb60 (1) Event: page_fault_user:0x398d8abff0 (1) Event: page_fault_user:0x398dbb0d30 (1) Event: page_fault_user:0x398dbb6c24 (1) Event: page_fault_user:0x398d821c50 (1) Event: page_fault_user:0x398dbb6c20 (1) Event: page_fault_user:0x398d886350 (1) Event: page_fault_user:0x7f0b90125000 (1) Event: page_fault_user:0x7f0b90124740 (1) Event: page_fault_user:0x7f0b90126000 (1) Event: page_fault_user:0x398d816230 (1) Event: page_fault_user:0x398d8002b8 (1) Event: page_fault_user:0x398dbb0b40 (1) Event: page_fault_user:0x398dbb2880 (1) Event: page_fault_user:0x7f0b90141cc6 (1) Event: page_fault_user:0x7f0b9013b85c (1) Event: page_fault_user:0x7f0b90127000 (1) Event: page_fault_user:0x606e70 (1) Event: page_fault_user:0x7f0b90144010 (1) Event: page_fault_user:0x7fffcb31b038 (1) Event: page_fault_user:0x606da8 (1) Event: page_fault_user:0x400040 (1) Event: page_fault_user:0x398d222218 (1) Event: page_fault_user:0x398d015120 (1) Event: page_fault_user:0x398d220ce8 (1) Event: page_fault_user:0x398d220b80 (1) Event: page_fault_user:0x7fffcb2fcff8 (1) Event: page_fault_user:0x398d001590 (1) Event: page_fault_user:0x398d838490 (1) Event: softirq_raise:RCU (3) Total: 252931 Avg: 84310 Max: 243288 Min:4639 Event: softirq_raise:SCHED (2) Total: 241249 Avg: 120624 Max: 239076 Min:2173 | + ftrace_raw_event_sched_wakeup_template (0xffffffff8109d960) 100% (1) time:239076 max:239076 min:0 avg:239076 ttwu_do_wakeup (0xffffffff810a01a2) ttwu_do_activate.constprop.122 (0xffffffff810a0236) try_to_wake_up (0xffffffff810a3ec3) default_wake_function (0xffffffff810a4002) autoremove_wake_function (0xffffffff810b50fd) __wake_up_common (0xffffffff810b4958) __wake_up (0xffffffff810b4cb8) rb_wake_up_waiters (0xffffffff8112f126) irq_work_run_list (0xffffffff81157d0f) irq_work_run (0xffffffff81157d5e) smp_trace_irq_work_interrupt (0xffffffff810082fc) trace_irq_work_interrupt (0xffffffff816c7aaa) irq_exit (0xffffffff8107dd66) smp_trace_apic_timer_interrupt (0xffffffff816c8c7a) trace_apic_timer_interrupt (0xffffffff816c725a) prepare_ftrace_return (0xffffffff8103d4fd) ftrace_graph_caller (0xffffffff816c8428) mem_cgroup_begin_page_stat (0xffffffff811cfd25) page_remove_rmap (0xffffffff811a4fc5) stub_execve (0xffffffff816c6929) unmap_single_vma (0xffffffff81198b1c) unmap_vmas (0xffffffff81199174) exit_mmap (0xffffffff811a1f5b) mmput (0xffffffff8107699a) flush_old_exec (0xffffffff811ddb75) load_elf_binary (0xffffffff812287df) search_binary_handler (0xffffffff811dd3e0) do_execveat_common.isra.31 (0xffffffff811de8bd) do_execve (0xffffffff811dea8c) SyS_execve (0xffffffff811ded1e) return_to_handler (0xffffffff816c8458)
Event: softirq_raise:HI (3) Total: 72472 Avg: 24157 Max: 64186 Min:3430 Event: softirq_entry:RCU (2) Total: 3191 Avg: 1595 Max: 1788 Min:1403 | + ftrace_raw_event_sched_wakeup_template (0xffffffff8109d960) 100% (1) time:1788 max:1788 min:0 avg:1788 ttwu_do_wakeup (0xffffffff810a01a2) ttwu_do_activate.constprop.122 (0xffffffff810a0236) try_to_wake_up (0xffffffff810a3ec3) default_wake_function (0xffffffff810a4002) autoremove_wake_function (0xffffffff810b50fd) __wake_up_common (0xffffffff810b4958) __wake_up (0xffffffff810b4cb8) rb_wake_up_waiters (0xffffffff8112f126) irq_work_run_list (0xffffffff81157d0f) irq_work_run (0xffffffff81157d5e) smp_trace_irq_work_interrupt (0xffffffff810082fc) trace_irq_work_interrupt (0xffffffff816c7aaa) irq_work_queue (0xffffffff81157e95) ring_buffer_unlock_commit (0xffffffff8113039f) __buffer_unlock_commit (0xffffffff811367d5) trace_buffer_unlock_commit (0xffffffff811376a2) ftrace_event_buffer_commit (0xffffffff81146d5f) ftrace_raw_event_sched_process_exec (0xffffffff8109c511) do_execveat_common.isra.31 (0xffffffff811de9a3) do_execve (0xffffffff811dea8c) SyS_execve (0xffffffff811ded1e) return_to_handler (0xffffffff816c8458) stub_execve (0xffffffff816c6929)
Event: softirq_entry:SCHED (2) Total: 2289 Avg: 1144 Max: 1350 Min:939 Event: softirq_entry:HI (3) Total: 180146 Avg: 60048 Max: 178969 Min:499 | + ftrace_raw_event_sched_wakeup_template (0xffffffff8109d960) 100% (1) time:178969 max:178969 min:0 avg:178969 ttwu_do_wakeup (0xffffffff810a01a2) ttwu_do_activate.constprop.122 (0xffffffff810a0236) try_to_wake_up (0xffffffff810a3ec3) wake_up_process (0xffffffff810a4057) wake_up_worker (0xffffffff8108de74) insert_work (0xffffffff8108fca6) __queue_work (0xffffffff8108fe12) delayed_work_timer_fn (0xffffffff81090088) call_timer_fn (0xffffffff810d8f89) run_timer_softirq (0xffffffff810da8a1) __do_softirq (0xffffffff8107d8fa) irq_exit (0xffffffff8107dd66) smp_trace_apic_timer_interrupt (0xffffffff816c8c7a) trace_apic_timer_interrupt (0xffffffff816c725a) prepare_ftrace_return (0xffffffff8103d4fd) ftrace_graph_caller (0xffffffff816c8428) mem_cgroup_begin_page_stat (0xffffffff811cfd25) page_remove_rmap (0xffffffff811a4fc5) stub_execve (0xffffffff816c6929) unmap_single_vma (0xffffffff81198b1c) unmap_vmas (0xffffffff81199174) exit_mmap (0xffffffff811a1f5b) mmput (0xffffffff8107699a) flush_old_exec (0xffffffff811ddb75) load_elf_binary (0xffffffff812287df) search_binary_handler (0xffffffff811dd3e0) do_execveat_common.isra.31 (0xffffffff811de8bd) do_execve (0xffffffff811dea8c) SyS_execve (0xffffffff811ded1e) return_to_handler (0xffffffff816c8458) ---
Event: sched_switch:R (2) Total: 234559 Avg: 117279 Max: 129886 Min:104673
| + ftrace_raw_event_sched_switch (0xffffffff8109f310) 100% (2) time:234559 max:129886 min:104673 avg:117279 __schedule (0xffffffff816c1e81) preempt_schedule (0xffffffff816c236e) ___preempt_schedule (0xffffffff81351a59) | + unmap_single_vma (0xffffffff81198c05) | 55% (1) time:129886 max:129886 min:0 avg:129886 | stop_one_cpu (0xffffffff8110909a) | sched_exec (0xffffffff810a119b) | do_execveat_common.isra.31 (0xffffffff811de528) | do_execve (0xffffffff811dea8c) | SyS_execve (0xffffffff811ded1e) | return_to_handler (0xffffffff816c8458) | stub_execve (0xffffffff816c6929) | + unmap_single_vma (0xffffffff81198c05) 45% (1) time:104673 max:104673 min:0 avg:104673 unmap_vmas (0xffffffff81199174) exit_mmap (0xffffffff811a1f5b) mmput (0xffffffff8107699a) flush_old_exec (0xffffffff811ddb75) load_elf_binary (0xffffffff812287df) search_binary_handler (0xffffffff811dd3e0) do_execveat_common.isra.31 (0xffffffff811de8bd) do_execve (0xffffffff811dea8c) SyS_execve (0xffffffff811ded1e) return_to_handler (0xffffffff816c8458) stub_execve (0xffffffff816c6929)
Event: sched_switch:S (1) Total: 1000513242 Avg: 1000513242 Max: 1000513242 Min:10005132
Event: func: sys_nanosleep() (1) Total: 1000598016 Avg: 1000598016 Max: 1000598016 Min:1000598016 Event: func: sys_munmap() (1) Total: 14300 Avg: 14300 Max: 14300 Min:14300 Event: func: sys_arch_prctl() (1) Total: 571 Avg: 571 Max: 571 Min:571 Event: func: sys_mprotect() (4) Total: 14382 Avg: 3595 Max: 7196 Min:2190 Event: func: SyS_read() (1) Total: 2640 Avg: 2640 Max: 2640 Min:2640 Event: func: sys_close() (5) Total: 4001 Avg: 800 Max: 1252 Min:414 Event: func: sys_newfstat() (3) Total: 11684 Avg: 3894 Max: 10206 Min:636 Event: func: SyS_open() (3) Total: 23615 Avg: 7871 Max: 10535 Min:4743 Event: func: sys_access() (1) Total: 5924 Avg: 5924 Max: 5924 Min:5924 Event: func: SyS_mmap() (8) Total: 39153 Avg: 4894 Max: 12354 Min:1518 Event: func: smp_trace_apic_timer_interrupt() (1) Total: 10298 Avg: 10298 Max: 10298 Min:10298 Event: func: SyS_brk() (4) Total: 2407 Avg: 601 Max: 1564 Min:206 Event: func: do_notify_resume() (2) Total: 4095 Avg: 2047 Max: 2521 Min:1574 Event: func: sys_execve() (5) Total: 1625251 Avg: 325050 Max: 1605698 Min:3570
-l 'sys_*' -l 'SyS_*'
-p nop
-p function
Event: sys_enter:35 (1) Total: 1000599765 Avg: 1000599765 Max: 1000599765 Min:1000599765 Event: sys_enter:11 (1) Total: 55025 Avg: 55025 Max: 55025 Min:55025 Event: sys_enter:158 (1) Total: 1584 Avg: 1584 Max: 1584 Min:1584 Event: sys_enter:10 (4) Total: 18359 Avg: 4589 Max: 8764 Min:2933 Event: sys_enter:0 (1) Total: 4223 Avg: 4223 Max: 4223 Min:4223 Event: sys_enter:3 (5) Total: 9948 Avg: 1989 Max: 2606 Min:1203 Event: sys_enter:5 (3) Total: 15530 Avg: 5176 Max: 11840 Min:1405 Event: sys_enter:2 (3) Total: 28002 Avg: 9334 Max: 12035 Min:5656 Event: sys_enter:21 (1) Total: 7814 Avg: 7814 Max: 7814 Min:7814 Event: sys_enter:9 (8) Total: 49583 Avg: 6197 Max: 14137 Min:2362 Event: sys_enter:12 (4) Total: 108493 Avg: 27123 Max: 104079 Min:922 Event: sys_enter:59 (5) Total: 1631608 Avg: 326321 Max: 1607529 Min:4563
execve("/usr/lib64/ccache/sleep", ["sleep", "1"], [/* 27 vars */] <unfinished ...> <... execve resumed> ) = -1 ENOENT (No such file or directory) execve("/usr/local/sbin/sleep", ["sleep", "1"], [/* 27 vars */] <unfinished ...> <... execve resumed> ) = -1 ENOENT (No such file or directory) execve("/usr/local/bin/sleep", ["sleep", "1"], [/* 27 vars */] <unfinished ...> <... execve resumed> ) = -1 ENOENT (No such file or directory) execve("/usr/sbin/sleep", ["sleep", "1"], [/* 27 vars */] <unfinished ...> <... execve resumed> ) = -1 ENOENT (No such file or directory) execve("/usr/bin/sleep", ["sleep", "1"], [/* 27 vars */] <unfinished ...> <... execve resumed> ) = 0
Event: softirq_raise:RCU (3) Total: 252931 Avg: 84310 Max: 243288 Min:4639 Event: softirq_raise:SCHED (2) Total: 241249 Avg: 120624 Max: 239076 Min:2173 | + ftrace_raw_event_sched_wakeup_template (0xffffffff8109d960) 100% (1) time:239076 max:239076 min:0 avg:239076 ttwu_do_wakeup (0xffffffff810a01a2) ttwu_do_activate.constprop.122 (0xffffffff810a0236) try_to_wake_up (0xffffffff810a3ec3) default_wake_function (0xffffffff810a4002) autoremove_wake_function (0xffffffff810b50fd) __wake_up_common (0xffffffff810b4958) __wake_up (0xffffffff810b4cb8) rb_wake_up_waiters (0xffffffff8112f126) irq_work_run_list (0xffffffff81157d0f) irq_work_run (0xffffffff81157d5e) smp_trace_irq_work_interrupt (0xffffffff810082fc) trace_irq_work_interrupt (0xffffffff816c7aaa) irq_exit (0xffffffff8107dd66)
--- # trace-cmd profile -S -p function_graph -l '*kmalloc*' -l '*kmalloc*:stacktrace' sleep 1 task: sshd-11786 Event: func: __kmalloc_reserve.isra.59() (2) Total: 149684 Avg: 74842 Max: 75598 Min:74086 | + __alloc_skb (0xffffffff815a8917) | 67% (2) time:149684 max:75598 min:74086 avg:74842 | __kmalloc_node_track_caller (0xffffffff811c6635) | __kmalloc_reserve.isra.59 (0xffffffff815a84ac) | return_to_handler (0xffffffff816c8458) | sk_stream_alloc_skb (0xffffffff81604ea1) | tcp_sendmsg (0xffffffff8160592c) | inet_sendmsg (0xffffffff8162fed1) | sock_aio_write (0xffffffff8159f9fc) | do_sync_write (0xffffffff811d694a) | vfs_write (0xffffffff811d7825) | SyS_write (0xffffffff811d7adf) | system_call_fastpath (0xffffffff816c63d2) | + __alloc_skb (0xffffffff815a8917) 33% (1) time:74086 max:74086 min:74086 avg:74086 __alloc_skb (0xffffffff815a8917) sk_stream_alloc_skb (0xffffffff81604ea1) tcp_sendmsg (0xffffffff8160592c) inet_sendmsg (0xffffffff8162fed1) sock_aio_write (0xffffffff8159f9fc) do_sync_write (0xffffffff811d694a) vfs_write (0xffffffff811d7825) SyS_write (0xffffffff811d7adf) system_call_fastpath (0xffffffff816c63d2) [..] ---
SEE ALSO
trace-cmd(1), trace-cmd-record(1), trace-cmd-report(1), trace-cmd-start(1), trace-cmd-stop(1), trace-cmd-reset(1), trace-cmd-split(1), trace-cmd-list(1), trace-cmd-listen(1)AUTHOR
Written by Steven Rostedt, < [email protected][1]>RESOURCES
https://git.kernel.org/pub/scm/utils/trace-cmd/trace-cmd.git/COPYING
Copyright (C) 2014 Red Hat, Inc. Free use of this software is granted under the terms of the GNU Public License (GPL).NOTES
mailto:[email protected]
01/22/2023 | libtracefs |