| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Message-ID: <Z7XvEFEZtCRZKG7Y@x1>
Date: Wed, 19 Feb 2025 15:47:44 +0100
From: Arnaldo Carvalho de Melo <acme@...nel.org>
To: Namhyung Kim <namhyung@...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
On Wed, Feb 19, 2025 at 03:37:10PM +0100, Arnaldo Carvalho de Melo wrote:
> On Tue, Feb 18, 2025 at 02:03:01PM -0800, Namhyung Kim wrote:
> > 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.
>
> No, it didn't fail to add, it managed to do it which left the kernel
> maps in a broken state, with overlappings while it had a cleared
> ends_broken, then, later, when the checks_invariant is finally called at
> perf record exit time:
Nope, __maps__insert() should notice that the ends are broken and set
it:
if (nr_maps == 1) {
/* If there's just 1 entry then maps are sorted. */
maps__set_maps_by_address_sorted(maps, true);
maps__set_maps_by_name_sorted(maps, maps_by_name != NULL);
} else {
/* Sorted if maps were already sorted and this map starts after the last one. */
maps__set_maps_by_address_sorted(maps,
maps__maps_by_address_sorted(maps) &&
map__end(maps_by_address[nr_maps - 2]) <= map__start(new));
maps__set_maps_by_name_sorted(maps, false);
}
if (map__end(new) < map__start(new))
RC_CHK_ACCESS(maps)->ends_broken = true;
humm, RC_CHK_ACCESS(maps)->ends_broken should be set for the case we
have and I think it isn't being... Then the bpf trampoline map that is
the last entry to be added is before the last entry and thus
maps_by_address_sorted is set to false, ends_broken continues false and
at the end maps_by_address_sorted is set to true and the last
check_invariants triggerrs the asserts...
> > > > > #4 0x00007ffff6e3681e in __assert_fail_base (fmt=0x7ffff6fc3bb8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@...ry=0x7bef08 "map__end(prev) <= map__end(map)",
> > > > > file=file@...ry=0x7bedf8 "util/maps.c", line=line@...ry=95, function=function@...ry=0x7bf1c0 <__PRETTY_FUNCTION__.6> "check_invariants") at assert.c:96
> > > > > #5 0x00007ffff6e47047 in __assert_fail (assertion=0x7bef08 "map__end(prev) <= map__end(map)", file=0x7bedf8 "util/maps.c", line=95,
> > > > > function=0x7bf1c0 <__PRETTY_FUNCTION__.6> "check_invariants") at assert.c:105
> > > > > #6 0x00000000006347a1 in check_invariants (maps=0xf987e0) at util/maps.c:95
> > > > > #7 0x0000000000635ae2 in maps__remove (maps=0xf987e0, map=0xf98a80) at util/maps.c:538
> > > > > #8 0x000000000062afd2 in machine__destroy_kernel_maps (machine=0xf98178) at util/machine.c:1176
> > > > > #9 0x000000000062b32b in machines__destroy_kernel_maps (machines=0xf98178) at util/machine.c:1238
> > > > > #10 0x00000000006388af in perf_session__destroy_kernel_maps (session=0xf97f60) at util/session.c:105
> > > > > #11 0x0000000000638df0 in perf_session__delete (session=0xf97f60) at util/session.c:248
> > > > > #12 0x0000000000431f18 in __cmd_record (rec=0xecace0 <record>, argc=4, argv=0x7fffffffde60) at builtin-record.c:2888
>
> is when we detect the problem, but I see what you mean, I'm trying to
> figure out why this isn't caught here:
>
> machine__process_ksymbol_register() ->
> int maps__insert(struct maps *maps, struct map *map)
> {
> int ret;
>
> down_write(maps__lock(maps));
> ret = __maps__insert(maps, map);
> check_invariants(maps);
> up_write(maps__lock(maps));
> return ret;
> }
>
> Some more tracing:
>
> root@...ber:~# perf probe -d probe_perf:* ; perf probe -qx ~/bin/perf check_invariants maps 'maps->maps_by_address_sorted' ; perf probe -qx ~/bin/perf maps__insert maps 'map->dso->name:string' 'map->start' 'map->end' ; perf probe -qx ~/bin/perf maps__fixup_end maps ; perf probe -l
> Removed event: probe_perf:check_invariants
> Removed event: probe_perf:maps_fixup_end
> Removed event: probe_perf:maps_insert
> probe_perf:check_invariants (on check_invariants:1@...l/maps.c in /home/acme/bin/perf with maps maps_by_address_sorted)
> 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:~#
>
> And then:
>
> root@...ber:~# perf trace --lib -e probe_perf:maps_*,probe_perf:check_invariants/max-stack=32/ perf record sleep
> <SNIP>
> 316.283 perf/1882053 probe_perf:maps_insert((634e64) maps=0x342785d0 name="bpf_prog_6deef7357e7b4530_sd_fw_ingress" start=0xffffffffc01648ac end=0xffffffffc01648ec)
> 316.284 perf/1882053 probe_perf:check_invariants((633b0f) maps=0x342785d0 maps_by_address_sorted=0x0)
> check_invariants (/home/acme/bin/perf)
> maps__insert (/home/acme/bin/perf)
> machine__process_ksymbol_register (/home/acme/bin/perf)
> machine__process_ksymbol (/home/acme/bin/perf)
> perf_event__process_ksymbol (/home/acme/bin/perf)
> machines__deliver_event (/home/acme/bin/perf)
> perf_session__deliver_event (/home/acme/bin/perf)
> perf_session__process_event (/home/acme/bin/perf)
> process_simple (/home/acme/bin/perf)
> reader__read_event (/home/acme/bin/perf)
> reader__process_events (/home/acme/bin/perf)
> __perf_session__process_events (/home/acme/bin/perf)
> perf_session__process_events (/home/acme/bin/perf)
> process_buildids (/home/acme/bin/perf)
> record__finish_output (/home/acme/bin/perf)
> __cmd_record (/home/acme/bin/perf)
> cmd_record (/home/acme/bin/perf)
> run_builtin (/home/acme/bin/perf)
> handle_internal_command (/home/acme/bin/perf)
> run_argv (/home/acme/bin/perf)
> main (/home/acme/bin/perf)
> __libc_start_call_main (/usr/lib64/libc.so.6)
> __libc_start_main@@GLIBC_2.34 (/usr/lib64/libc.so.6)
> _start (/home/acme/bin/perf)
> 316.296 perf/1882053 probe_perf:maps_insert((634e64) maps=0x342785d0 name="bpf_prog_be31ae23198a0378_sd_devices" start=0xffffffffc0186388 end=0xffffffffc01864b2)
> 316.298 perf/1882053 probe_perf:check_invariants((633b0f) maps=0x342785d0 maps_by_address_sorted=0x0)
> check_invariants (/home/acme/bin/perf)
> maps__insert (/home/acme/bin/perf)
> machine__process_ksymbol_register (/home/acme/bin/perf)
> machine__process_ksymbol (/home/acme/bin/perf)
> perf_event__process_ksymbol (/home/acme/bin/perf)
> machines__deliver_event (/home/acme/bin/perf)
> perf_session__deliver_event (/home/acme/bin/perf)
> perf_session__process_event (/home/acme/bin/perf)
> process_simple (/home/acme/bin/perf)
> reader__read_event (/home/acme/bin/perf)
> reader__process_events (/home/acme/bin/perf)
> __perf_session__process_events (/home/acme/bin/perf)
> perf_session__process_events (/home/acme/bin/perf)
> process_buildids (/home/acme/bin/perf)
> record__finish_output (/home/acme/bin/perf)
> __cmd_record (/home/acme/bin/perf)
> cmd_record (/home/acme/bin/perf)
> run_builtin (/home/acme/bin/perf)
> handle_internal_command (/home/acme/bin/perf)
> run_argv (/home/acme/bin/perf)
> main (/home/acme/bin/perf)
> __libc_start_call_main (/usr/lib64/libc.so.6)
> __libc_start_main@@GLIBC_2.34 (/usr/lib64/libc.so.6)
> _start (/home/acme/bin/perf)
> 316.310 perf/1882053 probe_perf:maps_insert((634e64) maps=0x342785d0 name="bpf_trampoline_6442522522" start=0xffffffffc0147640 end=0xffffffffc0148640)
> 316.311 perf/1882053 probe_perf:check_invariants((633b0f) maps=0x342785d0 maps_by_address_sorted=0x0)
> check_invariants (/home/acme/bin/perf)
> maps__insert (/home/acme/bin/perf)
> machine__process_ksymbol_register (/home/acme/bin/perf)
> machine__process_ksymbol (/home/acme/bin/perf)
> perf_event__process_ksymbol (/home/acme/bin/perf)
> machines__deliver_event (/home/acme/bin/perf)
> perf_session__deliver_event (/home/acme/bin/perf)
> perf_session__process_event (/home/acme/bin/perf)
> process_simple (/home/acme/bin/perf)
> reader__read_event (/home/acme/bin/perf)
> reader__process_events (/home/acme/bin/perf)
> __perf_session__process_events (/home/acme/bin/perf)
> perf_session__process_events (/home/acme/bin/perf)
> process_buildids (/home/acme/bin/perf)
> record__finish_output (/home/acme/bin/perf)
> __cmd_record (/home/acme/bin/perf)
> cmd_record (/home/acme/bin/perf)
> run_builtin (/home/acme/bin/perf)
> handle_internal_command (/home/acme/bin/perf)
> run_argv (/home/acme/bin/perf)
> main (/home/acme/bin/perf)
> __libc_start_call_main (/usr/lib64/libc.so.6)
> __libc_start_main@@GLIBC_2.34 (/usr/lib64/libc.so.6)
> _start (/home/acme/bin/perf)
> 316.369 perf/1882053 probe_perf:check_invariants((633b0f) maps=0x342a6950 maps_by_address_sorted=0x1)
> check_invariants (/home/acme/bin/perf)
> __maps__insert_sorted (/home/acme/bin/perf)
> __maps__fixup_overlap_and_insert (/home/acme/bin/perf)
> maps__fixup_overlap_and_insert (/home/acme/bin/perf)
> thread__insert_map (/home/acme/bin/perf)
> machine__process_mmap2_event (/home/acme/bin/perf)
> perf_event__process_mmap2 (/home/acme/bin/perf)
> build_id__process_mmap2 (/home/acme/bin/perf)
> machines__deliver_event (/home/acme/bin/perf)
> perf_session__deliver_event (/home/acme/bin/perf)
> ordered_events__deliver_event (/home/acme/bin/perf)
> do_flush (/home/acme/bin/perf)
> __ordered_events__flush (/home/acme/bin/perf)
> ordered_events__flush (/home/acme/bin/perf)
> __perf_session__process_events (/home/acme/bin/perf)
> perf_session__process_events (/home/acme/bin/perf)
> process_buildids (/home/acme/bin/perf)
> record__finish_output (/home/acme/bin/perf)
> __cmd_record (/home/acme/bin/perf)
> cmd_record (/home/acme/bin/perf)
> run_builtin (/home/acme/bin/perf)
> handle_internal_command (/home/acme/bin/perf)
> run_argv (/home/acme/bin/perf)
> main (/home/acme/bin/perf)
> __libc_start_call_main (/usr/lib64/libc.so.6)
> __libc_start_main@@GLIBC_2.34 (/usr/lib64/libc.so.6)
> _start (/home/acme/bin/perf)
> <SNIP>
> [ perf record: Captured and wrote 0.035 MB perf.data (7 samples) ]
> 1195.433 perf/1882053 probe_perf:check_invariants((633b0f) maps=0x342785d0 maps_by_address_sorted=0x1)
> check_invariants (/home/acme/bin/perf)
> maps__remove (/home/acme/bin/perf)
> machine__destroy_kernel_maps (/home/acme/bin/perfperf: util/maps.c:95: check_invariants: Assertion `map__end(prev) <= map__end(map)' failed.
> )
> machines__destroy_kernel_maps (/home/acme/bin/perf)
> perf_session__destroy_kernel_maps (/home/acme/bin/perf)
> perf_session__delete (/home/acme/bin/perf)
> __cmd_record (/home/acme/bin/perf)
> cmd_record (/home/acme/bin/perf)
> run_builtin (/home/acme/bin/perf)
> handle_internal_command (/home/acme/bin/perf)
> run_argv (/home/acme/bin/perf)
> main (/home/acme/bin/perf)
> __libc_start_call_main (/usr/lib64/libc.so.6)
> __libc_start_main@@GLIBC_2.34 (/usr/lib64/libc.so.6)
> _start (/home/acme/bin/perf)
> root@...ber:~#
>
> check_invariants() doesn't check the ends because the
> maps_byh_address_sorted is not set, I'll soon disappear into a call, but
> the above should help as a checkpoint, I'll be back.
>
> - Arnaldo
>
>
> > > 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.
>
> You mean my one-liner?
>
> I meant "refixes" as in maps__fixup_end() will fixup the overlapping of
> the bpf_trampoline and bpf_prog and will re-clear maps->ends_broken
> (needlessly, it was already cleared by the first call to
> maps__fixup_end() after loading modules, at the start of the session).
>
> Then check_invariants() _will_, check again, because maps->ends_broken
> is cleared (was cleared twice even), the end addresses and there will
> not be any overlapping, no?
>
> - Arnaldo
>
> > 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