[PATCH] perf record: Set timestamp boundary for AUX area events

[PATCH] perf record: Set timestamp boundary for AUX area events

[Adrian Hunter]

AUX area data is not processed by 'perf record' and consequently the
 --timestamp-boundary option may result in no values for "time of first
sample" and "time of last sample". However there are non-sample events
that can be used instead, namely 'itrace_start' and 'aux'.
'itrace_start' is issued before tracing starts, and 'aux' is issued
every time data is ready.

Implement tool callbacks for those two for 'perf record', to update the
timestamp boundary.

Example:

 $ perf record -e intel_pt//u --timestamp-boundary uname
 Linux
 [ perf record: Woken up 1 times to write data ]
 [ perf record: Captured and wrote 0.022 MB perf.data ]
 $ perf script --header-only | grep "time of"
 # time of first sample : 4574.835541
 # time of last sample : 4574.835907
 $ perf script --itrace=be -F-ip | head -1
           uname 13752 [001]  4574.835589:          1 branches:uH:
 $ perf script --itrace=be -F-ip | tail -1
           uname 13752 [001]  4574.835867:          1 branches:uH:
 $

Signed-off-by: Adrian Hunter <adrian.hunter@intel.com>
---
 tools/perf/builtin-record.c | 27 +++++++++++++++++++++++----
 1 file changed, 23 insertions(+), 4 deletions(-)

diff --git a/tools/perf/builtin-record.c b/tools/perf/builtin-record.c
index 5fb9665a2ec2..78e6c9e48379 100644
--- a/tools/perf/builtin-record.c
+++ b/tools/perf/builtin-record.c
@@ -967,6 +967,15 @@ static int record__open(struct record *rec)
 	return rc;
 }
 
