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:
```
$ perf test -vv PERF_RECORD_
...
7: PERF_RECORD_* events & perf_sample fields:
7: 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:
: 7: PERF_RECORD_* events & perf_sample fields:
---- unexpected signal (2) ----
#0 0x55788c6210a3 in child_test_sig_handler builtin-test.c:0
#1 0x7fc12fe49df0 in __restore_rt libc_sigaction.c:0
#2 0x7fc12fe99687 in __internal_syscall_cancel cancellation.c:64
#3 0x7fc12fee5f7a in clock_nanosleep@GLIBC_2.2.5 clock_nanosleep.c:72
#4 0x7fc12fef1393 in __nanosleep nanosleep.c:26
#5 0x7fc12ff02d68 in __sleep sleep.c:55
#6 0x55788c63196b in test__PERF_RECORD perf-record.c:0
#7 0x55788c620fb0 in run_test_child builtin-test.c:0
#8 0x55788c5bd18d in start_command run-command.c:127
#9 0x55788c621ef3 in __cmd_test builtin-test.c:0
#10 0x55788c6225bf in cmd_test ??:0
#11 0x55788c5afbd0 in run_builtin perf.c:0
#12 0x55788c5afeeb in handle_internal_command perf.c:0
#13 0x55788c52b383 in main ??:0
#14 0x7fc12fe33ca8 in __libc_start_call_main libc_start_call_main.h:74
#15 0x7fc12fe33d65 in __libc_start_main@@GLIBC_2.34 libc-start.c:128
#16 0x55788c52b9d1 in _start ??:0
---- unexpected signal (2) ----
#0 0x55788c6210a3 in child_test_sig_handler builtin-test.c:0
#1 0x7fc12fe49df0 in __restore_rt libc_sigaction.c:0
#2 0x7fc12fea3a14 in pthread_sigmask@GLIBC_2.2.5 pthread_sigmask.c:45
#3 0x7fc12fe49fd9 in __GI___sigprocmask sigprocmask.c:26
#4 0x7fc12ff2601b in __longjmp_chk longjmp.c:36
#5 0x55788c6210c0 in print_test_result.isra.0 builtin-test.c:0
#6 0x7fc12fe49df0 in __restore_rt libc_sigaction.c:0
#7 0x7fc12fe99687 in __internal_syscall_cancel cancellation.c:64
#8 0x7fc12fee5f7a in clock_nanosleep@GLIBC_2.2.5 clock_nanosleep.c:72
#9 0x7fc12fef1393 in __nanosleep nanosleep.c:26
#10 0x7fc12ff02d68 in __sleep sleep.c:55
#11 0x55788c63196b in test__PERF_RECORD perf-record.c:0
#12 0x55788c620fb0 in run_test_child builtin-test.c:0
#13 0x55788c5bd18d in start_command run-command.c:127
#14 0x55788c621ef3 in __cmd_test builtin-test.c:0
#15 0x55788c6225bf in cmd_test ??:0
#16 0x55788c5afbd0 in run_builtin perf.c:0
#17 0x55788c5afeeb in handle_internal_command perf.c:0
#18 0x55788c52b383 in main ??:0
#19 0x7fc12fe33ca8 in __libc_start_call_main libc_start_call_main.h:74
#20 0x7fc12fe33d65 in __libc_start_main@@GLIBC_2.34 libc-start.c:128
#21 0x55788c52b9d1 in _start ??:0
7: PERF_RECORD_* events & perf_sample fields : Skip (permissions)
```
Signed-off-by: Ian Rogers <irogers@google.com>
Link: https://lore.kernel.org/r/20250624210500.2121303-1-irogers@google.com
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Add a new debug option "type-profile" to enable the detailed info during
the type analysis especially for instruction tracking. You can use this
before the command name like 'report' or 'annotate'.
$ perf --debug type-profile annotate --data-type
Committer testing:
First get some memory events:
$ perf mem record ls
Then, without data-type profiling debug:
$ perf annotate --data-type | head
Annotate type: 'struct rtld_global' in /usr/lib64/ld-linux-x86-64.so.2 (1 samples):
============================================================================
samples offset size field
1 0 4336 struct rtld_global {
0 0 0 struct link_namespaces* _dl_ns;
0 2560 8 size_t _dl_nns;
0 2568 40 __rtld_lock_recursive_t _dl_load_lock {
0 2568 40 pthread_mutex_t mutex {
0 2568 40 struct __pthread_mutex_s __data {
0 2568 4 int __lock;
$
And with only data-type profiling:
$ perf --debug type-profile annotate --data-type | head
-----------------------------------------------------------
find_data_type_die [1e67] for reg13873052 (PC) offset=0x150e2 in dl_main
CU die offset: 0x29cd3
found PC-rel by addr=0x34020 offset=0x20
-----------------------------------------------------------
find_data_type_die [2e] for reg12 offset=0 in __GI___readdir64
CU die offset: 0x137a45
frame base: cfa=1 fbreg=-1
found "__futex" in scope=2/2 (die: 0x137ad5) 0(reg12) type=int (die:2a)
-----------------------------------------------------------
find_data_type_die [52] for reg5 offset=0 in __memmove_avx_unaligned_erms
CU die offset: 0x1124ed
no variable found
Annotate type: 'struct rtld_global' in /usr/lib64/ld-linux-x86-64.so.2 (1 samples):
============================================================================
samples offset size field
1 0 4336 struct rtld_global {
0 0 0 struct link_namespaces* _dl_ns;
0 2560 8 size_t _dl_nns;
0 2568 40 __rtld_lock_recursive_t _dl_load_lock {
0 2568 40 pthread_mutex_t mutex {
0 2568 40 struct __pthread_mutex_s __data {
0 2568 4 int __lock;
$
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Ian Rogers <irogers@google.com>
Cc: Ingo Molnar <mingo@kernel.org>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Linus Torvalds <torvalds@linux-foundation.org>
Cc: Masami Hiramatsu <mhiramat@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Link: https://lore.kernel.org/r/20240319055115.4063940-9-namhyung@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
This reverts commit 08efcb4a63.
This breaks the build as it will prefer using libbpf-devel header files,
even when not using LIBBPF_DYNAMIC=1, breaking the build.
This was detected on OpenSuSE Tumbleweed with libtraceevent-devel 1.3.0,
as described by Jiri Slaby:
=======================================================================
It breaks build with LIBTRACEEVENT_DYNAMIC and version 1.3.0:
> util/debug.c: In function ‘perf_debug_option’:
> util/debug.c:243:17: error: implicit declaration of function
‘tep_set_loglevel’ [-Werror=implicit-function-declaration]
> 243 | tep_set_loglevel(TEP_LOG_INFO);
> | ^~~~~~~~~~~~~~~~
> util/debug.c:243:34: error: ‘TEP_LOG_INFO’ undeclared (first use in this
function); did you mean ‘TEP_PRINT_INFO’?
> 243 | tep_set_loglevel(TEP_LOG_INFO);
> | ^~~~~~~~~~~~
> | TEP_PRINT_INFO
> util/debug.c:243:34: note: each undeclared identifier is reported only once
for each function it appears in
> util/debug.c:245:34: error: ‘TEP_LOG_DEBUG’ undeclared (first use in this
function)
> 245 | tep_set_loglevel(TEP_LOG_DEBUG);
> | ^~~~~~~~~~~~~
> util/debug.c:247:34: error: ‘TEP_LOG_ALL’ undeclared (first use in this
function)
> 247 | tep_set_loglevel(TEP_LOG_ALL);
> | ^~~~~~~~~~~
It is because the gcc's command line looks like:
gcc
...
-I/home/abuild/rpmbuild/BUILD/tools/lib/
...
-DLIBTRACEEVENT_VERSION=65790
...
=======================================================================
The proper way to fix this is more involved and so not suitable for this
late in the 5.16-rc stage.
Reported-by: Jiri Slaby <jirislaby@kernel.org>
Link: https://lore.kernel.org/lkml/bc2b0786-8965-1bcd-2316-9d9bb37b9c31@kernel.org
Cc: Andrii Nakryiko <andrii.nakryiko@gmail.com>
Cc: Ian Rogers <irogers@google.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Song Liu <songliubraving@fb.com>
Cc: Steven Rostedt <rostedt@goodmis.org>
Link: https://lore.kernel.org/lkml/YddGjjmlMZzxUZbN@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Allow to display time in perf debug output via new
debug_set_display_time function.
It will be used in perf daemon command to get verbose output into log
file.
The debug time format is:
[2020-12-03 18:25:31.822152] affinity: SYS
[2020-12-03 18:25:31.822164] mmap flush: 1
[2020-12-03 18:25:31.822175] comp level: 0
[2020-12-03 18:25:32.002047] mmap size 528384B
Committer notes:
Cast tod.tv_usec to long to avoid this problem:
78 12.70 ubuntu:18.04-x-sparc64 : FAIL sparc64-linux-gnu-gcc (Ubuntu 7.5.0-3ubuntu1~18.04) 7.5.0
util/debug.c: In function 'fprintf_time':
util/debug.c:63:32: error: format '%lu' expects argument of type 'long unsigned int', but argument 4 has type '__suseconds_t {aka int}' [-Werror=format=]
return fprintf(file, "[%s.%06lu] ", date, tod.tv_usec);
~~~~^ ~~~~~~~~~~~
%06u
Signed-off-by: Jiri Olsa <jolsa@kernel.org>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Alexei Budankov <abudankov@huawei.com>
Cc: Ian Rogers <irogers@google.com>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Michael Petlan <mpetlan@redhat.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lore.kernel.org/lkml/20210102220441.794923-4-jolsa@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Perf record with verbose=2 already prints this information along with
whole lot of other traces which requires lot of scrolling. Introduce
an option to print only perf_event_open() arguments and return value.
Sample o/p:
$ perf --debug perf-event-open=1 record -- ls > /dev/null
------------------------------------------------------------
perf_event_attr:
size 112
{ sample_period, sample_freq } 4000
sample_type IP|TID|TIME|PERIOD
read_format ID
disabled 1
inherit 1
exclude_kernel 1
mmap 1
comm 1
freq 1
enable_on_exec 1
task 1
precise_ip 3
sample_id_all 1
exclude_guest 1
mmap2 1
comm_exec 1
ksymbol 1
bpf_event 1
------------------------------------------------------------
sys_perf_event_open: pid 4308 cpu 0 group_fd -1 flags 0x8 = 4
sys_perf_event_open: pid 4308 cpu 1 group_fd -1 flags 0x8 = 5
sys_perf_event_open: pid 4308 cpu 2 group_fd -1 flags 0x8 = 6
sys_perf_event_open: pid 4308 cpu 3 group_fd -1 flags 0x8 = 8
sys_perf_event_open: pid 4308 cpu 4 group_fd -1 flags 0x8 = 9
sys_perf_event_open: pid 4308 cpu 5 group_fd -1 flags 0x8 = 10
sys_perf_event_open: pid 4308 cpu 6 group_fd -1 flags 0x8 = 11
sys_perf_event_open: pid 4308 cpu 7 group_fd -1 flags 0x8 = 12
------------------------------------------------------------
perf_event_attr:
type 1
size 112
config 0x9
watermark 1
sample_id_all 1
bpf_event 1
{ wakeup_events, wakeup_watermark } 1
------------------------------------------------------------
sys_perf_event_open: pid -1 cpu 0 group_fd -1 flags 0x8
sys_perf_event_open failed, error -13
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.002 MB perf.data (9 samples) ]
Committer notes:
Just like the 'verbose' variable this new 'debug_peo_args' needs to be
added to util/python.c, since we don't link the debug.o file in the
python binding, which ended up making 'perf test python' fail with:
# perf test -v python
18: 'import perf' in python :
--- start ---
test child forked, pid 19237
Traceback (most recent call last):
File "<stdin>", line 1, in <module>
ImportError: /tmp/build/perf/python/perf.so: undefined symbol: debug_peo_args
test child finished with -1
---- end ----
'import perf' in python: FAILED!
#
After adding that new variable to util/python.c:
# perf test -v python
18: 'import perf' in python :
--- start ---
test child forked, pid 22364
test child finished with 0
---- end ----
'import perf' in python: Ok
#
Signed-off-by: Ravi Bangoria <ravi.bangoria@linux.ibm.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Acked-by: Jiri Olsa <jolsa@kernel.org>
Link: http://lore.kernel.org/lkml/20191108094128.28769-1-ravi.bangoria@linux.ibm.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
We got the sane_ctype.h headers from git and kept using it so far, but
since that code originally came from the kernel sources to the git
sources, perhaps its better to just use the one in the kernel, so that
we can leverage tools/perf/check_headers.sh to be notified when our copy
gets out of sync, i.e. when fixes or goodies are added to the code we've
copied.
This will help with things like tools/lib/string.c where we want to have
more things in common with the kernel, such as strim(), skip_spaces(),
etc so as to go on removing the things that we have in tools/perf/util/
and instead using the code in the kernel, indirectly and removing things
like EXPORT_SYMBOL(), etc, getting notified when fixes and improvements
are made to the original code.
Hopefully this also should help with reducing the difference of code
hosted in tools/ to the one in the kernel proper.
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Link: https://lkml.kernel.org/n/tip-7k9868l713wqtgo01xxygn12@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
