| 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: <CAP-5=fUqcykMdApHVweETg9bp2EVPJhJOj_PR8cByOOA6OyQGw@mail.gmail.com>
Date: Wed, 12 Feb 2025 14:10:42 -0800
From: Ian Rogers <irogers@...gle.com>
To: Arnaldo Carvalho de Melo <acme@...nel.org>
Cc: Namhyung Kim <namhyung@...nel.org>, 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 12, 2025 at 1:59 PM Ian Rogers <irogers@...gle.com> wrote:
>
> On Wed, Feb 12, 2025 at 1:07 PM Arnaldo Carvalho de Melo
> <acme@...nel.org> wrote:
> >
> > On Wed, Feb 12, 2025 at 10:05:27PM +0100, Arnaldo Carvalho de Melo wrote:
> > > On Wed, Feb 05, 2025 at 04:01:37PM -0800, Namhyung Kim wrote:
> > > > Sometimes we need to analyze the data in process level but current sort
> > > > keys only work on thread level. Let's add 'tgid' sort key for that as
> > > > 'pid' is already taken for thread.
> > > >
> > > > This will look mostly the same, but it only uses tgid instead of tid.
> > > > Here's an example of a process with two threads (thloop).
> > > >
> > > > $ perf record -- perf test -w thloop
> > >
> > > Unrelated, but when building perf with DEBUG=1 and trying to test the
> > > above I noticed:
> > >
> > > root@...ber:~# perf record -- perf test -w thloop
> > > [ perf record: Woken up 1 times to write data ]
> > > [ perf record: Captured and wrote 0.404 MB perf.data (7968 samples) ]
> > > perf: util/maps.c:95: check_invariants: Assertion `map__end(prev) <= map__end(map)' failed.
> > > Aborted (core dumped)
> > > root@...ber:~# perf record -- perf test -w offcpu
> > > [ perf record: Woken up 1 times to write data ]
> > > [ perf record: Captured and wrote 0.040 MB perf.data (23 samples) ]
> > > perf: util/maps.c:95: check_invariants: Assertion `map__end(prev) <= map__end(map)' failed.
> > > Aborted (core dumped)
> > > root@...ber:~#
> > >
> > > I have:
> > >
> > > ⬢ [acme@...lbox perf-tools-next]$ git log --oneline perf-tools-next/perf-tools-next..
> > > 9de1ed6fa3b73cb1 (HEAD -> perf-tools-next) perf report: Add 'tgid' sort key
> > > 23e98ede2a353530 perf trace: Add --summary-mode option
> > > e6d6104625a3790b perf tools: Get rid of now-unused rb_resort.h
> > > 173ec14e72ef4ed7 perf trace: Convert syscall_stats to hashmap
> > > 66edfb5d404e743d perf trace: Allocate syscall stats only if summary is on
> > > ca6637e1ea08e6f4 perf parse-events filter: Use evsel__find_pmu()
> > > bd1ac4a678f7f2c8 perf bench evlist-open-close: Reduce scope of 2 variables
> > > cd59081880e89df8 perf test: Add direct off-cpu test
> > > 56cbd794c0c46ba9 perf record --off-cpu: Add --off-cpu-thresh option
> > > 28d9b19c5455556f perf record --off-cpu: Dump the remaining samples in BPF's stack trace map
> > > 2bc05b02743b50a7 perf script: Display off-cpu samples correctly
> > > bfa457a621596947 perf record --off-cpu: Disable perf_event's callchain collection
> > > eca732cc42d20266 perf evsel: Assemble offcpu samples
> > > 74ce50e40c569e90 perf record --off-cpu: Dump off-cpu samples in BPF
> > > e75f8ce63bfa6cb9 perf record --off-cpu: Preparation of off-cpu BPF program
> > > 0ffab9d26971c91c perf record --off-cpu: Parse off-cpu event
> > > efc3fe2070853b7d perf evsel: Expose evsel__is_offcpu_event() for future use
> > > ⬢ [acme@...lbox perf-tools-next]$
> > >
> > > locally, that is the stuff I've been testing lately, doubt it is related
> > > to these patches, I'll investigate later, have to go AFK, so FWIW as a
> > > heads up.
> >
> > Had time to extract this, now going really AFK:
> >
> > [New Thread 0x7fffdf24c6c0 (LWP 580622)]
> > [ perf record: Woken up 1 times to write data ]
> > [ perf record: Captured and wrote 0.403 MB perf.data (7948 samples) ]
> > [Thread 0x7fffdf24c6c0 (LWP 580622) exited]
> > perf: util/maps.c:95: check_invariants: Assertion `map__end(prev) <= map__end(map)' failed.
> >
> > Thread 1 "perf" received signal SIGABRT, Aborted.
> > Downloading 4.06 K source file /usr/src/debug/glibc-2.39-37.fc40.x86_64/nptl/pthread_kill.c
> > __pthread_kill_implementation (threadid=<optimized out>, signo=signo@...ry=6, no_tid=no_tid@...ry=0) at pthread_kill.c:44
> > 44 return INTERNAL_SYSCALL_ERROR_P (ret) ? INTERNAL_SYSCALL_ERRNO (ret) : 0;
> > (gdb) bt
> > #0 __pthread_kill_implementation (threadid=<optimized out>, signo=signo@...ry=6, no_tid=no_tid@...ry=0) at pthread_kill.c:44
> > #1 0x00007ffff6ea80a3 in __pthread_kill_internal (threadid=<optimized out>, signo=6) at pthread_kill.c:78
> > #2 0x00007ffff6e4ef1e in __GI_raise (sig=sig@...ry=6) at ../sysdeps/posix/raise.c:26
> > #3 0x00007ffff6e36902 in __GI_abort () at abort.c:79
> > #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
> > #13 0x00000000004351fb in cmd_record (argc=4, argv=0x7fffffffde60) at builtin-record.c:4286
> > #14 0x00000000004bd4d4 in run_builtin (p=0xecddc0 <commands+288>, argc=6, argv=0x7fffffffde60) at perf.c:351
> > #15 0x00000000004bd77b in handle_internal_command (argc=6, argv=0x7fffffffde60) at perf.c:404
> > #16 0x00000000004bd8d4 in run_argv (argcp=0x7fffffffdc4c, argv=0x7fffffffdc40) at perf.c:448
> > #17 0x00000000004bdc1d in main (argc=6, argv=0x7fffffffde60) at perf.c:556
> > (gdb)
>
> So my guess would be that something modified a map and broke the
> invariants of the maps_by_addresss/maps_by_name. It should be possible
> to add more check_invariants to work out where this happens.
>
> Thanks,
> Ian
I also suspect this is a regression. If you could bisect to find the
cause then the fix is probably to not modify a map but clone it,
change it and then reinsert it into the maps - the insert is called
maps__fixup_overlap_and_insert so that maps don't overlap one another
like the invariant check is detecting. Fwiw, in the older rbtree code,
invariant breakages like this would be silently ignored, so we may
have a latent bug :-(
Thanks,
Ian
> > > - Arnaldo
> > >
> > > > $ perf report --stdio -s tgid,pid -H
> > > > ...
> > > > #
> > > > # Overhead Tgid:Command / Pid:Command
> > > > # ........... ..........................
> > > > #
> > > > 100.00% 2018407:perf
> > > > 50.34% 2018407:perf
> > > > 49.66% 2018409:perf
> > > >
> > > > Suggested-by: Stephane Eranian <eranian@...gle.com>
> > > > Signed-off-by: Namhyung Kim <namhyung@...nel.org>
> > > > ---
> > > > tools/perf/Documentation/perf-report.txt | 1 +
> > > > tools/perf/util/hist.h | 1 +
> > > > tools/perf/util/sort.c | 35 ++++++++++++++++++++++++
> > > > tools/perf/util/sort.h | 1 +
> > > > 4 files changed, 38 insertions(+)
> > > >
> > > > diff --git a/tools/perf/Documentation/perf-report.txt b/tools/perf/Documentation/perf-report.txt
> > > > index 87f86451940623f3..4050ec4038425bf0 100644
> > > > --- a/tools/perf/Documentation/perf-report.txt
> > > > +++ b/tools/perf/Documentation/perf-report.txt
> > > > @@ -79,6 +79,7 @@ OPTIONS
> > > >
> > > > - comm: command (name) of the task which can be read via /proc/<pid>/comm
> > > > - pid: command and tid of the task
> > > > + - tgid: command and tgid of the task
> > > > - dso: name of library or module executed at the time of sample
> > > > - dso_size: size of library or module executed at the time of sample
> > > > - symbol: name of function executed at the time of sample
> > > > diff --git a/tools/perf/util/hist.h b/tools/perf/util/hist.h
> > > > index 46c8373e314657fa..c164e178e0a48a8e 100644
> > > > --- a/tools/perf/util/hist.h
> > > > +++ b/tools/perf/util/hist.h
> > > > @@ -38,6 +38,7 @@ enum hist_column {
> > > > HISTC_TIME,
> > > > HISTC_DSO,
> > > > HISTC_THREAD,
> > > > + HISTC_TGID,
> > > > HISTC_COMM,
> > > > HISTC_CGROUP_ID,
> > > > HISTC_CGROUP,
> > > > diff --git a/tools/perf/util/sort.c b/tools/perf/util/sort.c
> > > > index 3dd33721823f365d..5987438174967fd6 100644
> > > > --- a/tools/perf/util/sort.c
> > > > +++ b/tools/perf/util/sort.c
> > > > @@ -141,6 +141,40 @@ struct sort_entry sort_thread = {
> > > > .se_width_idx = HISTC_THREAD,
> > > > };
> > > >
> > > > +/* --sort tgid */
> > > > +
> > > > +static int64_t
> > > > +sort__tgid_cmp(struct hist_entry *left, struct hist_entry *right)
> > > > +{
> > > > + return thread__pid(right->thread) - thread__pid(left->thread);
> > > > +}
> > > > +
> > > > +static int hist_entry__tgid_snprintf(struct hist_entry *he, char *bf,
> > > > + size_t size, unsigned int width)
> > > > +{
> > > > + int tgid = thread__pid(he->thread);
> > > > + const char *comm = NULL;
> > > > +
> > > > + if (thread__pid(he->thread) == thread__tid(he->thread)) {
> > > > + comm = thread__comm_str(he->thread);
> > > > + } else {
> > > > + struct maps *maps = thread__maps(he->thread);
> > > > + struct thread *leader = machine__find_thread(maps__machine(maps),
> > > > + tgid, tgid);
> > > > + if (leader)
> > > > + comm = thread__comm_str(leader);
> > > > + }
> > > > + width = max(7U, width) - 8;
> > > > + return repsep_snprintf(bf, size, "%7d:%-*.*s", tgid, width, width, comm ?: "");
> > > > +}
> > > > +
> > > > +struct sort_entry sort_tgid = {
> > > > + .se_header = " Tgid:Command",
> > > > + .se_cmp = sort__tgid_cmp,
> > > > + .se_snprintf = hist_entry__tgid_snprintf,
> > > > + .se_width_idx = HISTC_TGID,
> > > > +};
> > > > +
> > > > /* --sort simd */
> > > >
> > > > static int64_t
> > > > @@ -2501,6 +2535,7 @@ static void sort_dimension_add_dynamic_header(struct sort_dimension *sd)
> > > >
> > > > static struct sort_dimension common_sort_dimensions[] = {
> > > > DIM(SORT_PID, "pid", sort_thread),
> > > > + DIM(SORT_TGID, "tgid", sort_tgid),
> > > > DIM(SORT_COMM, "comm", sort_comm),
> > > > DIM(SORT_DSO, "dso", sort_dso),
> > > > DIM(SORT_SYM, "symbol", sort_sym),
> > > > diff --git a/tools/perf/util/sort.h b/tools/perf/util/sort.h
> > > > index a8572574e1686be6..6044eb1d61447c0d 100644
> > > > --- a/tools/perf/util/sort.h
> > > > +++ b/tools/perf/util/sort.h
> > > > @@ -72,6 +72,7 @@ enum sort_type {
> > > > SORT_ANNOTATE_DATA_TYPE_OFFSET,
> > > > SORT_SYM_OFFSET,
> > > > SORT_ANNOTATE_DATA_TYPE_CACHELINE,
> > > > + SORT_TGID,
> > > >
> > > > /* branch stack specific sort keys */
> > > > __SORT_BRANCH_STACK,
> > > > --
> > > > 2.48.1.502.g6dc24dfdaf-goog
Powered by blists - more mailing lists