summaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorArnaldo Carvalho de Melo <acme@redhat.com>2019-08-14 15:20:13 -0400
committerArnaldo Carvalho de Melo <acme@redhat.com>2019-08-15 11:23:58 -0400
commitf90a24171a8179a29e5e1532fd5bb94e59b5380e (patch)
tree8363cf9454c0167aa0a5a00bf37cb8c775a9f10d
parent11e54d35e6d5c3533b706753224ef38ea235684b (diff)
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>
-rw-r--r--tools/perf/Documentation/perf-script.txt3
-rw-r--r--tools/perf/builtin-script.c26
2 files changed, 29 insertions, 0 deletions
diff --git a/tools/perf/Documentation/perf-script.txt b/tools/perf/Documentation/perf-script.txt
index caaab28f8400..9936819aae1c 100644
--- a/tools/perf/Documentation/perf-script.txt
+++ b/tools/perf/Documentation/perf-script.txt
@@ -417,6 +417,9 @@ include::itrace.txt[]
417 For itrace only show specified functions and their callees for 417 For itrace only show specified functions and their callees for
418 itrace. Multiple functions can be separated by comma. 418 itrace. Multiple functions can be separated by comma.
419 419
420--switch-on EVENT_NAME::
421 Only consider events after this event is found.
422
420SEE ALSO 423SEE ALSO
421-------- 424--------
422linkperf:perf-record[1], linkperf:perf-script-perl[1], 425linkperf:perf-record[1], linkperf:perf-script-perl[1],
diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c
index 31a529ec139f..d0bc7ccaf7bf 100644
--- a/tools/perf/builtin-script.c
+++ b/tools/perf/builtin-script.c
@@ -1616,6 +1616,11 @@ static int perf_sample__fprintf_synth(struct perf_sample *sample,
1616 return 0; 1616 return 0;
1617} 1617}
1618 1618
1619struct evswitch {
1620 struct evsel *on;
1621 bool discarding;
1622};
1623
1619struct perf_script { 1624struct perf_script {
1620 struct perf_tool tool; 1625 struct perf_tool tool;
1621 struct perf_session *session; 1626 struct perf_session *session;
@@ -1628,6 +1633,7 @@ struct perf_script {
1628 bool show_bpf_events; 1633 bool show_bpf_events;
1629 bool allocated; 1634 bool allocated;
1630 bool per_event_dump; 1635 bool per_event_dump;
1636 struct evswitch evswitch;
1631 struct perf_cpu_map *cpus; 1637 struct perf_cpu_map *cpus;
1632 struct perf_thread_map *threads; 1638 struct perf_thread_map *threads;
1633 int name_width; 1639 int name_width;
@@ -1805,6 +1811,13 @@ static void process_event(struct perf_script *script,
1805 if (!show_event(sample, evsel, thread, al)) 1811 if (!show_event(sample, evsel, thread, al))
1806 return; 1812 return;
1807 1813
1814 if (script->evswitch.on && script->evswitch.discarding) {
1815 if (script->evswitch.on != evsel)
1816 return;
1817
1818 script->evswitch.discarding = false;
1819 }
1820
1808 ++es->samples; 1821 ++es->samples;
1809 1822
1810 perf_sample__fprintf_start(sample, thread, evsel, 1823 perf_sample__fprintf_start(sample, thread, evsel,
@@ -3395,6 +3408,7 @@ int cmd_script(int argc, const char **argv)
3395 struct utsname uts; 3408 struct utsname uts;
3396 char *script_path = NULL; 3409 char *script_path = NULL;
3397 const char **__argv; 3410 const char **__argv;
3411 const char *event_switch_on = NULL;
3398 int i, j, err = 0; 3412 int i, j, err = 0;
3399 struct perf_script script = { 3413 struct perf_script script = {
3400 .tool = { 3414 .tool = {
@@ -3538,6 +3552,8 @@ int cmd_script(int argc, const char **argv)
3538 "file", "file saving guest os /proc/kallsyms"), 3552 "file", "file saving guest os /proc/kallsyms"),
3539 OPT_STRING(0, "guestmodules", &symbol_conf.default_guest_modules, 3553 OPT_STRING(0, "guestmodules", &symbol_conf.default_guest_modules,
3540 "file", "file saving guest os /proc/modules"), 3554 "file", "file saving guest os /proc/modules"),
3555 OPT_STRING(0, "switch-on", &event_switch_on,
3556 "event", "Consider events from the first ocurrence of this event"),
3541 OPT_END() 3557 OPT_END()
3542 }; 3558 };
3543 const char * const script_subcommands[] = { "record", "report", NULL }; 3559 const char * const script_subcommands[] = { "record", "report", NULL };
@@ -3862,6 +3878,16 @@ int cmd_script(int argc, const char **argv)
3862 script.range_num); 3878 script.range_num);
3863 } 3879 }
3864 3880
3881 if (event_switch_on) {
3882 script.evswitch.on = perf_evlist__find_evsel_by_str(session->evlist, event_switch_on);
3883 if (script.evswitch.on == NULL) {
3884 fprintf(stderr, "switch-on event not found (%s)\n", event_switch_on);
3885 err = -ENOENT;
3886 goto out_delete;
3887 }
3888 script.evswitch.discarding = true;
3889 }
3890
3865 err = __cmd_script(&script); 3891 err = __cmd_script(&script);
3866 3892
3867 flush_scripting(); 3893 flush_scripting();