From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1755248AbdCPQmG (ORCPT ); Thu, 16 Mar 2017 12:42:06 -0400 Received: from mga03.intel.com ([134.134.136.65]:28974 "EHLO mga03.intel.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1753443AbdCPQmE (ORCPT ); Thu, 16 Mar 2017 12:42:04 -0400 X-ExtLoop1: 1 X-IronPort-AV: E=Sophos;i="5.36,173,1486454400"; d="scan'208";a="1109246426" From: Alexander Shishkin To: Arnaldo Carvalho de Melo Cc: Adrian Hunter , Arnaldo Carvalho de Melo , linux-kernel@vger.kernel.org, vince@deater.net, eranian@google.com, Peter Zijlstra , Ingo Molnar Subject: Re: [PATCH 0/4] perf, pt, coresight: AUX flags and VMX update In-Reply-To: <20170220160946.GL4109@kernel.org> References: <20170220133352.17995-1-alexander.shishkin@linux.intel.com> <87ino4j3gr.fsf@ashishki-desk.ger.corp.intel.com> <20170220160946.GL4109@kernel.org> User-Agent: Notmuch/0.23.5 (http://notmuchmail.org) Emacs/24.5.1 (x86_64-pc-linux-gnu) Date: Thu, 16 Mar 2017 18:41:59 +0200 Message-ID: <8760j941ig.fsf@ashishki-desk.ger.corp.intel.com> MIME-Version: 1.0 Content-Type: text/plain Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Arnaldo Carvalho de Melo writes: > Em Mon, Feb 20, 2017 at 05:39:43PM +0200, Adrian Hunter escreveu: >> On 20/02/17 17:18, Alexander Shishkin wrote: >> > Alexander Shishkin 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 >> >> > From: Alexander Shishkin >> > 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? Other similar warnings come at the default verbosity level (that is, same as this one), so I thought I'd just follow their example. It's useful information though, you can make deductions based on how many records are 'partial'. If it's all of them, then you should likely stop trying to trace kvm process, for example. >> >> 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 Indeed, how about something like below? I'm kind of new to wording user-friendly warnings, but the general idea is like what you're suggesting. >>From cdd8fc60c2f82250871b84b4ac0841f740719f49 Mon Sep 17 00:00:00 2001 From: Alexander Shishkin Date: Mon, 20 Feb 2017 17:08:53 +0200 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 8 times out of 8! > > Are you running a KVM guest in the background? Trying to be even more helpful, we will detect if the user's kvm driver sets up exclusive VMX root mode for the entire lifespan of the kvm process: > Reloading kvm_intel module with vmm_exclusive=0 > will reduce the gaps to only guest's timeslices. Note however, that you'll still have gaps in cpu-wide traces even with vmm_exclusive=0, but the number of gaps will be below 100% (as opposed to the above example). Currently this is the only reason for partial records. Cc: Adrian Hunter Signed-off-by: Alexander Shishkin --- tools/include/uapi/linux/perf_event.h | 1 + tools/lib/api/fs/fs.c | 29 +++++++++++++++++++++++++++++ tools/lib/api/fs/fs.h | 1 + tools/perf/util/event.c | 5 +++-- tools/perf/util/event.h | 1 + tools/perf/util/session.c | 27 ++++++++++++++++++++++++--- 6 files changed, 59 insertions(+), 5 deletions(-) diff --git a/tools/include/uapi/linux/perf_event.h b/tools/include/uapi/linux/perf_event.h index bec0aad0e1..d09a9cd021 100644 --- a/tools/include/uapi/linux/perf_event.h +++ b/tools/include/uapi/linux/perf_event.h @@ -915,6 +915,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/lib/api/fs/fs.c b/tools/lib/api/fs/fs.c index 4b6bfc43cc..809c7721cd 100644 --- a/tools/lib/api/fs/fs.c +++ b/tools/lib/api/fs/fs.c @@ -439,6 +439,35 @@ int sysfs__read_str(const char *entry, char **buf, size_t *sizep) return filename__read_str(path, buf, sizep); } +int sysfs__read_bool(const char *entry, bool *value) +{ + char *buf; + size_t size; + int ret; + + ret = sysfs__read_str(entry, &buf, &size); + if (ret < 0) + return ret; + + switch (buf[0]) { + case '1': + case 'y': + case 'Y': + *value = true; + break; + case '0': + case 'n': + case 'N': + *value = false; + break; + default: + ret = -1; + } + + free(buf); + + return ret; +} int sysctl__read_int(const char *sysctl, int *value) { char path[PATH_MAX]; diff --git a/tools/lib/api/fs/fs.h b/tools/lib/api/fs/fs.h index 6b332dc744..956c21127d 100644 --- a/tools/lib/api/fs/fs.h +++ b/tools/lib/api/fs/fs.h @@ -37,4 +37,5 @@ int sysctl__read_int(const char *sysctl, int *value); int sysfs__read_int(const char *entry, int *value); int sysfs__read_ull(const char *entry, unsigned long long *value); int sysfs__read_str(const char *entry, char **buf, size_t *sizep); +int sysfs__read_bool(const char *entry, bool *value); #endif /* __API_FS__ */ diff --git a/tools/perf/util/event.c b/tools/perf/util/event.c index d082cb7044..a042822834 100644 --- a/tools/perf/util/event.c +++ b/tools/perf/util/event.c @@ -1288,11 +1288,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 e1d8166ebb..eb7a7b2007 100644 --- a/tools/perf/util/event.h +++ b/tools/perf/util/event.h @@ -276,6 +276,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 ae42e742d4..24259bc2c5 100644 --- a/tools/perf/util/session.c +++ b/tools/perf/util/session.c @@ -1,5 +1,6 @@ #include #include +#include #include #include @@ -1260,9 +1261,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); @@ -1555,6 +1559,23 @@ 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) { + bool vmm_exclusive = false; + + (void)sysfs__read_bool("module/kvm_intel/parameters/vmm_exclusive", + &vmm_exclusive); + + ui__warning("AUX data had gaps in it %" PRIu64 " times out of %u!\n\n" + "Are you running a KVM guest in the background?%s\n\n", + stats->total_aux_partial, + stats->nr_events[PERF_RECORD_AUX], + vmm_exclusive ? + "\nReloading kvm_intel module with vmm_exclusive=0\n" + "will reduce the gaps to only guest's timeslices." : + ""); + } + if (stats->nr_unknown_events != 0) { ui__warning("Found %u unknown events!\n\n" "Is this an older tool processing a perf.data " -- 2.11.0