+static void set_timestamp_boundary(struct record *rec, u64 sample_time)
+{
+	if (rec->evlist->first_sample_time == 0)
+		rec->evlist->first_sample_time = sample_time;
+
+	if (sample_time)
+		rec->evlist->last_sample_time = sample_time;
+}
+
 static int process_sample_event(struct perf_tool *tool,
 				union perf_event *event,
 				struct perf_sample *sample,
@@ -975,10 +984,7 @@ static int process_sample_event(struct perf_tool *tool,
 {
 	struct record *rec = container_of(tool, struct record, tool);
 
-	if (rec->evlist->first_sample_time == 0)
-		rec->evlist->first_sample_time = sample->time;
-
-	rec->evlist->last_sample_time = sample->time;
+	set_timestamp_boundary(rec, sample->time);
 
 	if (rec->buildid_all)
 		return 0;
@@ -2372,6 +2378,17 @@ static int build_id__process_mmap2(struct perf_tool *tool, union perf_event *eve
 	return perf_event__process_mmap2(tool, event, sample, machine);
 }
 
+static int process_timestamp_boundary(struct perf_tool *tool,
+				      union perf_event *event __maybe_unused,
+				      struct perf_sample *sample,
+				      struct machine *machine __maybe_unused)
+{
+	struct record *rec = container_of(tool, struct record, tool);
+
+	set_timestamp_boundary(rec, sample->time);
+	return 0;
+}
+
 /*
  * XXX Ideally would be local to cmd_record() and passed to a record__new
  * because we need to have access to it in record__exit, that is called
@@ -2406,6 +2423,8 @@ static struct record record = {
 		.namespaces	= perf_event__process_namespaces,
 		.mmap		= build_id__process_mmap,
 		.mmap2		= build_id__process_mmap2,
+		.itrace_start	= process_timestamp_boundary,
+		.aux		= process_timestamp_boundary,
 		.ordered_events	= true,
 	},
 };
-- 
2.17.1

Re: [PATCH] perf record: Set timestamp boundary for AUX area events

[Andi Kleen]

On Mon, May 03, 2021 at 09:42:22AM +0300, Adrian Hunter wrote:
> AUX area data is not processed by 'perf record' and consequently the
>  --timestamp-boundary option may result in no values for "time of first
> sample" and "time of last sample". However there are non-sample events
> that can be used instead, namely 'itrace_start' and 'aux'.
> 'itrace_start' is issued before tracing starts, and 'aux' is issued
> every time data is ready.

Hmm, what happens when some other non PT events are in the same perf record?
And those maybe run at different times than PT (e.g. due to some PT specific
filter).  Does this all work correctly then?

-Andi

Re: [PATCH] perf record: Set timestamp boundary for AUX area events

[Adrian Hunter]

On 3/05/21 5:56 pm, Andi Kleen wrote:
> On Mon, May 03, 2021 at 09:42:22AM +0300, Adrian Hunter wrote:
>> AUX area data is not processed by 'perf record' and consequently the
>>  --timestamp-boundary option may result in no values for "time of first
>> sample" and "time of last sample". However there are non-sample events
>> that can be used instead, namely 'itrace_start' and 'aux'.

"instead" -> "as well"

>> 'itrace_start' is issued before tracing starts, and 'aux' is issued
>> every time data is ready.
> 
> Hmm, what happens when some other non PT events are in the same perf record?

The sample timestamps are still processed, so the lowest sample timestamp or
'itrace_start' timestamp or 'aux' timestamp is the start.  Similarly for the end.

> And those maybe run at different times than PT (e.g. due to some PT specific
> filter).  Does this all work correctly then?

The broadest range is used

Re: [PATCH] perf record: Set timestamp boundary for AUX area events

[Andi Kleen]

On Mon, May 03, 2021 at 06:06:38PM +0300, Adrian Hunter wrote:
> On 3/05/21 5:56 pm, Andi Kleen wrote:
> > On Mon, May 03, 2021 at 09:42:22AM +0300, Adrian Hunter wrote:
> >> AUX area data is not processed by 'perf record' and consequently the
> >>  --timestamp-boundary option may result in no values for "time of first
> >> sample" and "time of last sample". However there are non-sample events
> >> that can be used instead, namely 'itrace_start' and 'aux'.
> 
> "instead" -> "as well"
> 
> >> 'itrace_start' is issued before tracing starts, and 'aux' is issued
> >> every time data is ready.
> > 
> > Hmm, what happens when some other non PT events are in the same perf record?
> 
> The sample timestamps are still processed, so the lowest sample timestamp or
> 'itrace_start' timestamp or 'aux' timestamp is the start.  Similarly for the end.
> 
> > And those maybe run at different times than PT (e.g. due to some PT specific
> > filter).  Does this all work correctly then?
> 
> The broadest range is used

Ok makes sense.

Acked-by: Andi Kleen <ak@linux.intel.com>

-Andi

Re: [PATCH] perf record: Set timestamp boundary for AUX area events

[Arnaldo Carvalho de Melo]

Em Mon, May 03, 2021 at 09:11:31AM -0700, Andi Kleen escreveu:
> On Mon, May 03, 2021 at 06:06:38PM +0300, Adrian Hunter wrote:
> > On 3/05/21 5:56 pm, Andi Kleen wrote:
> > > On Mon, May 03, 2021 at 09:42:22AM +0300, Adrian Hunter wrote:
> > >> AUX area data is not processed by 'perf record' and consequently the
> > >>  --timestamp-boundary option may result in no values for "time of first
> > >> sample" and "time of last sample". However there are non-sample events
> > >> that can be used instead, namely 'itrace_start' and 'aux'.
> > 
> > "instead" -> "as well"
> > 
> > >> 'itrace_start' is issued before tracing starts, and 'aux' is issued
> > >> every time data is ready.
> > > 
> > > Hmm, what happens when some other non PT events are in the same perf record?
> > 
> > The sample timestamps are still processed, so the lowest sample timestamp or
> > 'itrace_start' timestamp or 'aux' timestamp is the start.  Similarly for the end.
> > 
> > > And those maybe run at different times than PT (e.g. due to some PT specific
> > > filter).  Does this all work correctly then?
> > 
> > The broadest range is used
> 
> Ok makes sense.
> 
> Acked-by: Andi Kleen <ak@linux.intel.com>

Thanks, applied.

- Arnaldo