perf script: Add option to specify time window of interest
authorDavid Ahern <dsa@cumulusnetworks.com>
Tue, 29 Nov 2016 17:15:43 +0000 (10:15 -0700)
committerArnaldo Carvalho de Melo <acme@redhat.com>
Thu, 1 Dec 2016 16:02:45 +0000 (13:02 -0300)
Add option to allow user to control analysis window. e.g., collect data
for some amount of time and analyze a segment of interest within that
window.

Committer notes:

Testing it:

  # perf evlist -v
  cycles:ppp: size: 112, { sample_period, sample_freq }: 4000, sample_type: IP|TID|TIME|CALLCHAIN|CPU|PERIOD, disabled: 1, inherit: 1, mmap: 1, comm: 1, freq: 1, task: 1, precise_ip: 3, sample_id_all: 1, exclude_guest: 1, mmap2: 1, comm_exec: 1
  #
  # perf script --hide-call-graph | head -15
    swapper    0 [0] 9693.370039:      1 cycles:ppp: ffffffffb90072ad x86_pmu_enable (.../4.8.8-300.fc25.x86_64/vmlinux)
    swapper    0 [0] 9693.370044:      1 cycles:ppp: ffffffffb900ca1b intel_pmu_handle_irq (.../4.8.8-300.fc25.x86_64/vmlinux)
    swapper    0 [0] 9693.370046:      7 cycles:ppp: ffffffffb902fd93 native_sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux)
    swapper    0 [0] 9693.370048:    126 cycles:ppp: ffffffffb902fd93 native_sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux)
    swapper    0 [0] 9693.370049:   2701 cycles:ppp: ffffffffb902fd93 native_sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux)
    swapper    0 [0] 9693.370051:  58823 cycles:ppp: ffffffffb90cd2e0 idle_cpu (.../4.8.8-300.fc25.x86_64/vmlinux)
    swapper    0 [1] 9693.370059:      1 cycles:ppp: ffffffffb91a713a ctx_resched (.../4.8.8-300.fc25.x86_64/vmlinux)
    swapper    0 [1] 9693.370062:      1 cycles:ppp: ffffffffb900ca1b intel_pmu_handle_irq (.../4.8.8-300.fc25.x86_64/vmlinux)
    swapper    0 [1] 9693.370064:     13 cycles:ppp: ffffffffb902fd93 native_sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux)
    swapper    0 [1] 9693.370065:    250 cycles:ppp: ffffffffb902fd93 native_sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux)
    swapper    0 [1] 9693.370067:   5269 cycles:ppp: ffffffffb902fe79 sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux)
    swapper    0 [1] 9693.370069: 114602 cycles:ppp: ffffffffb90c1c5a atomic_notifier_call_chain (.../4.8.8-300.fc25.x86_64/vmlinux)
       perf 5124 [2] 9693.370076:      1 cycles:ppp: ffffffffb91a76c1 __perf_event_enable (.../4.8.8-300.fc25.x86_64/vmlinux)
       perf 5124 [2] 9693.370091:      1 cycles:ppp: ffffffffb900ca1b intel_pmu_handle_irq (.../4.8.8-300.fc25.x86_64/vmlinux)
       perf 5124 [2] 9693.370095:      3 cycles:ppp: ffffffffb902fd93 native_sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux)
  #
  # perf script --hide-call-graph --time ,9693.370048
    swapper    0 [0] 9693.370039:      1 cycles:ppp: ffffffffb90072ad x86_pmu_enable (.../4.8.8-300.fc25.x86_64/vmlinux)
    swapper    0 [0] 9693.370044:      1 cycles:ppp: ffffffffb900ca1b intel_pmu_handle_irq (.../4.8.8-300.fc25.x86_64/vmlinux)
    swapper    0 [0] 9693.370046:      7 cycles:ppp: ffffffffb902fd93 native_sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux)
  # perf script --hide-call-graph --time 9693.370064,9693.370076
    swapper    0 [1] 9693.370064:     13 cycles:ppp: ffffffffb902fd93 native_sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux)
    swapper    0 [1] 9693.370065:    250 cycles:ppp: ffffffffb902fd93 native_sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux)
    swapper    0 [1] 9693.370067:   5269 cycles:ppp: ffffffffb902fe79 sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux)
    swapper    0 [1] 9693.370069: 114602 cycles:ppp: ffffffffb90c1c5a atomic_notifier_call_chain (.../4.8.8-300.fc25.x86_64/vmlinux)
  #

Signed-off-by: David Ahern <dsahern@gmail.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Acked-by: Namhyung Kim <namhyung@kernel.org>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: http://lkml.kernel.org/r/1480439746-42695-4-git-send-email-dsahern@gmail.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
tools/perf/Documentation/perf-script.txt
tools/perf/builtin-script.c

index 0f6ee09f7256fee04f3dcc1cda92599e62b7250f..5dc5c6a09ac4f4113fd88f56f16c8713ff2e9646 100644 (file)
@@ -292,6 +292,13 @@ include::itrace.txt[]
 --force::
        Don't do ownership validation.
 
+--time::
+       Only analyze samples within given time window: <start>,<stop>. Times
+       have the format seconds.microseconds. If start is not given (i.e., time
+       string is ',x.y') then analysis starts at the beginning of the file. If
+       stop time is not given (i.e, time string is 'x.y,') then analysis goes
+       to end of file.
+
 SEE ALSO
 --------
 linkperf:perf-record[1], linkperf:perf-script-perl[1],
index 066b4bf73780c96292a0c9a7aeefb41ed10dc95f..2f3ff69fc4e7f0e40c50b2d10d1fc73396f74d4d 100644 (file)
@@ -22,6 +22,7 @@
 #include "util/thread_map.h"
 #include "util/stat.h"
 #include "util/thread-stack.h"
+#include "util/time-utils.h"
 #include <linux/bitmap.h>
 #include <linux/stringify.h>
 #include <linux/time64.h>
@@ -833,6 +834,8 @@ struct perf_script {
        struct cpu_map          *cpus;
        struct thread_map       *threads;
        int                     name_width;
+       const char              *time_str;
+       struct perf_time_interval ptime;
 };
 
 static int perf_evlist__max_name_len(struct perf_evlist *evlist)
@@ -1014,6 +1017,9 @@ static int process_sample_event(struct perf_tool *tool,
        struct perf_script *scr = container_of(tool, struct perf_script, tool);
        struct addr_location al;
 
+       if (perf_time__skip_sample(&scr->ptime, sample->time))
+               return 0;
+
        if (debug_mode) {
                if (sample->time < last_timestamp) {
                        pr_err("Samples misordered, previous: %" PRIu64
@@ -2186,7 +2192,8 @@ int cmd_script(int argc, const char **argv, const char *prefix __maybe_unused)
                        "Enable symbol demangling"),
        OPT_BOOLEAN(0, "demangle-kernel", &symbol_conf.demangle_kernel,
                        "Enable kernel symbol demangling"),
-
+       OPT_STRING(0, "time", &script.time_str, "str",
+                  "Time span of interest (start,stop)"),
        OPT_END()
        };
        const char * const script_subcommands[] = { "record", "report", NULL };
@@ -2465,6 +2472,12 @@ int cmd_script(int argc, const char **argv, const char *prefix __maybe_unused)
        if (err < 0)
                goto out_delete;
 
+       /* needs to be parsed after looking up reference time */
+       if (perf_time__parse_str(&script.ptime, script.time_str) != 0) {
+               pr_err("Invalid time string\n");
+               return -EINVAL;
+       }
+
        err = __cmd_script(&script);
 
        flush_scripting();