perf trace: Allow mixing with other events

Basically adopting 'perf record' --event command line argument syntax:

 # trace -e \!mprotect,mmap,munmap,open,close,read,fstat,access,arch_prctl --event sched:*switch,sched:*exec,sched:*exit usleep 1
  0.048 (        ): sched:sched_process_exec:filename=/bin/usleep pid=24732 old_pid=24732)
  0.078 (0.002 ms): usleep/24732 brk(                          ) = 0x78f000
  0.430 (0.002 ms): usleep/24732 brk(                          ) = 0x78f000
  0.434 (0.003 ms): usleep/24732 brk(brk: 0x7b0000             ) = 0x7b0000
  0.438 (0.001 ms): usleep/24732 brk(                          ) = 0x7b0000
  0.460 (0.004 ms): usleep/24732 nanosleep(rqtp: 0x7ffff3696a40) ...
  0.460 (        ): sched:sched_switch:prev_comm=usleep prev_pid=24732 prev_prio=120 prev_state=S ==> next_comm=swapper/1 next_pid=0 next_prio=120)
  0.515 (0.058 ms): usleep/24732  ... [continued]: nanosleep()) = 0
  0.520 (0.000 ms): usleep/24732 exit_group(
  0.550 (        ): sched:sched_process_exit:comm=usleep pid=24732 prio=120)
 #

Next steps, probably in this order:

1) Use ordered_events code, the logic in trace needs the events to be
   time ordered when needed, i.e. when multiple CPUs are involved.

2) Callchains!

3) Automatically account for interruptions when saying how long things
   took.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Borislav Petkov <bp@suse.de>
Cc: David Ahern <dsahern@gmail.com>
Cc: Don Zickus <dzickus@redhat.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Mike Galbraith <efault@gmx.de>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/n/tip-gpst8mph575yb4wgf91qibyb@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>

diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c
index feabd08ec90dcc7f9e357ba0c9037f03a9571e0e..a44ac933621917883aebc938655ac2ca45db83b1 100644 (file)
--- a/tools/perf/builtin-trace.c
+++ b/tools/perf/builtin-trace.c
@@ -1219,6 +1219,7 @@ struct trace {
                struct syscall  *table;
        } syscalls;
        struct record_opts      opts;
+       struct perf_evlist      *evlist;
        struct machine          *host;
        struct thread           *current;
        u64                     base_time;
@@ -1833,6 +1834,24 @@ out_dump:
        return 0;
 }
 
+static int trace__event_handler(struct trace *trace, struct perf_evsel *evsel,
+                               union perf_event *event __maybe_unused,
+                               struct perf_sample *sample)
+{
+       trace__printf_interrupted_entry(trace, sample);
+       trace__fprintf_tstamp(trace, sample->time, trace->output);
+       fprintf(trace->output, "(%9.9s): %s:", " ", evsel->name);
+
+       if (evsel->tp_format) {
+               event_format__fprintf(evsel->tp_format, sample->cpu,
+                                     sample->raw_data, sample->raw_size,
+                                     trace->output);
+       }
+
+       fprintf(trace->output, ")\n");
+       return 0;
+}
+
 static void print_location(FILE *f, struct perf_sample *sample,
                           struct addr_location *al,
                           bool print_dso, bool print_sym)
@@ -2067,7 +2086,7 @@ static int perf_evlist__add_pgfault(struct perf_evlist *evlist,
 
 static int trace__run(struct trace *trace, int argc, const char **argv)
 {
-       struct perf_evlist *evlist = perf_evlist__new();
+       struct perf_evlist *evlist = trace->evlist;
        struct perf_evsel *evsel;
        int err = -1, i;
        unsigned long before;
@@ -2076,11 +2095,6 @@ static int trace__run(struct trace *trace, int argc, const char **argv)
 
        trace->live = true;
 
-       if (evlist == NULL) {
-               fprintf(trace->output, "Not enough memory to run!\n");
-               goto out;
-       }
-
        if (trace->trace_syscalls &&
            perf_evlist__add_syscall_newtp(evlist, trace__sys_enter,
                                           trace__sys_exit))
@@ -2227,7 +2241,7 @@ out_disable:
 
 out_delete_evlist:
        perf_evlist__delete(evlist);
-out:
+       trace->evlist = NULL;
        trace->live = false;
        return err;
 {
@@ -2498,6 +2512,14 @@ static int parse_pagefaults(const struct option *opt, const char *str,
        return 0;
 }
 
+static void evlist__set_evsel_handler(struct perf_evlist *evlist, void *handler)
+{
+       struct perf_evsel *evsel;
+
+       evlist__for_each(evlist, evsel)
+               evsel->handler = handler;
+}
+
 int cmd_trace(int argc, const char **argv, const char *prefix __maybe_unused)
 {
        const char * const trace_usage[] = {
@@ -2532,6 +2554,9 @@ int cmd_trace(int argc, const char **argv, const char *prefix __maybe_unused)
        const char *output_name = NULL;
        const char *ev_qualifier_str = NULL;
        const struct option trace_options[] = {
+       OPT_CALLBACK(0, "event", &trace.evlist, "event",
+                    "event selector. use 'perf list' to list available events",
+                    parse_events_option),
        OPT_BOOLEAN(0, "comm", &trace.show_comm,
                    "show the thread COMM next to its id"),
        OPT_BOOLEAN(0, "tool_stats", &trace.show_tool_stats, "show tool stats"),
@@ -2573,6 +2598,15 @@ int cmd_trace(int argc, const char **argv, const char *prefix __maybe_unused)
        int err;
        char bf[BUFSIZ];
 
+       trace.evlist = perf_evlist__new();
+       if (trace.evlist == NULL)
+               return -ENOMEM;
+
+       if (trace.evlist == NULL) {
+               pr_err("Not enough memory to run!\n");
+               goto out;
+       }
+
        argc = parse_options(argc, argv, trace_options, trace_usage,
                             PARSE_OPT_STOP_AT_NON_OPTION);
 
@@ -2581,6 +2615,9 @@ int cmd_trace(int argc, const char **argv, const char *prefix __maybe_unused)
                trace.opts.sample_time = true;
        }
 
+       if (trace.evlist->nr_entries > 0)
+               evlist__set_evsel_handler(trace.evlist, trace__event_handler);
+
        if ((argc >= 1) && (strcmp(argv[0], "record") == 0))
                return trace__record(&trace, argc-1, &argv[1]);