[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <Z7UDlZKnqXRqNqQa@google.com>
Date: Tue, 18 Feb 2025 14:03:01 -0800
From: Namhyung Kim <namhyung@...nel.org>
To: Arnaldo Carvalho de Melo <acme@...nel.org>
Cc: Ian Rogers <irogers@...gle.com>, Kan Liang <kan.liang@...ux.intel.com>,
Jiri Olsa <jolsa@...nel.org>,
Adrian Hunter <adrian.hunter@...el.com>,
Peter Zijlstra <peterz@...radead.org>,
Ingo Molnar <mingo@...nel.org>, LKML <linux-kernel@...r.kernel.org>,
linux-perf-users@...r.kernel.org,
Stephane Eranian <eranian@...gle.com>
Subject: Re: [PATCH] perf report: Add 'tgid' sort key
Hi Arnaldo,
On Tue, Feb 18, 2025 at 10:01:33PM +0100, Arnaldo Carvalho de Melo wrote:
> On Tue, Feb 18, 2025 at 09:36:52PM +0100, Arnaldo Carvalho de Melo wrote:
> > So the call to maps_fixup_end() will set maps->end_broken to false,
> > since it fixed up the map ends, etc, but then we insert more maps with
> > broken ends:
>
> > #6 0x0000000000633d52 in check_invariants (maps=0xf967c0) at util/maps.c:95
> > 95 assert(map__end(prev) <= map__end(map));
> > (gdb) p prev->dso->name
> > $1 = 0xfc47ab "bpf_trampoline_6442522522"
>
> So the above map is created overlapping a previously existing map:
>
> root@...ber:~# perf probe -l
> probe_perf:maps_fixup_end (on maps__fixup_end:1@...l/maps.c in /home/acme/bin/perf with maps)
> probe_perf:maps_insert (on maps__insert:1@...l/maps.c in /home/acme/bin/perf with maps name start end)
> root@...ber:~#
>
> root@...ber:~# perf trace --lib -e probe_perf:maps* perf record sleep
> <SNIP>
> 319.791 perf/1732173 probe_perf:maps_insert((634e5e) maps=0x2d9715d0 name="bpf_prog_6deef7357e7b4530_sd_fw_egress" start=0xffffffffc0160788 end=0xffffffffc01607c8)
> 319.810 perf/1732173 probe_perf:maps_insert((634e5e) maps=0x2d9715d0 name="bpf_prog_6deef7357e7b4530_sd_fw_ingress" start=0xffffffffc01647b8 end=0xffffffffc01647f8)
> 319.822 perf/1732173 probe_perf:maps_insert((634e5e) maps=0x2d9715d0 name="bpf_prog_6deef7357e7b4530_sd_fw_egress" start=0xffffffffc016482c end=0xffffffffc016486c)
> 319.834 perf/1732173 probe_perf:maps_insert((634e5e) maps=0x2d9715d0 name="bpf_prog_6deef7357e7b4530_sd_fw_ingress" start=0xffffffffc01648ac end=0xffffffffc01648ec)
> 319.845 perf/1732173 probe_perf:maps_insert((634e5e) maps=0x2d9715d0 name="bpf_prog_be31ae23198a0378_sd_devices" start=0xffffffffc0186388 end=0xffffffffc01864b2)
> 319.857 perf/1732173 probe_perf:maps_insert((634e5e) maps=0x2d9715d0 name="bpf_trampoline_6442522522" start=0xffffffffc0147640 end=0xffffffffc0148640)
> [ perf record: Captured and wrote 0.035 MB perf.data (7 samples) ]
> perf: util/maps.c:95: check_invariants: Assertion `map__end(prev) <= map__end(map)' failed.
> root@...ber:~#
>
> So a PERF_RECORD_KSYMBOL processing will add a map for
> "bpf_trampoline_6442522522" that has its start after before the
> "bpf_prog_40ddf486530245f5_sd_devices" start, ok, but ends after
> "bpf_prog_40ddf486530245f5_sd_devices", overlapping it.
>
> machine__process_ksymbol_register() does:
>
> 713 map__set_start(map, event->ksymbol.addr);
> 714 map__set_end(map, map__start(map) + event->ksymbol.len);
> 715 err = maps__insert(machine__kernel_maps(machine), map);
>
> And:
>
> (gdb) p /x event->ksymbol.addr
> $2 = 0xffffffffc0147a2c
> (gdb) p event->ksymbol.len
> $3 = 306
Hmm.. so I think the situation is like below.
(bpf_trampoline_6442522522)
+---------------------------------------+
| |
| +------------------------+ |
| | (bpf_prog_40ddf486...) | <----+---- adding this
| | | |
| | | |
| c0147a2c |
| |
c0147640 c0148640
And it failed to add bpf_prog_40ddf486... in check_invariants() because
the end address is smaller than the previous map.
>
> Thread 1 "perf" hit Breakpoint 1, machine__process_ksymbol_register (machine=0xf96158, event=0x7ffff7fb9aa0, sample=0x7fffffffa860) at util/machine.c:688
> 688 {
> (gdb) bt
> #0 machine__process_ksymbol_register (machine=0xf96158, event=0x7ffff7fb9aa0, sample=0x7fffffffa860) at util/machine.c:688
> #1 0x00000000006294ca in machine__process_ksymbol (machine=0xf96158, event=0x7ffff7fb9aa0, sample=0x7fffffffa860) at util/machine.c:779
> #2 0x00000000005ce2fd in perf_event__process_ksymbol (tool=0xec8ce0 <record>, event=0x7ffff7fb9aa0, sample=0x7fffffffa860, machine=0xf96158) at util/event.c:296
> #3 0x000000000063b6e4 in machines__deliver_event (machines=0xf96158, evlist=0xf521f0, event=0x7ffff7fb9aa0, sample=0x7fffffffa860, tool=0xec8ce0 <record>, file_offset=31392,
> file_path=0xf96850 "perf.data") at util/session.c:1334
> #4 0x000000000063b8c9 in perf_session__deliver_event (session=0xf95f40, event=0x7ffff7fb9aa0, tool=0xec8ce0 <record>, file_offset=31392, file_path=0xf96850 "perf.data")
> at util/session.c:1367
> #5 0x000000000063c6bd in perf_session__process_event (session=0xf95f40, event=0x7ffff7fb9aa0, file_offset=31392, file_path=0xf96850 "perf.data") at util/session.c:1626
> #6 0x000000000063de3d in process_simple (session=0xf95f40, event=0x7ffff7fb9aa0, file_offset=31392, file_path=0xf96850 "perf.data") at util/session.c:2203
> #7 0x000000000063daf4 in reader__read_event (rd=0x7fffffffafa0, session=0xf95f40, prog=0x7fffffffaf70) at util/session.c:2132
> #8 0x000000000063dcee in reader__process_events (rd=0x7fffffffafa0, session=0xf95f40, prog=0x7fffffffaf70) at util/session.c:2181
> #9 0x000000000063df8b in __perf_session__process_events (session=0xf95f40) at util/session.c:2226
> #10 0x000000000063e988 in perf_session__process_events (session=0xf95f40) at util/session.c:2390
> #11 0x000000000042d98b in process_buildids (rec=0xec8ce0 <record>) at builtin-record.c:1475
> #12 0x000000000042e963 in record__finish_output (rec=0xec8ce0 <record>) at builtin-record.c:1798
> #13 0x0000000000431c46 in __cmd_record (rec=0xec8ce0 <record>, argc=2, argv=0x7fffffffde80) at builtin-record.c:2841
> #14 0x000000000043513f in cmd_record (argc=2, argv=0x7fffffffde80) at builtin-record.c:4260
> #15 0x00000000004bcf65 in run_builtin (p=0xecbd60 <commands+288>, argc=3, argv=0x7fffffffde80) at perf.c:351
> #16 0x00000000004bd20c in handle_internal_command (argc=3, argv=0x7fffffffde80) at perf.c:404
> #17 0x00000000004bd365 in run_argv (argcp=0x7fffffffdc6c, argv=0x7fffffffdc60) at perf.c:448
> #18 0x00000000004bd6ae in main (argc=3, argv=0x7fffffffde80) at perf.c:556
> (gdb)
>
>
> So, this one liner "refixes" the "modules" ends when processing the
> records to find the build ids, unsure if it is the best solution tho:
I think it "fixes" the problem by not clearing maps->ends_broken during
the sample processing. So check_invariants() will not check the end
addresses of overlapping bpf_trampoline and bpf_prog.
I'm curious how other commands (like perf report) are affected. I think
the original concern was the output of `perf buildid-list -m`.
Thanks,
Namhyung
>
> diff --git a/tools/perf/builtin-record.c b/tools/perf/builtin-record.c
> index 5db1aedf48df92d2..5c4603d08ab5f2cb 100644
> --- a/tools/perf/builtin-record.c
> +++ b/tools/perf/builtin-record.c
> @@ -1797,6 +1797,8 @@ record__finish_output(struct record *rec)
> if (!rec->no_buildid) {
> process_buildids(rec);
>
> + maps__fixup_end(machine__kernel_maps(&rec->session->machines.host));
> +
> if (rec->buildid_all)
> perf_session__dsos_hit_all(rec->session);
> }
>
>
Powered by blists - more mailing lists