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

From: Arnaldo Carvalho de Melo
Date: Mon Feb 20 2017 - 11:10:17 EST


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@xxxxxxxxxxxxxxx> 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@xxxxxxxxx>
>
> > From: Alexander Shishkin <alexander.shishkin@xxxxxxxxxxxxxxx>
> > 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@xxxxxxxxx>
> > Signed-off-by: Alexander Shishkin <alexander.shishkin@xxxxxxxxxxxxxxx>
> > ---
> > 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 "
> >