Commit 853b7407 authored by David Ahern's avatar David Ahern Committed by Arnaldo Carvalho de Melo

perf sched timehist: Add option to specify time window of interest

Add option to allow user to control analysis window. e.g., collect data
for time window and analyze a segment of interest within that window.

Committer notes:

Testing it:

  # perf sched record -a usleep 1
  [ perf record: Woken up 1 times to write data ]
  [ perf record: Captured and wrote 1.593 MB perf.data (25 samples) ]
  #
  # perf sched timehist | head -18
  Samples do not have callchains.
          time    cpu   task name       wait time  sch delay  run time
                        [tid/pid]          (msec)     (msec)    (msec)
  ------------- ------  --------------- ---------  ---------  --------
   19818.635579 [0002]  <idle>              0.000      0.000     0.000
   19818.635613 [0000]  perf[9116]          0.000      0.000     0.000
   19818.635676 [0000]  <idle>              0.000      0.000     0.063
   19818.635678 [0000]  rcuos/2[29]         0.000      0.002     0.001
   19818.635696 [0002]  perf[9117]          0.000      0.004     0.116
   19818.635702 [0000]  <idle>              0.001      0.000     0.024
   19818.635709 [0002]  migration/2[25]     0.000      0.003     0.012
   19818.636263 [0000]  usleep[9117]        0.005      0.000     0.560
   19818.636316 [0000]  <idle>              0.560      0.000     0.053
   19818.636358 [0002]  <idle>              0.129      0.000     0.649
   19818.636358 [0000]  usleep[9117]        0.053      0.002     0.042
  #

  # perf sched timehist --time 19818.635696,
  Samples do not have callchains.
           time    cpu  task name       wait time  sch delay  run time
                        [tid/pid]          (msec)     (msec)    (msec)
  ------------- ------  ---------------  --------  --------- ---------
   19818.635696 [0002]  perf[9117]          0.000      0.120     0.000
   19818.635702 [0000]  <idle>              0.019      0.000     0.006
   19818.635709 [0002]  migration/2[25]     0.000      0.003     0.012
   19818.636263 [0000]  usleep[9117]        0.005      0.000     0.560
   19818.636316 [0000]  <idle>              0.560      0.000     0.053
   19818.636358 [0002]  <idle>              0.129      0.000     0.649
   19818.636358 [0000]  usleep[9117]        0.053      0.002     0.042
  #
  # perf sched timehist --time 19818.635696,19818.635709
  Samples do not have callchains.
           time    cpu  task name       wait time  sch delay  run time
                        [tid/pid]          (msec)     (msec)    (msec)
  ------------- ------  --------------- ---------  --------- ---------
   19818.635696 [0002]  perf[9117]          0.000      0.120     0.000
   19818.635702 [0000]  <idle>              0.019      0.000     0.006
   19818.635709 [0002]  migration/2[25]     0.000      0.003     0.012
   19818.635709 [0000]  usleep[9117]        0.005      0.000     0.006
  #
