public inbox for linux-kernel@vger.kernel.org
 help / color / mirror / Atom feed
* [PATCH v2 1/3] perf tools: Record total sampling time
@ 2013-12-03  9:00 Namhyung Kim
  2013-12-03  9:00 ` [PATCH v2 2/3] perf tools: Record sampling time for each entry Namhyung Kim
  2013-12-03  9:00 ` [PATCH v2 3/3] perf report: Add --event-time option Namhyung Kim
  0 siblings, 2 replies; 5+ messages in thread
From: Namhyung Kim @ 2013-12-03  9:00 UTC (permalink / raw)
  To: Arnaldo Carvalho de Melo
  Cc: Peter Zijlstra, Paul Mackerras, Ingo Molnar, Namhyung Kim, LKML,
	Jiri Olsa, David Ahern, Stephane Eranian, Andi Kleen,
	Pekka Enberg, Frederic Weisbecker

From: Namhyung Kim <namhyung.kim@lge.com>

It's sometimes useful to see total sampling or elapsed time with
normal performance result.  To do that, record first and last sample
time for each evsel and to display it in the header (--stdio only for
now).

  $ perf record -a sleep 1
  $ perf report --stdio
  ...
  # Samples: 4K of event 'cycles'
  # Event count (approx.): 4087481688
  # Total sampling time  : 1.001260 (sec)
  #
  # Overhead       Command               Shared Object                   Symbol
  # ........  ............  ..........................  .......................
  #
      89.06%      nautilus  libgobject-2.0.so.0.3701.0  [.] 0x0000000000020bf0
       1.79%   kworker/1:0  [kernel.kallsyms]           [k] generic_exec_single
       1.75%       swapper  [kernel.kallsyms]           [k] intel_idle
       1.14%      nautilus  [unknown]                   [.] 0x0000003153f2ff61
       0.69%   kworker/0:1  [kernel.kallsyms]           [k] generic_exec_single
       0.67%      nautilus  ld-2.17.so                  [.] do_lookup_x

Reviewed-by: Pekka Enberg <penberg@kernel.org>
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
 tools/perf/builtin-report.c | 15 ++++++++++++++-
 tools/perf/util/evsel.h     |  2 ++
 tools/perf/util/hist.h      |  1 +
 tools/perf/util/session.c   |  7 +++++++
 4 files changed, 24 insertions(+), 1 deletion(-)

diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c
index 8cf8e66ba594..1d47fbec4421 100644
--- a/tools/perf/builtin-report.c
+++ b/tools/perf/builtin-report.c
@@ -456,6 +456,14 @@ static size_t hists__fprintf_nr_sample_events(struct perf_report *rep,
 		ret += fprintf(fp, "\n# Sort order   : %s", sort_order);
 	} else
 		ret += fprintf(fp, "\n# Event count (approx.): %" PRIu64, nr_events);
+	if (rep->tool.ordered_samples) {
+		u64 total_time = hists->stats.total_time;
+		u64 sec = total_time / NSEC_PER_SEC;
+		u64 usec = (total_time - sec * NSEC_PER_SEC) / NSEC_PER_USEC;
+
+		ret += fprintf(fp, "\n# Total sampling time  : "
+			       "%" PRIu64 ".%06" PRIu64 " (sec)", sec, usec);
+	}
 	return ret + fprintf(fp, "\n#\n");
 }
 
@@ -565,8 +573,13 @@ static int __cmd_report(struct perf_report *rep)
 	}
 
 	nr_samples = 0;
-	list_for_each_entry(pos, &session->evlist->entries, node)
+	list_for_each_entry(pos, &session->evlist->entries, node) {
 		nr_samples += pos->hists.nr_entries;
+		if (rep->tool.ordered_samples) {
+			pos->hists.stats.total_time = pos->last_timestamp -
+							pos->first_timestamp;
+		}
+	}
 
 	ui_progress__init(&prog, nr_samples, "Merging related events...");
 
diff --git a/tools/perf/util/evsel.h b/tools/perf/util/evsel.h
index 8120eeb86ac1..20a7c653b74b 100644
--- a/tools/perf/util/evsel.h
+++ b/tools/perf/util/evsel.h
@@ -67,6 +67,8 @@ struct perf_evsel {
 	int			idx;
 	u32			ids;
 	struct hists		hists;
+	u64			first_timestamp;
+	u64			last_timestamp;
 	char			*name;
 	double			scale;
 	const char		*unit;
diff --git a/tools/perf/util/hist.h b/tools/perf/util/hist.h
index b621347a1585..bc5acdfc2b4b 100644
--- a/tools/perf/util/hist.h
+++ b/tools/perf/util/hist.h
@@ -28,6 +28,7 @@ struct symbol;
  */
 struct events_stats {
 	u64 total_period;
+	u64 total_time;
 	u64 total_lost;
 	u64 total_invalid_chains;
 	u32 nr_events[PERF_RECORD_HEADER_MAX];
diff --git a/tools/perf/util/session.c b/tools/perf/util/session.c
index 4ce146bae552..e4b158f0586a 100644
--- a/tools/perf/util/session.c
+++ b/tools/perf/util/session.c
@@ -925,6 +925,13 @@ perf_session__deliver_sample(struct perf_session *session,
 	u64 sample_type = evsel->attr.sample_type;
 	u64 read_format = evsel->attr.read_format;
 
+	if (tool->ordered_samples) {
+		if (evsel->first_timestamp == 0)
+			evsel->first_timestamp = sample->time;
+
+		evsel->last_timestamp = sample->time;
+	}
+
 	/* Standard sample delievery. */
 	if (!(sample_type & PERF_SAMPLE_READ))
 		return tool->sample(tool, event, sample, evsel, machine);
-- 
1.7.11.7


^ permalink raw reply related	[flat|nested] 5+ messages in thread
end of thread, other threads:[~2013-12-09  7:59 UTC | newest]

Thread overview: 5+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2013-12-03  9:00 [PATCH v2 1/3] perf tools: Record total sampling time Namhyung Kim
2013-12-03  9:00 ` [PATCH v2 2/3] perf tools: Record sampling time for each entry Namhyung Kim
2013-12-03 16:20   ` David Ahern
2013-12-09  7:59     ` Namhyung Kim
2013-12-03  9:00 ` [PATCH v2 3/3] perf report: Add --event-time option Namhyung Kim

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox