[PATCH 0/4] perf report: add parameters 'start' & 'end' to specify analysis interval

[PATCH 0/4] perf report: add parameters 'start' & 'end' to specify analysis interval

[Chenggang Qin]

This patch set introduced a feature to analysis the samples in a specified time
interval.
After perf.data file was generated by perf record, the user could want to
analysis a sub time interval of the whole record period.
For some functions, the percent of its samples in a certain sub time interval is
different from the percent in the total record period. Showing the scene in a
certain time interval could allow users to more easily troubleshoot performance
problems. The sample's timestamp are recorded in the perf.data file. The samples
are sorted in the ordered_samples by timestamp while perf report processed them.
So, it is easily to search the samples whose timestamp are in a certain time
interval.
We add 2 paramters --start and --end to specify the time interval.
perf report --start xxxxx --end xxxxx
The smallest granularity of time interval is millsecond.
For example:
If the whole record period of a perf.data file is 10000 to 20000, we can use the
following command to analysis the samples between [15000, 16000).
perf report --start 15000 --end 16000
The time is the uptime, it start timing from the system starts.

Cc: David Ahern <dsahern@gmail.com>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Arnaldo Carvalho de Melo <acme@ghostprotocols.net>
Cc: Arjan van de Ven <arjan@linux.intel.com>
Cc: Namhyung Kim <namhyung@gmail.com>
Cc: Yanmin Zhang <yanmin.zhang@intel.com>
Cc: Wu Fengguang <fengguang.wu@intel.com>
Cc: Mike Galbraith <efault@gmx.de>
Cc: Andrew Morton <akpm@linux-foundation.org>
Signed-off-by: Chenggang Qin <chenggang.qcg@taobao.com>

Chenggang Qin (4):
  perf tools: add parameter 'start' & 'end' to perf report
  perf tools: relate 'start' & 'end' to perf_session
  perf tools: record min_timestamp of samples queue in ordered_samples
  perf tools: add the feature to assign analysis interval to perf
    report

 tools/perf/builtin-report.c |   14 ++++++++++++
 tools/perf/util/session.c   |   49 +++++++++++++++++++++++++++++++++++++++++-
 tools/perf/util/session.h   |    3 ++
 3 files changed, 64 insertions(+), 2 deletions(-)

-- 
1.7.8.rc2.5.g815b

[PATCH 1/4] perf report: add parameter 'start' & 'end' to perf report

[Chenggang Qin]

perf report --start time1 --end time2
The unit of time1 & time2 are millsecond.

Cc: David Ahern <dsahern@gmail.com>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Arnaldo Carvalho de Melo <acme@ghostprotocols.net>
Cc: Arjan van de Ven <arjan@linux.intel.com>
Cc: Namhyung Kim <namhyung@gmail.com>
Cc: Yanmin Zhang <yanmin.zhang@intel.com>
Cc: Wu Fengguang <fengguang.wu@intel.com>
Cc: Mike Galbraith <efault@gmx.de>
Cc: Andrew Morton <akpm@linux-foundation.org>
Signed-off-by: Chenggang Qin <chenggang.qcg@taobao.com>

---
 tools/perf/builtin-report.c |    9 +++++++++
 1 files changed, 9 insertions(+), 0 deletions(-)

diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c
index 72eae74..e9e9d0a 100644
--- a/tools/perf/builtin-report.c
+++ b/tools/perf/builtin-report.c
@@ -733,6 +733,7 @@ int cmd_report(int argc, const char **argv, const char *prefix __maybe_unused)
 {
 	struct perf_session *session;
 	struct stat st;
+	u64 tstart = 0, tend = 0;
 	bool has_br_stack = false;
 	int branch_mode = -1;
 	int ret = -1;
@@ -843,6 +844,8 @@ int cmd_report(int argc, const char **argv, const char *prefix __maybe_unused)
 	OPT_BOOLEAN(0, "mem-mode", &report.mem_mode, "mem access profile"),
 	OPT_CALLBACK(0, "percent-limit", &report, "percent",
 		     "Don't show entries under that percent", parse_percent_limit),
+	OPT_U64(0, "start", &tstart, "Start time of analysis interval. (Unit: ms)"),
+	OPT_U64(0, "end", &tend, "End time of analysis interval. (Unit: ms)"),
 	OPT_END()
 	};
 
@@ -850,6 +853,12 @@ int cmd_report(int argc, const char **argv, const char *prefix __maybe_unused)
 
 	argc = parse_options(argc, argv, options, report_usage, 0);
 
+	if (tend && tstart >= tend) {
+		fprintf(stderr, "start [%" PRIu64 "] is greater than end [%"
+			PRIu64 "].\n", tstart, tend);
+		return -1;
+	}
+
 	if (report.use_stdio)
 		use_browser = 0;
 	else if (report.use_tui)
-- 
1.7.8.rc2.5.g815b

[PATCH 2/4] perf tools: relate 'start' & 'end' to perf_session

[Chenggang Qin]

Copy the value to start and end to struct perf_session.

Cc: David Ahern <dsahern@gmail.com>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Arnaldo Carvalho de Melo <acme@ghostprotocols.net>
Cc: Arjan van de Ven <arjan@linux.intel.com>
Cc: Namhyung Kim <namhyung@gmail.com>
Cc: Yanmin Zhang <yanmin.zhang@intel.com>
Cc: Wu Fengguang <fengguang.wu@intel.com>
Cc: Mike Galbraith <efault@gmx.de>
Cc: Andrew Morton <akpm@linux-foundation.org>
Signed-off-by: Chenggang Qin <chenggang.qcg@taobao.com>

---
 tools/perf/builtin-report.c |    5 +++++
 tools/perf/util/session.c   |    3 +++
 tools/perf/util/session.h   |    2 ++
 3 files changed, 10 insertions(+), 0 deletions(-)

diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c
index e9e9d0a..d3c1c8a 100644
--- a/tools/perf/builtin-report.c
+++ b/tools/perf/builtin-report.c
@@ -889,6 +889,11 @@ repeat:
 	if (session == NULL)
 		return -ENOMEM;
 
+	if (tstart)
+		session->tstart = tstart * 1e6;
+	if (tend)
+		session->tend = tend * 1e6;
+
 	report.session = session;
 
 	has_br_stack = perf_header__has_feat(&session->header,
diff --git a/tools/perf/util/session.c b/tools/perf/util/session.c
index 568b750..193bb6a 100644
--- a/tools/perf/util/session.c
+++ b/tools/perf/util/session.c
@@ -134,6 +134,9 @@ struct perf_session *perf_session__new(const char *filename, int mode,
 	INIT_LIST_HEAD(&self->ordered_samples.to_free);
 	machines__init(&self->machines);
 
+	self->tstart = 0;
+	self->tend = ULLONG_MAX;
+
 	if (mode == O_RDONLY) {
 		if (perf_session__open(self, force) < 0)
 			goto out_delete;
diff --git a/tools/perf/util/session.h b/tools/perf/util/session.h
index 04bf737..c9a6c27 100644
--- a/tools/perf/util/session.h
+++ b/tools/perf/util/session.h
@@ -37,6 +37,8 @@ struct perf_session {
 	int			fd;
 	bool			fd_pipe;
 	bool			repipe;
+	u64			tstart;
+	u64			tend;
 	struct ordered_samples	ordered_samples;
 	char			filename[1];
 };
-- 
1.7.8.rc2.5.g815b

Re: [PATCH 2/4] perf tools: relate 'start' & 'end' to perf_session

[David Ahern]

On 11/1/13, 3:29 AM, Chenggang Qin wrote:
> Copy the value to start and end to struct perf_session.

Why put the times in the session?

David

Re: 答复：[PATCH 2/4] perf tools: relate 'start' & 'end' to perf_session

[David Ahern]

On 11/6/13, 4:23 AM, 秦承刚 wrote:
> Hi David:
> The goal is to simplify transfering the times to function
> perf_session__process_events() and other functions in the sample
> processing path. Session is a parameter throughout the total sample
> processing path.

Right. By putting the time check in session code you are going to be 
dropping samples related to task events too. e.g., a task is created 
after the session is started and before the time window. Samples for the 
task (FORK, MMAP, COMM) will get dropped as will events for other tasks 
(e.g., EXIT). Then samples during the time window will not correlate 
nicely/correctly to a task with a name and maps.

I have patches locally with this same idea -- collect data for a broad 
time window but only show/analyze samples for a specific time window. 
Instead of having the time check in the session code I have it in the 
commands (report, script, etc). e.g., in sample event processing:

     if (perf_time__skip_sample(sample))
         goto out;

where that function has the logic to compare sample timestamps to a user 
given window.

I seem to recall Namhyung send out a patch on time intervals as well.

David

Re: 答复：答复：[PATCH 2/4] perf tools: relate 'start' & 'end' to perf_session

[David Ahern]

On 11/7/13, 5:14 AM, 秦承刚 wrote:
> Hi, David
> The samples for the task before the end of the time window are not
> influenced by the time window. The time window only cover the sample
> events in the ordered_samples. FORK, MMAP, COMM events are not in the
> ordered_samples. They are delivered in the function
> "perf_session__process_event". The task events that are after the end of
> the time window can be ingnored safely.

following builtin-report.c:
perf_session__process_events() -> __perf_session__process_events() --> 
perf_session__process_event():

     ret = perf_evlist__parse_sample(session->evlist, event, &sample);
     if (ret)
         return ret;

     if (tool->ordered_samples) {
         ret = perf_session_queue_event(session, event, &sample,
                            file_offset);
         if (ret != -ETIME)
             return ret;
     }

All samples are dropped into the ordered_samples queue if they have a 
timestamp. And I believe it was the sample_id_all patch that put a 
timestamp on task events too (~2.6.35 or 36 timeframe).


> Would you give me a link to your patch?

https://github.com/dsahern/linux/blob/timehist-timeofday-3.9/tools/perf/util/time-utils.c
and
https://github.com/dsahern/linux/blob/timehist-timeofday-3.9/tools/perf/builtin-timehist.c

I did not push the builtin-report.c change, but it follows directly from 
the timehist command.

David

[PATCH 3/4] perf tools: record min_timestamp of samples queue in ordered_samples

[Chenggang Qin]

Add a field 'min_timestamp' in struct ordered_samples to record the minimial
timestamp of the samples in ordered_samples->samples.

Cc: David Ahern <dsahern@gmail.com>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Arnaldo Carvalho de Melo <acme@ghostprotocols.net>
Cc: Arjan van de Ven <arjan@linux.intel.com>
Cc: Namhyung Kim <namhyung@gmail.com>
Cc: Yanmin Zhang <yanmin.zhang@intel.com>
Cc: Wu Fengguang <fengguang.wu@intel.com>
Cc: Mike Galbraith <efault@gmx.de>
Cc: Andrew Morton <akpm@linux-foundation.org>
Signed-off-by: Chenggang Qin <chenggang.qcg@taobao.com>

---
 tools/perf/util/session.c |    3 +++
 tools/perf/util/session.h |    1 +
 2 files changed, 4 insertions(+), 0 deletions(-)

diff --git a/tools/perf/util/session.c b/tools/perf/util/session.c
index 193bb6a..4e9dd66 100644
--- a/tools/perf/util/session.c
+++ b/tools/perf/util/session.c
@@ -708,6 +708,9 @@ int perf_session_queue_event(struct perf_session *s, union perf_event *event,
 	new->file_offset = file_offset;
 	new->event = event;
 
+	if (list_empty(&os->samples) || os->min_timestamp > timestamp)
+		os->min_timestamp = timestamp;
+
 	__queue_event(new, s);
 
 	return 0;
diff --git a/tools/perf/util/session.h b/tools/perf/util/session.h
index c9a6c27..7d411b9 100644
--- a/tools/perf/util/session.h
+++ b/tools/perf/util/session.h
@@ -18,6 +18,7 @@ struct ordered_samples {
 	u64			last_flush;
 	u64			next_flush;
 	u64			max_timestamp;
+	u64			min_timestamp;
 	struct list_head	samples;
 	struct list_head	sample_cache;
 	struct list_head	to_free;
-- 
1.7.8.rc2.5.g815b

Re: [PATCH 3/4] perf tools: record min_timestamp of samples queue in ordered_samples

[David Ahern]

On 11/1/13, 3:29 AM, Chenggang Qin wrote:
> Add a field 'min_timestamp' in struct ordered_samples to record the minimial
> timestamp of the samples in ordered_samples->samples.

why? How do you intend to use the field?

David

[PATCH 4/4] perf tools: add the feature to assign analysis interval to perf report

[Chenggang Qin]

Only process the samples whose timestamp is in [start, end).

Cc: David Ahern <dsahern@gmail.com>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Arnaldo Carvalho de Melo <acme@ghostprotocols.net>
Cc: Arjan van de Ven <arjan@linux.intel.com>
Cc: Namhyung Kim <namhyung@gmail.com>
Cc: Yanmin Zhang <yanmin.zhang@intel.com>
Cc: Wu Fengguang <fengguang.wu@intel.com>
Cc: Mike Galbraith <efault@gmx.de>
Cc: Andrew Morton <akpm@linux-foundation.org>
Signed-off-by: Chenggang Qin <chenggang.qcg@taobao.com>

---
 tools/perf/util/session.c |   43 +++++++++++++++++++++++++++++++++++++++++--
 1 files changed, 41 insertions(+), 2 deletions(-)

diff --git a/tools/perf/util/session.c b/tools/perf/util/session.c
index 4e9dd66..d50e29e 100644
--- a/tools/perf/util/session.c
+++ b/tools/perf/util/session.c
@@ -532,6 +532,9 @@ static int flush_sample_queue(struct perf_session *s,
 	bool show_progress = limit == ULLONG_MAX;
 	int ret;
 
+	if (limit > s->tend)
+		limit = s->tend;
+
 	if (!tool->ordered_samples || !limit)
 		return 0;
 
@@ -539,6 +542,9 @@ static int flush_sample_queue(struct perf_session *s,
 		if (session_done())
 			return 0;
 
+		if (iter->timestamp < s->tstart)
+			continue;
+
 		if (iter->timestamp > limit)
 			break;
 
@@ -617,7 +623,26 @@ static int process_finished_round(struct perf_tool *tool,
 				  union perf_event *event __maybe_unused,
 				  struct perf_session *session)
 {
-	int ret = flush_sample_queue(session, tool);
+	int ret = 0;
+
+	/*
+	 * The next round should be processed continue.
+	 * But, this round is skipped.
+	 */
+	if (session->ordered_samples.next_flush < session->tstart) {
+		session->ordered_samples.next_flush = session->ordered_samples.max_timestamp;
+		return ret;
+	}
+
+	/*
+	 * This round & all followed rounds are skipped.
+	 */
+	if (session->ordered_samples.min_timestamp > session->tend) {
+		session->ordered_samples.next_flush = ULLONG_MAX;
+		return ret;
+	}
+
+	ret = flush_sample_queue(session, tool);
 	if (!ret)
 		session->ordered_samples.next_flush = session->ordered_samples.max_timestamp;
 
@@ -1373,6 +1398,14 @@ more:
 		goto out_err;
 	}
 
+	/*
+	 * After process a finished round event:
+	 * The minimal timestamp in os->samples is greater than
+	 * tend, so, the followed  events couldn't be processed.
+	 */
+	if (session->ordered_samples.next_flush == ULLONG_MAX)
+		goto out_err;
+
 	head += size;
 	file_pos += size;
 
@@ -1389,8 +1422,14 @@ more:
 	if (file_pos < file_size)
 		goto more;
 
+	if (session->ordered_samples.max_timestamp < session->tstart)
+		goto out_err;
+
+	if (session->ordered_samples.min_timestamp > session->tend)
+		goto out_err;
+
 	/* do the final flush for ordered samples */
-	session->ordered_samples.next_flush = ULLONG_MAX;
+	session->ordered_samples.next_flush = session->tend;
 	err = flush_sample_queue(session, tool);
 out_err:
 	ui_progress__finish();
-- 
1.7.8.rc2.5.g815b

Re: [PATCH 0/4] perf report: add parameters 'start' & 'end' to specify analysis interval

[Ingo Molnar]

* Chenggang Qin <chenggang.qin@gmail.com> wrote:

> This patch set introduced a feature to analysis the samples in a specified time
> interval.
> After perf.data file was generated by perf record, the user could want to
> analysis a sub time interval of the whole record period.
> For some functions, the percent of its samples in a certain sub time interval is
> different from the percent in the total record period. Showing the scene in a
> certain time interval could allow users to more easily troubleshoot performance
> problems. The sample's timestamp are recorded in the perf.data file. The samples
> are sorted in the ordered_samples by timestamp while perf report processed them.
> So, it is easily to search the samples whose timestamp are in a certain time
> interval.
> We add 2 paramters --start and --end to specify the time interval.
> perf report --start xxxxx --end xxxxx
> The smallest granularity of time interval is millsecond.
> For example:
> If the whole record period of a perf.data file is 10000 to 20000, we can use the
> following command to analysis the samples between [15000, 16000).
> perf report --start 15000 --end 16000
> The time is the uptime, it start timing from the system starts.
> 
> Cc: David Ahern <dsahern@gmail.com>
> Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
> Cc: Paul Mackerras <paulus@samba.org>
> Cc: Ingo Molnar <mingo@redhat.com>
> Cc: Arnaldo Carvalho de Melo <acme@ghostprotocols.net>
> Cc: Arjan van de Ven <arjan@linux.intel.com>
> Cc: Namhyung Kim <namhyung@gmail.com>
> Cc: Yanmin Zhang <yanmin.zhang@intel.com>
> Cc: Wu Fengguang <fengguang.wu@intel.com>
> Cc: Mike Galbraith <efault@gmx.de>
> Cc: Andrew Morton <akpm@linux-foundation.org>
> Signed-off-by: Chenggang Qin <chenggang.qcg@taobao.com>
> 
> Chenggang Qin (4):
>   perf tools: add parameter 'start' & 'end' to perf report
>   perf tools: relate 'start' & 'end' to perf_session
>   perf tools: record min_timestamp of samples queue in ordered_samples
>   perf tools: add the feature to assign analysis interval to perf
>     report
> 
>  tools/perf/builtin-report.c |   14 ++++++++++++
>  tools/perf/util/session.c   |   49 +++++++++++++++++++++++++++++++++++++++++-
>  tools/perf/util/session.h   |    3 ++
>  3 files changed, 64 insertions(+), 2 deletions(-)

Looks useful - but right now this has to be used 'blindly', without 
knowing _which_ portion of the perf.data is 'interesting'.

That problem could be resolved by allowing direct manipulation of 
the start/end interval via the GTK front end: a small graph could 
show the 'sample graph', with two sliders specifying the reported 
interval?

Something like this, at the top of the window:

  ---------------------------------------------------------------
  |                                                             |
  |    ....                        .....                        |
  | ..      .            ...    .         .                     |
  |          .       ...    .  .            .    .              |
  |            .....         ..               ..  .... .... ..  |
  |                          [1]             [2]                |
  ---------------------------------------------------------------
  |
  |   Usual perf report GTK output
  |
  |   ....
  |

The 'graph' might be anything that visualizes the time axis of the 
perf.data: a sample frequency visualization for example, or maybe a 
simple task activity graph based on fork/exec/exit data, with some 
simple time display included as well (a vertical marker every 
minute/second or so).

The [1] and [2] markers demark the two sliders, which in the above 
mockup example show an 'interesting' portion of the profile with a 
lot of samples.

With such a solution the feature you add would be very useful 
indeed, I'd even argue for the data file time-axis visualization to 
be enabled by default, with the initial start/end interval covering 
the whole perf.data, but the sliders being just a mouse-drag away 
from being changed.

Thanks,

	Ingo