Signed-off-by: default avatarDavid Ahern <dsahern@gmail.com>
Tested-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
Acked-by: default avatarNamhyung Kim <namhyung@kernel.org>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: http://lkml.kernel.org/r/1480439746-42695-5-git-send-email-dsahern@gmail.comSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
parent a91f4c47
...@@ -132,6 +132,14 @@ OPTIONS for 'perf sched timehist' ...@@ -132,6 +132,14 @@ OPTIONS for 'perf sched timehist'
--migrations:: --migrations::
Show migration events. Show migration events.
--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 SEE ALSO
-------- --------
linkperf:perf-record[1] linkperf:perf-record[1]
...@@ -15,6 +15,7 @@ ...@@ -15,6 +15,7 @@
#include "util/color.h" #include "util/color.h"
#include "util/stat.h" #include "util/stat.h"
#include "util/callchain.h" #include "util/callchain.h"
#include "util/time-utils.h"
#include <subcmd/parse-options.h> #include <subcmd/parse-options.h>
#include "util/trace-event.h" #include "util/trace-event.h"
...@@ -205,6 +206,8 @@ struct perf_sched { ...@@ -205,6 +206,8 @@ struct perf_sched {
bool show_wakeups; bool show_wakeups;
bool show_migrations; bool show_migrations;
u64 skipped_samples; u64 skipped_samples;
const char *time_str;
struct perf_time_interval ptime;
}; };
/* per thread run time data */ /* per thread run time data */
...@@ -1837,13 +1840,14 @@ static void timehist_header(struct perf_sched *sched) ...@@ -1837,13 +1840,14 @@ static void timehist_header(struct perf_sched *sched)
static void timehist_print_sample(struct perf_sched *sched, static void timehist_print_sample(struct perf_sched *sched,
struct perf_sample *sample, struct perf_sample *sample,
struct addr_location *al, struct addr_location *al,
struct thread *thread) struct thread *thread,
u64 t)
{ {
struct thread_runtime *tr = thread__priv(thread); struct thread_runtime *tr = thread__priv(thread);
u32 max_cpus = sched->max_cpu + 1; u32 max_cpus = sched->max_cpu + 1;
char tstr[64]; char tstr[64];
timestamp__scnprintf_usec(sample->time, tstr, sizeof(tstr)); timestamp__scnprintf_usec(t, tstr, sizeof(tstr));
printf("%15s [%04d] ", tstr, sample->cpu); printf("%15s [%04d] ", tstr, sample->cpu);
if (sched->show_cpu_visual) { if (sched->show_cpu_visual) {
...@@ -2194,7 +2198,8 @@ static int timehist_sched_wakeup_event(struct perf_tool *tool, ...@@ -2194,7 +2198,8 @@ static int timehist_sched_wakeup_event(struct perf_tool *tool,
tr->ready_to_run = sample->time; tr->ready_to_run = sample->time;
/* show wakeups if requested */ /* show wakeups if requested */
if (sched->show_wakeups) if (sched->show_wakeups &&
!perf_time__skip_sample(&sched->ptime, sample->time))
timehist_print_wakeup_event(sched, sample, machine, thread); timehist_print_wakeup_event(sched, sample, machine, thread);
return 0; return 0;
...@@ -2288,10 +2293,11 @@ static int timehist_sched_change_event(struct perf_tool *tool, ...@@ -2288,10 +2293,11 @@ static int timehist_sched_change_event(struct perf_tool *tool,
struct machine *machine) struct machine *machine)
{ {
struct perf_sched *sched = container_of(tool, struct perf_sched, tool); struct perf_sched *sched = container_of(tool, struct perf_sched, tool);
struct perf_time_interval *ptime = &sched->ptime;
struct addr_location al; struct addr_location al;
struct thread *thread; struct thread *thread;
struct thread_runtime *tr = NULL; struct thread_runtime *tr = NULL;
u64 tprev; u64 tprev, t = sample->time;
int rc = 0; int rc = 0;
if (machine__resolve(machine, &al, sample) < 0) { if (machine__resolve(machine, &al, sample) < 0) {
...@@ -2318,9 +2324,35 @@ static int timehist_sched_change_event(struct perf_tool *tool, ...@@ -2318,9 +2324,35 @@ static int timehist_sched_change_event(struct perf_tool *tool,
tprev = perf_evsel__get_time(evsel, sample->cpu); tprev = perf_evsel__get_time(evsel, sample->cpu);
timehist_update_runtime_stats(tr, sample->time, tprev); /*
* If start time given:
* - sample time is under window user cares about - skip sample
* - tprev is under window user cares about - reset to start of window
*/
if (ptime->start && ptime->start > t)
goto out;
if (ptime->start > tprev)
tprev = ptime->start;
/*
* If end time given:
* - previous sched event is out of window - we are done
* - sample time is beyond window user cares about - reset it
* to close out stats for time window interest
*/
if (ptime->end) {
if (tprev > ptime->end)
goto out;
if (t > ptime->end)
t = ptime->end;
}
timehist_update_runtime_stats(tr, t, tprev);
if (!sched->summary_only) if (!sched->summary_only)
timehist_print_sample(sched, sample, &al, thread); timehist_print_sample(sched, sample, &al, thread, t);
out: out:
if (tr) { if (tr) {
...@@ -2583,6 +2615,11 @@ static int perf_sched__timehist(struct perf_sched *sched) ...@@ -2583,6 +2615,11 @@ static int perf_sched__timehist(struct perf_sched *sched)
symbol__init(&session->header.env); symbol__init(&session->header.env);
if (perf_time__parse_str(&sched->ptime, sched->time_str) != 0) {
pr_err("Invalid time string\n");
return -EINVAL;
}
if (timehist_check_attr(sched, evlist) != 0) if (timehist_check_attr(sched, evlist) != 0)
goto out; goto out;
...@@ -2997,6 +3034,8 @@ int cmd_sched(int argc, const char **argv, const char *prefix __maybe_unused) ...@@ -2997,6 +3034,8 @@ int cmd_sched(int argc, const char **argv, const char *prefix __maybe_unused)
OPT_BOOLEAN('w', "wakeups", &sched.show_wakeups, "Show wakeup events"), OPT_BOOLEAN('w', "wakeups", &sched.show_wakeups, "Show wakeup events"),
OPT_BOOLEAN('M', "migrations", &sched.show_migrations, "Show migration events"), OPT_BOOLEAN('M', "migrations", &sched.show_migrations, "Show migration events"),
OPT_BOOLEAN('V', "cpu-visual", &sched.show_cpu_visual, "Add CPU visual"), OPT_BOOLEAN('V', "cpu-visual", &sched.show_cpu_visual, "Add CPU visual"),
OPT_STRING(0, "time", &sched.time_str, "str",
"Time span for analysis (start,stop)"),
OPT_PARENT(sched_options) OPT_PARENT(sched_options)
}; };
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment