[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <tip-853b74071110bed344bad1ca9d8de27731b1c574@git.kernel.org>
Date: Fri, 2 Dec 2016 02:42:37 -0800
From: tip-bot for David Ahern <tipbot@...or.com>
To: linux-tip-commits@...r.kernel.org
Cc: hpa@...or.com, namhyung@...nel.org, dsa@...ulusnetworks.com,
mingo@...nel.org, jolsa@...nel.org, dsahern@...il.com,
linux-kernel@...r.kernel.org, acme@...hat.com, tglx@...utronix.de,
peterz@...radead.org
Subject: [tip:perf/core] perf sched timehist: Add option to specify time
window of interest
Commit-ID: 853b74071110bed344bad1ca9d8de27731b1c574
Gitweb: http://git.kernel.org/tip/853b74071110bed344bad1ca9d8de27731b1c574
Author: David Ahern <dsa@...ulusnetworks.com>
AuthorDate: Tue, 29 Nov 2016 10:15:44 -0700
Committer: Arnaldo Carvalho de Melo <acme@...hat.com>
CommitDate: Thu, 1 Dec 2016 13:02:52 -0300
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: David Ahern <dsahern@...il.com>
Tested-by: Arnaldo Carvalho de Melo <acme@...hat.com>
Acked-by: Namhyung Kim <namhyung@...nel.org>
Cc: Jiri Olsa <jolsa@...nel.org>
Cc: Peter Zijlstra <peterz@...radead.org>
Link: http://lkml.kernel.org/r/1480439746-42695-5-git-send-email-dsahern@gmail.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@...hat.com>
---
tools/perf/Documentation/perf-sched.txt | 8 ++++++
tools/perf/builtin-sched.c | 51 +++++++++++++++++++++++++++++----
2 files changed, 53 insertions(+), 6 deletions(-)
diff --git a/tools/perf/Documentation/perf-sched.txt b/tools/perf/Documentation/perf-sched.txt
index 121c60d..7775b1e 100644
--- a/tools/perf/Documentation/perf-sched.txt
+++ b/tools/perf/Documentation/perf-sched.txt
@@ -132,6 +132,14 @@ OPTIONS for 'perf sched timehist'
--migrations::
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
--------
linkperf:perf-record[1]
diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c
index 4f9e7cb..870d94c 100644
--- a/tools/perf/builtin-sched.c
+++ b/tools/perf/builtin-sched.c
@@ -15,6 +15,7 @@
#include "util/color.h"
#include "util/stat.h"
#include "util/callchain.h"
+#include "util/time-utils.h"
#include <subcmd/parse-options.h>
#include "util/trace-event.h"
@@ -205,6 +206,8 @@ struct perf_sched {
bool show_wakeups;
bool show_migrations;
u64 skipped_samples;
+ const char *time_str;
+ struct perf_time_interval ptime;
};
/* per thread run time data */
@@ -1837,13 +1840,14 @@ static void timehist_header(struct perf_sched *sched)
static void timehist_print_sample(struct perf_sched *sched,
struct perf_sample *sample,
struct addr_location *al,
- struct thread *thread)
+ struct thread *thread,
+ u64 t)
{
struct thread_runtime *tr = thread__priv(thread);
u32 max_cpus = sched->max_cpu + 1;
char tstr[64];
- timestamp__scnprintf_usec(sample->time, tstr, sizeof(tstr));
+ timestamp__scnprintf_usec(t, tstr, sizeof(tstr));
printf("%15s [%04d] ", tstr, sample->cpu);
if (sched->show_cpu_visual) {
@@ -2194,7 +2198,8 @@ static int timehist_sched_wakeup_event(struct perf_tool *tool,
tr->ready_to_run = sample->time;
/* 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);
return 0;
@@ -2288,10 +2293,11 @@ static int timehist_sched_change_event(struct perf_tool *tool,
struct machine *machine)
{
struct perf_sched *sched = container_of(tool, struct perf_sched, tool);
+ struct perf_time_interval *ptime = &sched->ptime;
struct addr_location al;
struct thread *thread;
struct thread_runtime *tr = NULL;
- u64 tprev;
+ u64 tprev, t = sample->time;
int rc = 0;
if (machine__resolve(machine, &al, sample) < 0) {
@@ -2318,9 +2324,35 @@ static int timehist_sched_change_event(struct perf_tool *tool,
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)
- timehist_print_sample(sched, sample, &al, thread);
+ timehist_print_sample(sched, sample, &al, thread, t);
out:
if (tr) {
@@ -2583,6 +2615,11 @@ static int perf_sched__timehist(struct perf_sched *sched)
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)
goto out;
@@ -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('M', "migrations", &sched.show_migrations, "Show migration events"),
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)
};
Powered by blists - more mailing lists