perf script: Allow specifying event to switch on processing of other events
Sometime we want to only consider events after something happens, so
allow discarding events till such events is found, e.g.:
Record all scheduler tracepoints and the sys_enter_nanosleep syscall
event for the 'sleep 1' workload:
# perf record -e sched:*,syscalls:sys_enter_nanosleep sleep 1
[ perf record: Woken up 31 times to write data ]
[ perf record: Captured and wrote 0.032 MB perf.data (10 samples) ]
#
So we have these events in the generated perf data file:
# perf evlist
sched:sched_kthread_stop
sched:sched_kthread_stop_ret
sched:sched_waking
sched:sched_wakeup
sched:sched_wakeup_new
sched:sched_switch
sched:sched_migrate_task
sched:sched_process_free
sched:sched_process_exit
sched:sched_wait_task
sched:sched_process_wait
sched:sched_process_fork
sched:sched_process_exec
sched:sched_stat_wait
sched:sched_stat_sleep
sched:sched_stat_iowait
sched:sched_stat_blocked
sched:sched_stat_runtime
sched:sched_pi_setprio
sched:sched_move_numa
sched:sched_stick_numa
sched:sched_swap_numa
sched:sched_wake_idle_without_ipi
syscalls:sys_enter_nanosleep
# Tip: use 'perf evlist --trace-fields' to show fields for tracepoint events
#
Then show all of the events that actually took place in this 'perf record' session:
# perf script
:13637 13637 [002] 108237.581529: sched:sched_waking: comm=perf pid=13638 prio=120 target_cpu=001
:13637 13637 [002] 108237.581537: sched:sched_wakeup: perf:13638 [120] success=1 CPU:001
sleep 13638 [001] 108237.581992: sched:sched_process_exec: filename=/usr/bin/sleep pid=13638 old_pid=13638
sleep 13638 [001] 108237.582286: syscalls:sys_enter_nanosleep: rqtp: 0x7fff1948ac40, rmtp: 0x00000000
sleep 13638 [001] 108237.582289: sched:sched_stat_runtime: comm=sleep pid=13638 runtime=578104 [ns] vruntime=202889459556 [ns]
sleep 13638 [001] 108237.582291: sched:sched_switch: sleep:13638 [120] S ==> swapper/1:0 [120]
swapper 0 [001] 108238.582428: sched:sched_waking: comm=sleep pid=13638 prio=120 target_cpu=001
swapper 0 [001] 108238.582458: sched:sched_wakeup: sleep:13638 [120] success=1 CPU:001
sleep 13638 [001] 108238.582698: sched:sched_stat_runtime: comm=sleep pid=13638 runtime=173915 [ns] vruntime=202889633471 [ns]
sleep 13638 [001] 108238.582782: sched:sched_process_exit: comm=sleep pid=13638 prio=120
#
Now lets see only the ones that took place after a certain "marker":
# perf script --switch-on syscalls:sys_enter_nanosleep
sleep 13638 [001] 108237.582289: sched:sched_stat_runtime: comm=sleep pid=13638 runtime=578104 [ns] vruntime=202889459556 [ns]
sleep 13638 [001] 108237.582291: sched:sched_switch: sleep:13638 [120] S ==> swapper/1:0 [120]
swapper 0 [001] 108238.582428: sched:sched_waking: comm=sleep pid=13638 prio=120 target_cpu=001
swapper 0 [001] 108238.582458: sched:sched_wakeup: sleep:13638 [120] success=1 CPU:001
sleep 13638 [001] 108238.582698: sched:sched_stat_runtime: comm=sleep pid=13638 runtime=173915 [ns] vruntime=202889633471 [ns]
sleep 13638 [001] 108238.582782: sched:sched_process_exit: comm=sleep pid=13638 prio=120
#
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Florian Weimer <fweimer@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: William Cohen <wcohen@redhat.com>
Link: https://lkml.kernel.org/n/tip-f1oo0ufdhrkx6nhy2lj1ierm@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2 files changed