[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <CAP-5=fXonwoMOqfK30bo1i438cDa7oTWOOWFwJNXY9UOMBpkCQ@mail.gmail.com>
Date: Thu, 29 May 2025 15:02:23 -0700
From: Ian Rogers <irogers@...gle.com>
To: Arnaldo Carvalho de Melo <acme@...nel.org>
Cc: Peter Zijlstra <peterz@...radead.org>, Ingo Molnar <mingo@...hat.com>,
Namhyung Kim <namhyung@...nel.org>, Mark Rutland <mark.rutland@....com>,
Alexander Shishkin <alexander.shishkin@...ux.intel.com>, Jiri Olsa <jolsa@...nel.org>,
Adrian Hunter <adrian.hunter@...el.com>, Kan Liang <kan.liang@...ux.intel.com>,
James Clark <james.clark@...aro.org>, Howard Chu <howardchu95@...il.com>,
Yicong Yang <yangyicong@...ilicon.com>, Michael Petlan <mpetlan@...hat.com>,
Andi Kleen <ak@...ux.intel.com>, Christophe Leroy <christophe.leroy@...roup.eu>,
"Dr. David Alan Gilbert" <linux@...blig.org>,
Krzysztof Łopatowski <krzysztof.m.lopatowski@...il.com>,
Dmitry Vyukov <dvyukov@...gle.com>, linux-perf-users@...r.kernel.org,
linux-kernel@...r.kernel.org
Subject: Re: [PATCH v2 2/2] perf debug: Add function symbols to dump_stack
On Thu, May 29, 2025 at 1:21 PM Arnaldo Carvalho de Melo
<acme@...nel.org> wrote:
>
> On Wed, May 28, 2025 at 10:23:22PM -0700, Ian Rogers wrote:
> > Symbolize stack traces by creating a live machine. Add this
> > functionality to dump_stack and switch dump_stack users to use
> > it. Switch TUI to use it. Add stack traces to the child test function
> > which can be useful to diagnose blocked code.
> >
> > Example output:
> > ```
> > 8: PERF_RECORD_* events & perf_sample fields : Running (1 active)
> > ^C
> > Signal (2) while running tests.
> > Terminating tests with the same signal
> > Internal test harness failure. Completing any started tests:
> > : 8: PERF_RECORD_* events & perf_sample fields:
>
> So you are testing it with:
>
> root@...ber:~# perf test PERF_RECORD
> 8: PERF_RECORD_* events & perf_sample fields : Running (1 active)
> ^C
> Signal (2) while running tests.
> Terminating tests with the same signal
> Internal test harness failure. Completing any started tests:
> 8: PERF_RECORD_* events & perf_sample fields : Skip (permissions)
> root@...ber:~#
>
> ?
You are running the test as a child and by default the child test
output is only displayed if verbose is enabled. I use verbose=2 below
as verbose=1 won't display anything unless the child test gives a fail
exit value:
```
$ git log --oneline
b9ac06abfde9 perf debug: Add function symbols to dump_stack
e561806265ed perf machine: Factor creating a "live" machine out of dwarf-unwind
628e124404b3 perf tests switch-tracking: Fix timestamp comparison
$ make -C tools/perf O=/tmp/perf
...
$ sudo /tmp/perf/perf test -vv PERF_RECORD
8: PERF_RECORD_* events & perf_sample fields:
8: PERF_RECORD_* events & perf_sample fields :
Running (1 active)
^C
Signal (2) while running tests.
Terminating tests with the same signal
Internal test harness failure. Completing any started tests:
: 8: PERF_RECORD_* events & perf_sample fields:
---- unexpected signal (2) ----
#0 0x5617ec45e5e3 in child_test_sig_handler builtin-test.c:0
#1 0x7f855c649df0 in __restore_rt libc_sigaction.c:0
#2 0x7f855c699687 in __internal_syscall_cancel cancellation.c:64
#3 0x7f855c6e5f7a in clock_nanosleep@...BC_2.2.5 clock_nanosleep.c:72
#4 0x7f855c6f1393 in __nanosleep nanosleep.c:26
#5 0x7f855c702d68 in __sleep sleep.c:55
#6 0x5617ec46ebfb in test__PERF_RECORD perf-record.c:0
#7 0x5617ec45e4f0 in run_test_child builtin-test.c:0
#8 0x5617ec3faf0d in start_command run-command.c:127
#9 0x5617ec45f433 in __cmd_test builtin-test.c:0
#10 0x5617ec45faff in cmd_test perf[147aff]
#11 0x5617ec3ed960 in run_builtin perf.c:0
#12 0x5617ec3edc7b in handle_internal_command perf.c:0
#13 0x5617ec368d33 in main perf[50d33]
#14 0x7f855c633ca8 in __libc_start_call_main libc_start_call_main.h:74
#15 0x7f855c633d65 in __libc_start_main@@GLIBC_2.34 libc-start.c:128
#16 0x5617ec369381 in _start perf[51381]
---- unexpected signal (2) ----
#0 0x5617ec45e5e3 in child_test_sig_handler builtin-test.c:0
#1 0x7f855c649df0 in __restore_rt libc_sigaction.c:0
#2 0x7f855c6a3a14 in pthread_sigmask@...BC_2.2.5 pthread_sigmask.c:45
#3 0x7f855c649fd9 in __GI___sigprocmask sigprocmask.c:26
#4 0x7f855c72601b in __longjmp_chk longjmp.c:36
#5 0x5617ec45e600 in print_test_result.isra.0 builtin-test.c:0
#6 0x7f855c649df0 in __restore_rt libc_sigaction.c:0
#7 0x7f855c699687 in __internal_syscall_cancel cancellation.c:64
#8 0x7f855c6e5f7a in clock_nanosleep@...BC_2.2.5 clock_nanosleep.c:72
#9 0x7f855c6f1393 in __nanosleep nanosleep.c:26
#10 0x7f855c702d68 in __sleep sleep.c:55
#11 0x5617ec46ebfb in test__PERF_RECORD perf-record.c:0
#12 0x5617ec45e4f0 in run_test_child builtin-test.c:0
#13 0x5617ec3faf0d in start_command run-command.c:127
#14 0x5617ec45f433 in __cmd_test builtin-test.c:0
#15 0x5617ec45faff in cmd_test perf[147aff]
#16 0x5617ec3ed960 in run_builtin perf.c:0
#17 0x5617ec3edc7b in handle_internal_command perf.c:0
#18 0x5617ec368d33 in main perf[50d33]
#19 0x7f855c633ca8 in __libc_start_call_main libc_start_call_main.h:74
#20 0x7f855c633d65 in __libc_start_main@@GLIBC_2.34 libc-start.c:128
#21 0x5617ec369381 in _start perf[51381]
8: PERF_RECORD_* events & perf_sample fields :
Skip (permissions)
```
> I built it with DEBUG=1 and without, and with your patch, following your
> example output, I'm not being able to reproduce.
>
> Tried it as well with:
>
> ⬢ [acme@...lbx perf-tools-next]$ cat segv.patch
> diff --git a/tools/perf/util/symbol.c b/tools/perf/util/symbol.c
> index 8b30c6f16a9eeac1..e55d86f1097d6d79 100644
> --- a/tools/perf/util/symbol.c
> +++ b/tools/perf/util/symbol.c
> @@ -402,6 +402,8 @@ static struct symbol *symbols__find(struct rb_root_cached *symbols, u64 ip)
> {
> struct rb_node *n;
>
> + *(int *)NULL = 0;
> +
> if (symbols == NULL)
> return NULL;
>
> ⬢ [acme@...lbx perf-tools-next]$ patch -p1 < segv.patch
> patching file tools/perf/util/symbol.c
> ⬢ [acme@...lbx perf-tools-next]$ m
> rm: cannot remove '/home/acme/libexec/perf-core/scripts/python/Perf-Trace-Util/lib/Perf/Trace/__pycache__/Core.cpython-313.pyc': Permission denied
> make: Entering directory '/home/acme/git/perf-tools-next/tools/perf'
> BUILD: Doing 'make -j32' parallel build
> Warning: Kernel ABI header differences:
> diff -u tools/arch/arm64/include/asm/cputype.h arch/arm64/include/asm/cputype.h
>
> Auto-detecting system features:
> ... libdw: [ on ]
> ... glibc: [ on ]
> ... libelf: [ on ]
> ... libnuma: [ on ]
> ... numa_num_possible_cpus: [ on ]
> ... libperl: [ on ]
> ... libpython: [ on ]
> ... libcrypto: [ on ]
> ... libcapstone: [ on ]
> ... llvm-perf: [ on ]
> ... zlib: [ on ]
> ... lzma: [ on ]
> ... get_cpuid: [ on ]
> ... bpf: [ on ]
> ... libaio: [ on ]
> ... libzstd: [ on ]
>
> INSTALL libsubcmd_headers
> INSTALL libperf_headers
> INSTALL libapi_headers
> INSTALL libsymbol_headers
> INSTALL libbpf_headers
> CC /tmp/build/perf-tools-next/util/symbol.o
> LD /tmp/build/perf-tools-next/util/perf-util-in.o
> LD /tmp/build/perf-tools-next/perf-util-in.o
> AR /tmp/build/perf-tools-next/libperf-util.a
> LINK /tmp/build/perf-tools-next/perf
> GEN /tmp/build/perf-tools-next/python/perf.cpython-313-x86_64-linux-gnu.so
> INSTALL binaries
> INSTALL tests
> INSTALL libperf-jvmti.so
> INSTALL libexec
> INSTALL perf-archive
> INSTALL perf-iostat
> INSTALL perl-scripts
> INSTALL python-scripts
> INSTALL dlfilters
> INSTALL perf_completion-script
> INSTALL perf-tip
> make: Leaving directory '/home/acme/git/perf-tools-next/tools/perf'
> 18: 'import perf' in python : Ok
> ⬢ [acme@...lbx perf-tools-next]$
>
> root@...ber:~# perf top
> perf: Segmentation fault
> -------- backtrace --------
> Segmentation fault (core dumped)
> root@...ber:~#
>
> Tried also with this, but probably something else is at play:
>
> root@...ber:~# perf probe -x ~/bin/perf dump_stack
> Added new event:
> probe_perf:dump_stack (on dump_stack in /home/acme/bin/perf)
>
> You can now use it in all perf tools, such as:
>
> perf record -e probe_perf:dump_stack -aR sleep 1
>
> root@...ber:~#
> root@...ber:~# perf trace -e probe_perf:dump_stack/max-stack=16/ perf top
> perf: Segmentation fault
> -------- backtrace --------
> root@...ber:~#
>
> Running perf trace on a separate terminal it also doesn't catch
> dump_stack being called (that probe point).
>
> root@...ber:~# perf top --stdio
> PerfTop: 0 irqs/sec kernel: 0.0% exact: 0.0% lost: 0/0 drop: 0/0 [4000Hz cycles:P], (all, 32 CPUs)
> ------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>
> perf: Segmentation fault
> Segmentation fault (core dumped)
> root@...ber:~#
>
> root@...ber:~# nm ~/bin/perf | grep dump_stack
> 0000000000637eaa T __dump_stack
> 00000000006380fa T dump_stack
> 000000000063816b T sighandler_dump_stack
> root@...ber:~#
>
> ⬢ [acme@...lbx perf-tools-next]$ rpm -q glibc
> glibc-2.41-5.fc42.x86_64
> root@...ber:~# uname -a
> Linux number 6.14.8-300.fc42.x86_64 #1 SMP PREEMPT_DYNAMIC Thu May 22 19:26:02 UTC 2025 x86_64 GNU/Linux
> root@...ber:~#
>
> What am I missing?
For perf top I can do:
```
$ sudo /tmp/perf/perf top
```
in a different terminal:
```
$ sudo killall -11 perf
```
then back in the first terminal:
```
perf: Segmentation fault
-------- backtrace --------
#0 0x55ee68647918 in ui__signal_backtrace setup.c:110
#1 0x7fe2d3849df0 in __restore_rt libc_sigaction.c:0
#2 0x7fe2d38a49ee in __syscall_cancel_arch syscall_cancel.S:56
#3 0x7fe2d3899668 in __internal_syscall_cancel cancellation.c:54
#4 0x7fe2d38996ad in __syscall_cancel cancellation.c:79
#5 0x7fe2d390d9c6 in __poll poll.c:43
#6 0x55ee6855dfcb in fdarray__poll array.c:139
#7 0x55ee68565a05 in perf_evlist__poll evlist.c:391
#8 0x55ee68673b5a in evlist__poll evlist.c:594
#9 0x55ee684e7a61 in __cmd_top builtin-top.c:1369
#10 0x55ee684e9a6c in cmd_top builtin-top.c:1856
#11 0x55ee6855d1f0 in run_builtin perf.c:351
#12 0x55ee6855d497 in handle_internal_command perf.c:404
#13 0x55ee6855d5f0 in run_argv perf.c:451
#14 0x55ee6855d939 in main perf.c:558
#15 0x7fe2d3833ca8 in __libc_start_call_main libc_start_call_main.h:74
#16 0x7fe2d3833d65 in __libc_start_main@@GLIBC_2.34 libc-start.c:128
#17 0x55ee684b0a91 in _start perf[4ca91]
```
As the same symbol code is used for the backtrace then adding the segv
there is likely causing a segv in the signal handler in __dump_stack.
Thanks,
Ian
> - Arnaldo
>
> > ____ unexpected signal (2) ____
> > #0 0x5590fb6209b6 in child_test_sig_handler builtin-test.c:243
> > #1 0x7f4a91e49e20 in __restore_rt libc_sigaction.c:0
> > #2 0x7f4a91ee4f33 in clock_nanosleep@...BC_2.2.5 clock_nanosleep.c:71
> > #3 0x7f4a91ef0333 in __nanosleep nanosleep.c:26
> > #4 0x7f4a91f01f68 in __sleep sleep.c:55
> > #5 0x5590fb638c63 in test__PERF_RECORD perf-record.c:295
> > #6 0x5590fb620b43 in run_test_child builtin-test.c:269
> > #7 0x5590fb5b83ab in start_command run-command.c:127
> > #8 0x5590fb621572 in start_test builtin-test.c:467
> > #9 0x5590fb621a47 in __cmd_test builtin-test.c:573
> > #10 0x5590fb6225ea in cmd_test builtin-test.c:775
> > #11 0x5590fb5a9099 in run_builtin perf.c:351
> > #12 0x5590fb5a9340 in handle_internal_command perf.c:404
> > #13 0x5590fb5a9499 in run_argv perf.c:451
> > #14 0x5590fb5a97e2 in main perf.c:558
> > #15 0x7f4a91e33d68 in __libc_start_call_main libc_start_call_main.h:74
> > #16 0x7f4a91e33e25 in __libc_start_main@@GLIBC_2.34 libc-start.c:128
> > #17 0x5590fb4fd6d1 in _start perf[436d1]
> > ```
> >
> > Signed-off-by: Ian Rogers <irogers@...gle.com>
> > ---
> > v2: Fix NO_BACKTRACE=1 build (Arnaldo)
> > ---
> > tools/perf/tests/builtin-test.c | 15 +++++++-
> > tools/perf/ui/tui/setup.c | 2 +-
> > tools/perf/util/debug.c | 68 +++++++++++++++++++++++++++------
> > tools/perf/util/debug.h | 1 +
> > 4 files changed, 73 insertions(+), 13 deletions(-)
> >
> > diff --git a/tools/perf/tests/builtin-test.c b/tools/perf/tests/builtin-test.c
> > index 45d3d8b3317a..80375ca39a37 100644
> > --- a/tools/perf/tests/builtin-test.c
> > +++ b/tools/perf/tests/builtin-test.c
> > @@ -6,6 +6,9 @@
> > */
> > #include <fcntl.h>
> > #include <errno.h>
> > +#ifdef HAVE_BACKTRACE_SUPPORT
> > +#include <execinfo.h>
> > +#endif
> > #include <poll.h>
> > #include <unistd.h>
> > #include <setjmp.h>
> > @@ -231,6 +234,16 @@ static jmp_buf run_test_jmp_buf;
> >
> > static void child_test_sig_handler(int sig)
> > {
> > +#ifdef HAVE_BACKTRACE_SUPPORT
> > + void *stackdump[32];
> > + size_t stackdump_size;
> > +#endif
> > +
> > + fprintf(stderr, "\n---- unexpected signal (%d) ----\n", sig);
> > +#ifdef HAVE_BACKTRACE_SUPPORT
> > + stackdump_size = backtrace(stackdump, ARRAY_SIZE(stackdump));
> > + __dump_stack(stderr, stackdump, stackdump_size);
> > +#endif
> > siglongjmp(run_test_jmp_buf, sig);
> > }
> >
> > @@ -244,7 +257,7 @@ static int run_test_child(struct child_process *process)
> >
> > err = sigsetjmp(run_test_jmp_buf, 1);
> > if (err) {
> > - fprintf(stderr, "\n---- unexpected signal (%d) ----\n", err);
> > + /* Received signal. */
> > err = err > 0 ? -err : -1;
> > goto err_out;
> > }
> > diff --git a/tools/perf/ui/tui/setup.c b/tools/perf/ui/tui/setup.c
> > index 16c6eff4d241..022534eed68c 100644
> > --- a/tools/perf/ui/tui/setup.c
> > +++ b/tools/perf/ui/tui/setup.c
> > @@ -108,7 +108,7 @@ static void ui__signal_backtrace(int sig)
> >
> > printf("-------- backtrace --------\n");
> > size = backtrace(stackdump, ARRAY_SIZE(stackdump));
> > - backtrace_symbols_fd(stackdump, size, STDOUT_FILENO);
> > + __dump_stack(stdout, stackdump, size);
> >
> > exit(0);
> > }
> > diff --git a/tools/perf/util/debug.c b/tools/perf/util/debug.c
> > index f9ef7d045c92..0c7c6a9e158b 100644
> > --- a/tools/perf/util/debug.c
> > +++ b/tools/perf/util/debug.c
> > @@ -14,11 +14,18 @@
> > #ifdef HAVE_BACKTRACE_SUPPORT
> > #include <execinfo.h>
> > #endif
> > +#include "addr_location.h"
> > #include "color.h"
> > -#include "event.h"
> > #include "debug.h"
> > +#include "event.h"
> > +#include "machine.h"
> > +#include "map.h"
> > #include "print_binary.h"
> > +#include "srcline.h"
> > +#include "symbol.h"
> > +#include "synthetic-events.h"
> > #include "target.h"
> > +#include "thread.h"
> > #include "trace-event.h"
> > #include "ui/helpline.h"
> > #include "ui/ui.h"
> > @@ -298,21 +305,60 @@ void perf_debug_setup(void)
> > libapi_set_print(pr_warning_wrapper, pr_warning_wrapper, pr_debug_wrapper);
> > }
> >
> > +void __dump_stack(FILE *file, void **stackdump, size_t stackdump_size)
> > +{
> > + /* TODO: async safety. printf, malloc, etc. aren't safe inside a signal handler. */
> > + pid_t pid = getpid();
> > + struct machine *machine = machine__new_live(/*kernel_maps=*/false, pid);
> > + struct thread *thread = NULL;
> > +
> > + if (machine)
> > + thread = machine__find_thread(machine, pid, pid);
> > +
> > +#ifdef HAVE_BACKTRACE_SUPPORT
> > + if (!machine || !thread) {
> > + /*
> > + * Backtrace functions are async signal safe. Fall back on them
> > + * if machine/thread creation fails.
> > + */
> > + backtrace_symbols_fd(stackdump, stackdump_size, fileno(file));
> > + machine__delete(machine);
> > + return;
> > + }
> > +#endif
> > +
> > + for (size_t i = 0; i < stackdump_size; i++) {
> > + struct addr_location al;
> > + u64 addr = (u64)stackdump[i];
> > + bool printed = false;
> > +
> > + addr_location__init(&al);
> > + if (thread && thread__find_map(thread, PERF_RECORD_MISC_USER, addr, &al)) {
> > + al.sym = map__find_symbol(al.map, al.addr);
> > + if (al.sym) {
> > + fprintf(file, " #%zd %p in %s ", i, stackdump[i], al.sym->name);
> > + printed = true;
> > + }
> > + }
> > + if (!printed)
> > + fprintf(file, " #%zd %p ", i, stackdump[i]);
> > +
> > + map__fprintf_srcline(al.map, al.addr, "", file);
> > + fprintf(file, "\n");
> > + addr_location__exit(&al);
> > + }
> > + thread__put(thread);
> > + machine__delete(machine);
> > +}
> > +
> > /* Obtain a backtrace and print it to stdout. */
> > #ifdef HAVE_BACKTRACE_SUPPORT
> > void dump_stack(void)
> > {
> > - void *array[16];
> > - size_t size = backtrace(array, ARRAY_SIZE(array));
> > - char **strings = backtrace_symbols(array, size);
> > - size_t i;
> > -
> > - printf("Obtained %zd stack frames.\n", size);
> > -
> > - for (i = 0; i < size; i++)
> > - printf("%s\n", strings[i]);
> > + void *stackdump[32];
> > + size_t size = backtrace(stackdump, ARRAY_SIZE(stackdump));
> >
> > - free(strings);
> > + __dump_stack(stdout, stackdump, size);
> > }
> > #else
> > void dump_stack(void) {}
> > diff --git a/tools/perf/util/debug.h b/tools/perf/util/debug.h
> > index a4026d1fd6a3..6b737e195ce1 100644
> > --- a/tools/perf/util/debug.h
> > +++ b/tools/perf/util/debug.h
> > @@ -85,6 +85,7 @@ void debug_set_display_time(bool set);
> > void perf_debug_setup(void);
> > int perf_quiet_option(void);
> >
> > +void __dump_stack(FILE *file, void **stackdump, size_t stackdump_size);
> > void dump_stack(void);
> > void sighandler_dump_stack(int sig);
> >
> > --
> > 2.49.0.1204.g71687c7c1d-goog
> >
Powered by blists - more mailing lists