[PATCH v1 3/4] perf record: Skip don't fail for events that don't open
Ian Rogers
irogers at google.com
Tue Nov 12 08:25:13 PST 2024
On Tue, Nov 12, 2024 at 6:12 AM James Clark <james.clark at linaro.org> wrote:
>
>
>
> On 11/11/2024 5:00 pm, Ian Rogers wrote:
> > On Mon, Nov 11, 2024 at 7:49 AM James Clark <james.clark at linaro.org> wrote:
> >>
> >>
> >>
> >> On 26/10/2024 1:17 pm, Ian Rogers wrote:
> >>> Whilst for many tools it is an expected behavior that failure to open
> >>> a perf event is a failure, ARM decided to name PMU events the same as
> >>> legacy events and then failed to rename such events on a server uncore
> >>> SLC PMU. As perf's default behavior when no PMU is specified is to
> >>> open the event on all PMUs that advertise/"have" the event, this
> >>> yielded failures when trying to make the priority of legacy and
> >>> sysfs/json events uniform - something requested by RISC-V and ARM. A
> >>> legacy event user on ARM hardware may find their event opened on an
> >>> uncore PMU which for perf record will fail. Arnaldo suggested skipping
> >>> such events which this patch implements. Rather than have the skipping
> >>> conditional on running on ARM, the skipping is done on all
> >>> architectures as such a fundamental behavioral difference could lead
> >>> to problems with tools built/depending on perf.
> >>>
> >>> An example of perf record failing to open events on x86 is:
> >>> ```
> >>> $ perf record -e data_read,cycles,LLC-prefetch-read -a sleep 0.1
> >>> Error:
> >>> Failure to open event 'data_read' on PMU 'uncore_imc_free_running_0' which will be removed.
> >>> The sys_perf_event_open() syscall returned with 22 (Invalid argument) for event (data_read).
> >>> "dmesg | grep -i perf" may provide additional information.
> >>>
> >>> Error:
> >>> Failure to open event 'data_read' on PMU 'uncore_imc_free_running_1' which will be removed.
> >>> The sys_perf_event_open() syscall returned with 22 (Invalid argument) for event (data_read).
> >>> "dmesg | grep -i perf" may provide additional information.
> >>>
> >>
> >> This makes me wonder if this message was overly wordy to begin with.
> >> This line is fine:
> >>
> >> Failure to open event 'data_read' on PMU 'uncore_imc_free_running_0'
> >> which will be removed.
> >>
> >> The next bit about the syscall just repeats. The exit code could be
> >> included on the previous line. And the dmesg bit is general advice that
> >> could possibly be printed once at the end.
> >
> > Thanks for the time spent investigating this!
> >
> > I agree on this. I wonder if we should have short and long messages,
> > or message+help like we do for parse events. One patch series like
> > this is improving EBUSY:
> > https://lore.kernel.org/lkml/20241106003007.2112584-1-ctshao@google.com/
> > The issue with printing at the end is knowing where/when the end is.
> > Printing once is easy enough.
> >
> >>> Error:
> >>> Failure to open event 'LLC-prefetch-read' on PMU 'cpu' which will be removed.
> >>> The LLC-prefetch-read event is not supported.
> >>> [ perf record: Woken up 1 times to write data ]
> >>> [ perf record: Captured and wrote 2.188 MB perf.data (87 samples) ]
> >>>
> >>> $ perf report --stats
> >>> Aggregated stats:
> >>> TOTAL events: 17255
> >>> MMAP events: 284 ( 1.6%)
> >>> COMM events: 1961 (11.4%)
> >>> EXIT events: 1 ( 0.0%)
> >>> FORK events: 1960 (11.4%)
> >>> SAMPLE events: 87 ( 0.5%)
> >>> MMAP2 events: 12836 (74.4%)
> >>> KSYMBOL events: 83 ( 0.5%)
> >>> BPF_EVENT events: 36 ( 0.2%)
> >>> FINISHED_ROUND events: 2 ( 0.0%)
> >>> ID_INDEX events: 1 ( 0.0%)
> >>> THREAD_MAP events: 1 ( 0.0%)
> >>> CPU_MAP events: 1 ( 0.0%)
> >>> TIME_CONV events: 1 ( 0.0%)
> >>> FINISHED_INIT events: 1 ( 0.0%)
> >>> cycles stats:
> >>> SAMPLE events: 87
> >>> ```
> >>>
> >>> Note, if all events fail to open then the data file will contain no
> >>> samples. This is deliberate as at the point the events are opened
> >>> there are other events, such as the dummy event for sideband data, and
> >>> these events will succeed in opening even if the user specified ones
> >>
> >> Is a file with only sideband events useful? Is it possible to fail the
> >> record command if the event doesn't open anywhere?
> >>
> >> I noticed this leads to some different behavior and a libperf warning
> >> when you have paranoid=3:
> >>
> >> $ perf record -e cycles -C 0 -- true
> >>
> >> Error:
> >> Failure to open event 'cpu_atom/cycles/u' on PMU 'cpu_atom' which will
> >> be removed.
> >> ...
> >> Consider adjusting /proc/sys/kernel/perf_event_paranoid setting
> >> ...
> >> libperf: Miscounted nr_mmaps 0 vs 28
> >> WARNING: No sample_id_all support, falling back to unordered
> >> processing
> >> [ perf record: Woken up 1 times to write data ]
> >> [ perf record: Captured and wrote 0.021 MB perf.data ]
> >
> > So paranoid=3 is a Debian extension that Peter Z doesn't agree with
> > and so isn't enabled in regular kernels. So we're dealing with cycles,
> > which we'd expect to open or fall-back to a software event like
> > task-clock. It feels like things could happen better here but that's
> > not necessarily the fault of this patch.
> >
>
> paranoid=3 is a bit of a red-herring. I actually meant any paranoid
> value other than -1. The important part is "-C 0" because only root is
> allowed to open on a CPU. Or "-a" also causes the issue.
>
> Previously you got the command failure and the hint about the paranoid
> value, but now you get the libperf error too and it still makes the file.
>
> I still don't think a file with only sideband events is useful, I don't
> think there's even a commandline that you can run currently that results
> in that? You always need at least one event to open for it to succeed
> and I'm thinking we could keep that.
You can currently do `perf record -e dummy ...` for example in this
ARM SPE test (I see similar in offcpu, attr test, intel_pt, switch
tracking):
https://git.kernel.org/pub/scm/linux/kernel/git/perf/perf-tools-next.git/tree/tools/perf/tests/shell/test_arm_spe.sh?h=perf-tools-next#n94
If we add a condition that an evlist with only sideband events is
erroneous, and fail perf record, then I think that will break these
expectations. Any change like that would at least need to fix up the
tests, but the tests could be a good indicator that users are also
doing things like this and that may lead to complaints.
> It would be nice to fix the libperf warning too because it's warning
> about something that was already warned about.
Do you have something in mind to clean up the warning? Perhaps you can
send it as a patch.
> >>> don't. Having a mix of open and broken events leads to a problem of
> >>> identifying different sources of events.
> >> >
> >>
> >> In my basic test I saw that the opened event was identified correctly in
> >> perf report, unless you have an example that you encountered that we
> >> should fix?
> >
> > I didn't find any but we also don't tend to test failing to open
> > events. I could imagine things failing in `perf test` on neoverse
> > testing given the l3 advertising the cycles event.
> >
> >> One place I saw an issue was with auxtrace events. If there's an event
> >> name clash then you're likely to not be able to open the file afterwards
> >> because the auxtrace code can't handle an event that didn't open. But I
> >> don't know of any name clashes there (I just faked one for testing), and
> >> maybe that could be fixed up later in the auxtrace code if there is ever
> >> a real one.
> >>
> >> Other than the above it does seem to work ok.
> >
> > Cool, can this be taken as a Tested-by?
> >
>
> Yep, although with a caveat that I faked the second cycles PMU that
> wouldn't open, but I don't think that should make a difference:
>
> Tested-by: James Clark <james.clark at linaro.org>
Thanks James, as this patch is before reapplying the "Prefer
sysfs/JSON hardware events over legacy" patch, can I take it that the
tag is for the whole series?
> I can also test with the real thing if you like but would take a bit
> longer as I have to borrow it off Leo.
More testing is always good.
Thanks,
Ian
> > Thanks,
> > Ian
> >
> >>> The issue with legacy events is that on RISC-V they want the driver to
> >>> not have mappings from legacy to non-legacy config encodings for each
> >>> vendor/model due to size, complexity and difficulty to update. It was
> >>> reported that on ARM Apple-M? CPUs the legacy mapping in the driver
> >>> was broken and the sysfs/json events should always take precedent,
> >>> however, it isn't clear this is still the case. It is the case that
> >>> without working around this issue a legacy event like cycles without a
> >>> PMU can encode differently than when specified with a PMU - the
> >>> non-PMU version favoring legacy encodings, the PMU one avoiding legacy
> >>> encodings.
> >>>
> >>> The patch removes events and then adjusts the idx value for each
> >>> evsel. This is done so that the dense xyarrays used for file
> >>> descriptors, etc. don't contain broken entries. As event opening
> >>> happens relatively late in the record process, use of the idx value
> >>> before the open will have become corrupted, so it is expected there
> >>> are latent bugs hidden behind this change - the change is best
> >>> effort. As the only vendor that has broken event names is ARM, this
> >>> will principally effect ARM users. They will also experience warning
> >>> messages like those above because of the uncore PMU advertising legacy
> >>> event names.
> >>
> >>
> >>
> >>>
> >>> Suggested-by: Arnaldo Carvalho de Melo <acme at kernel.org>
> >>> Signed-off-by: Ian Rogers <irogers at google.com>
> >>> ---
> >>> tools/perf/builtin-record.c | 22 +++++++++++++++++-----
> >>> 1 file changed, 17 insertions(+), 5 deletions(-)
> >>>
> >>> diff --git a/tools/perf/builtin-record.c b/tools/perf/builtin-record.c
> >>> index f83252472921..7e99743f7e42 100644
> >>> --- a/tools/perf/builtin-record.c
> >>> +++ b/tools/perf/builtin-record.c
> >>> @@ -1364,6 +1364,7 @@ static int record__open(struct record *rec)
> >>> struct perf_session *session = rec->session;
> >>> struct record_opts *opts = &rec->opts;
> >>> int rc = 0;
> >>> + bool skipped = false;
> >>>
> >>> evlist__for_each_entry(evlist, pos) {
> >>> try_again:
> >>> @@ -1379,15 +1380,26 @@ static int record__open(struct record *rec)
> >>> pos = evlist__reset_weak_group(evlist, pos, true);
> >>> goto try_again;
> >>> }
> >>> - rc = -errno;
> >>> evsel__open_strerror(pos, &opts->target, errno, msg, sizeof(msg));
> >>> - ui__error("%s\n", msg);
> >>> - goto out;
> >>> + ui__error("Failure to open event '%s' on PMU '%s' which will be removed.\n%s\n",
> >>> + evsel__name(pos), evsel__pmu_name(pos), msg);
> >>> + pos->skippable = true;
> >>> + skipped = true;
> >>> + } else {
> >>> + pos->supported = true;
> >>> }
> >>> -
> >>> - pos->supported = true;
> >>> }
> >>>
> >>> + if (skipped) {
> >>> + struct evsel *tmp;
> >>> + int idx = 0;
> >>> +
> >>> + evlist__for_each_entry_safe(evlist, tmp, pos) {
> >>> + if (pos->skippable)
> >>> + evlist__remove(evlist, pos);
> >>> + pos->core.idx = idx++;
> >>> + }
> >>> + }
> >>> if (symbol_conf.kptr_restrict && !evlist__exclude_kernel(evlist)) {
> >>> pr_warning(
> >>> "WARNING: Kernel address maps (/proc/{kallsyms,modules}) are restricted,\n"
> >>
>
More information about the linux-riscv
mailing list