Re: [PATCH 0/4] perf, pt, coresight: AUX flags and VMX update

[Arnaldo Carvalho de Melo <acme@kernel.org>]

Em Mon, Feb 20, 2017 at 05:39:43PM +0200, Adrian Hunter escreveu:
> On 20/02/17 17:18, Alexander Shishkin wrote:
> > Alexander Shishkin <alexander.shishkin@linux.intel.com> writes:
> > 
> >> With the vmm_exclusive=0, PT seems to be much more usable on BDW now. This
> >> patchset does three things:
> >>  * adds a flag to PERF_RECORD_AUX, signalling that a transaction has gaps
> >>    in it (due to VMX root mode kicking in),
> > 
> > In the above context, will something like this be fine?
 
> Looks fine to me.
 
> Acked-by: Adrian Hunter <adrian.hunter@intel.com>
> 
> > From: Alexander Shishkin <alexander.shishkin@linux.intel.com>
> > Subject: [PATCH] perf tools: Handle partial AUX records and print a warning

> > This patch decodes the 'partial' flag in AUX records and prints
> > a warning to the user, so that they don't have to guess why their
> > PT traces contain gaps (or missing altogether):

> >> Warning:
> >> AUX data had gaps in it 6 times out of 8!

The above should be left for a more verbose mode?

> >> Are you running a KVM guest in the background?

The warning should be a bit more precise, as you said, tuning
vmm_exclusive is key here, i.e.:

"Are you running a KVM guest in the background with
kvm_intel.vmm_exclusive=1?"

And that we can even figure out, its just a matter of reading:

[root@jouet ~]# cat /sys/module/kvm_intel/parameters/vmm_exclusive
Y

I have tested after setting that using:

 modprobe kvm_intel vmm_exclusive=n

And I was able to get Intel PT records from a workload.

So perhaps we can get this patch in, which improves the situation, and
then, on top of it do these extra checks and give proper hints, ok?

- Arnaldo
 
> > Currently this is the only reason for partial records.
> > 
> > Cc: Adrian Hunter <adrian.hunter@intel.com>
> > Signed-off-by: Alexander Shishkin <alexander.shishkin@linux.intel.com>
> > ---
> >  tools/include/uapi/linux/perf_event.h |  1 +
> >  tools/perf/util/event.c               |  5 +++--
> >  tools/perf/util/event.h               |  1 +
> >  tools/perf/util/session.c             | 17 ++++++++++++++---
> >  4 files changed, 19 insertions(+), 5 deletions(-)
> > 
> > diff --git a/tools/include/uapi/linux/perf_event.h b/tools/include/uapi/linux/perf_event.h
> > index c66a485a24..8306415207 100644
> > --- a/tools/include/uapi/linux/perf_event.h
> > +++ b/tools/include/uapi/linux/perf_event.h
> > @@ -885,6 +885,7 @@ enum perf_callchain_context {
> >   */
> >  #define PERF_AUX_FLAG_TRUNCATED		0x01	/* record was truncated to fit */
> >  #define PERF_AUX_FLAG_OVERWRITE		0x02	/* snapshot from overwrite mode */
> > +#define PERF_AUX_FLAG_PARTIAL		0x04	/* record contains gaps */
> >  
> >  #define PERF_FLAG_FD_NO_GROUP		(1UL << 0)
> >  #define PERF_FLAG_FD_OUTPUT		(1UL << 1)
> > diff --git a/tools/perf/util/event.c b/tools/perf/util/event.c
> > index 4ea7ce72ed..ba193cd019 100644
> > --- a/tools/perf/util/event.c
> > +++ b/tools/perf/util/event.c
> > @@ -1153,11 +1153,12 @@ int perf_event__process_exit(struct perf_tool *tool __maybe_unused,
> >  
> >  size_t perf_event__fprintf_aux(union perf_event *event, FILE *fp)
> >  {
> > -	return fprintf(fp, " offset: %#"PRIx64" size: %#"PRIx64" flags: %#"PRIx64" [%s%s]\n",
> > +	return fprintf(fp, " offset: %#"PRIx64" size: %#"PRIx64" flags: %#"PRIx64" [%s%s%s]\n",
> >  		       event->aux.aux_offset, event->aux.aux_size,
> >  		       event->aux.flags,
> >  		       event->aux.flags & PERF_AUX_FLAG_TRUNCATED ? "T" : "",
> > -		       event->aux.flags & PERF_AUX_FLAG_OVERWRITE ? "O" : "");
> > +		       event->aux.flags & PERF_AUX_FLAG_OVERWRITE ? "O" : "",
> > +		       event->aux.flags & PERF_AUX_FLAG_PARTIAL   ? "P" : "");
> >  }
> >  
> >  size_t perf_event__fprintf_itrace_start(union perf_event *event, FILE *fp)
> > diff --git a/tools/perf/util/event.h b/tools/perf/util/event.h
> > index c735c53a26..d7e53fe176 100644
> > --- a/tools/perf/util/event.h
> > +++ b/tools/perf/util/event.h
> > @@ -269,6 +269,7 @@ struct events_stats {
> >  	u64 total_lost;
> >  	u64 total_lost_samples;
> >  	u64 total_aux_lost;
> > +	u64 total_aux_partial;
> >  	u64 total_invalid_chains;
> >  	u32 nr_events[PERF_RECORD_HEADER_MAX];
> >  	u32 nr_non_filtered_samples;
> > diff --git a/tools/perf/util/session.c b/tools/perf/util/session.c
> > index 4cdbc8f5f1..abdb797fa4 100644
> > --- a/tools/perf/util/session.c
> > +++ b/tools/perf/util/session.c
> > @@ -1258,9 +1258,12 @@ static int machines__deliver_event(struct machines *machines,
> >  	case PERF_RECORD_UNTHROTTLE:
> >  		return tool->unthrottle(tool, event, sample, machine);
> >  	case PERF_RECORD_AUX:
> > -		if (tool->aux == perf_event__process_aux &&
> > -		    (event->aux.flags & PERF_AUX_FLAG_TRUNCATED))
> > -			evlist->stats.total_aux_lost += 1;
> > +		if (tool->aux == perf_event__process_aux) {
> > +			if (event->aux.flags & PERF_AUX_FLAG_TRUNCATED)
> > +				evlist->stats.total_aux_lost += 1;
> > +			if (event->aux.flags & PERF_AUX_FLAG_PARTIAL)
> > +				evlist->stats.total_aux_partial += 1;
> > +		}
> >  		return tool->aux(tool, event, sample, machine);
> >  	case PERF_RECORD_ITRACE_START:
> >  		return tool->itrace_start(tool, event, sample, machine);
> > @@ -1548,6 +1551,14 @@ static void perf_session__warn_about_errors(const struct perf_session *session)
> >  			    stats->nr_events[PERF_RECORD_AUX]);
> >  	}
> >  
> > +	if (session->tool->aux == perf_event__process_aux &&
> > +	    stats->total_aux_partial != 0) {
> > +		ui__warning("AUX data had gaps in it %" PRIu64 " times out of %u!\n\n"
> > +		            "Are you running a KVM guest in the background?\n\n",
> > +			    stats->total_aux_partial,
> > +			    stats->nr_events[PERF_RECORD_AUX]);
> > +	}
> > +
> >  	if (stats->nr_unknown_events != 0) {
> >  		ui__warning("Found %u unknown events!\n\n"
> >  			    "Is this an older tool processing a perf.data "
> >