kernel/linux.git/tools/perf/util/debug.c, branch v6.12.80

perf debug: Avoid stack overflow in recursive error message

2025-04-10T12:39:24+00:00

[ Upstream commit bda840191d2aae3b7cadc3ac21835dcf29487191 ] In debug_file, pr_warning_once is called on error. As that function calls debug_file the function will yield a stack overflow. Switch the location of the call so the recursion is avoided. Reviewed-by: Howard Chu Signed-off-by: Ian Rogers Reviewed-by: Arnaldo Carvalho de Melo Link: https://lore.kernel.org/r/20250228222308.626803-2-irogers@google.com Fixes: ec49230cf6dda704 ("perf debug: Expose debug file") Signed-off-by: Namhyung Kim Signed-off-by: Sasha Levin

perf annotate-data: Add debug messages

2024-03-21T13:41:28+00:00

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 Tested-by: Arnaldo Carvalho de Melo Cc: Adrian Hunter Cc: Ian Rogers Cc: Ingo Molnar Cc: Jiri Olsa Cc: Linus Torvalds Cc: Masami Hiramatsu Cc: Peter Zijlstra Cc: Stephane Eranian Link: https://lore.kernel.org/r/20240319055115.4063940-9-namhyung@kernel.org Signed-off-by: Arnaldo Carvalho de Melo

perf tools: Make it possible to see perf's kernel and module memory mappings

2024-02-08T23:49:39+00:00

Dump kmaps if using 'perf --debug kmaps' or verbose > 2 (e.g. -vvv) for tools 'perf script' and 'perf report' if there is no browser. Example: $ perf --debug kmaps script 2>&1 >/dev/null | grep kvm.intel build id event received for /lib/modules/6.7.2-local/kernel/arch/x86/kvm/kvm-intel.ko: 0691d75e10e72ebbbd45a44c59f6d00a5604badf [20] Map: 0-3a3 4f5d8 [kvm_intel].modinfo Map: 0-5240 5f280 [kvm_intel]__versions Map: 0-30 64 [kvm_intel].note.Linux Map: 0-14 644c0 [kvm_intel].orc_header Map: 0-5297 43680 [kvm_intel].rodata Map: 0-5bee 3b837 [kvm_intel].text.unlikely Map: 0-7e0 41430 [kvm_intel].noinstr.text Map: 0-2080 713c0 [kvm_intel].bss Map: 0-26 705c8 [kvm_intel].data..read_mostly Map: 0-5888 6a4c0 [kvm_intel].data Map: 0-22 70220 [kvm_intel].data.once Map: 0-40 705f0 [kvm_intel].data..percpu Map: 0-1685 41d20 [kvm_intel].init.text Map: 0-4b8 6fd60 [kvm_intel].init.data Map: 0-380 70248 [kvm_intel]__dyndbg Map: 0-8 70218 [kvm_intel].exit.data Map: 0-438 4f980 [kvm_intel]__param Map: 0-5f5 4ca0f [kvm_intel].rodata.str1.1 Map: 0-3657 493b8 [kvm_intel].rodata.str1.8 Map: 0-e0 70640 [kvm_intel].data..ro_after_init Map: 0-500 70ec0 [kvm_intel].gnu.linkonce.this_module Map: ffffffffc13a7000-ffffffffc1421000 a0 /lib/modules/6.7.2-local/kernel/arch/x86/kvm/kvm-intel.ko The example above shows how the module section mappings are all wrong except for the main .text mapping at 0xffffffffc13a7000. Signed-off-by: Adrian Hunter Acked-by: Namhyung Kim Cc: Like Xu Signed-off-by: Namhyung Kim Link: https://lore.kernel.org/r/20240208085326.13432-2-adrian.hunter@intel.com

perf debug: Expose debug file

2023-12-20T17:53:20+00:00

Some dumping call backs need to be passed a FILE*. Expose debug file via an accessor API for a consistent way to do this. Catch the unlikely failure of it not being set. Switch two cases where stderr was being used instead of debug_file. Signed-off-by: Ian Rogers Acked-by: Namhyung Kim Cc: Adrian Hunter Cc: Alexander Shishkin Cc: Andi Kleen Cc: Athira Rajeev Cc: Changbin Du Cc: Colin Ian King Cc: Dmitrii Dolgov <9erthalion6@gmail.com> Cc: German Gomez Cc: Guilherme Amadio Cc: Huacai Chen Cc: Ingo Molnar Cc: James Clark Cc: Jiri Olsa Cc: K Prateek Nayak Cc: Kajol Jain Cc: Kan Liang Cc: Leo Yan Cc: Li Dong Cc: Liam Howlett Cc: Mark Rutland Cc: Masami Hiramatsu Cc: Miguel Ojeda Cc: Ming Wang Cc: Nick Terrell Cc: Paolo Bonzini Cc: Peter Zijlstra Cc: Ravi Bangoria Cc: Sandipan Das Cc: Sean Christopherson Cc: Steinar H. Gunderson Cc: Vincent Whitchurch Cc: Wenyu Liu Cc: Yang Jihong Link: https://lore.kernel.org/r/20231207011722.1220634-16-irogers@google.com Signed-off-by: Arnaldo Carvalho de Melo

perf debug: Increase libtraceevent logging when verbose

2023-01-19T16:26:49+00:00

libtraceevent has added more levels of debug printout and with changes like: https://lore.kernel.org/linux-trace-devel/20210507095022.1079364-3-tz.stoyanov@gmail.com previously generated output like "registering plugin" is no longer displayed. This change makes it so that if perf's verbose debug output is enabled then the debug and info libtraceevent messages can be displayed. This change was previously posted: https://lore.kernel.org/linux-perf-users/20210923001024.550263-4-irogers@google.com/ and reverted: https://lore.kernel.org/linux-perf-users/20220109153446.160593-1-acme@kernel.org/ The previous failure was due to -Itools/lib being on the include path and libtraceevent in tools/lib being version 1.1.0. This meant that when LIBTRACEEVENT_VERSION was 1.3.0 the #if succeeded, but the header file for libtraceevent (taken from tools/lib rather than the intended /usr/include) was for version 1.1.0 and function definitions were missing. Since the previous issue the -Itools/lib include path has been removed: https://lore.kernel.org/lkml/20221109184914.1357295-1-irogers@google.com/ As well as libtraceevent 1.1.0 has been removed from tools/lib: https://lore.kernel.org/lkml/20221130062935.2219247-1-irogers@google.com/ Signed-off-by: Ian Rogers Cc: Adrian Hunter Cc: Alexander Shishkin Cc: Athira Jajeev Cc: Eelco Chaudron Cc: German Gomez Cc: Ingo Molnar Cc: Jiri Olsa Cc: Kan Liang Cc: Kim Phillips Cc: Leo Yan Cc: Mark Rutland Cc: Namhyung Kim Cc: Paolo Bonzini Cc: Peter Zijlstra Cc: Sean Christopherson Cc: Stephane Eranian Cc: Yang Jihong Link: https://lore.kernel.org/r/20230111070641.1728726-3-irogers@google.com Signed-off-by: Arnaldo Carvalho de Melo

perf debug: Set debug_peo_args and redirect_to_stderr variable to correct values in perf_quiet_option()

2022-12-20T18:16:33+00:00

When perf uses quiet mode, perf_quiet_option() sets the 'debug_peo_args' variable to -1, and display_attr() incorrectly determines the value of 'debug_peo_args'. As a result, unexpected information is displayed. Before: # perf record --quiet -- ls > /dev/null ------------------------------------------------------------ perf_event_attr: size 128 { sample_period, sample_freq } 4000 sample_type IP|TID|TIME|PERIOD read_format ID|LOST disabled 1 inherit 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 ------------------------------------------------------------ ... After: # perf record --quiet -- ls > /dev/null # redirect_to_stderr is a similar problem. Fixes: f78eaef0e0493f60 ("perf tools: Allow to force redirect pr_debug to stderr.") Fixes: ccd26741f5e6bdf2 ("perf tool: Provide an option to print perf_event_open args and return value") Suggested-by: Adrian Hunter Reviewed-by: Adrian Hunter Signed-off-by: Yang Jihong Cc: Alexander Shishkin Cc: Andi Kleen Cc: Carsten Haitzler Cc: Ian Rogers Cc: Ingo Molnar Cc: Jiri Olsa Cc: Leo Yan Cc: Mark Rutland Cc: martin.lau@kernel.org Cc: Masami Hiramatsu Cc: Namhyung Kim Cc: Peter Zijlstra Cc: Ravi Bangoria Cc: Ravi Bangoria Link: https://lore.kernel.org/r/20221220035702.188413-2-yangjihong1@huawei.com Signed-off-by: Arnaldo Carvalho de Melo

perf script: Fix hex dump character output

2022-01-12T17:28:21+00:00

Using grep -C with perf script -D can give erroneous results as grep loses lines due to non-printable characters, for example, below the 0020, 0060 and 0070 lines are missing: $ perf script -D | grep -C10 AUX | head . 0010: 08 00 00 00 00 00 00 00 1f 00 00 00 00 00 00 00 ................ . 0030: 01 00 00 00 00 00 00 00 00 04 00 00 00 00 00 00 ................ . 0040: 00 08 00 00 00 00 00 00 02 00 00 00 00 00 00 00 ................ . 0050: 00 00 00 00 00 00 00 00 01 00 00 00 00 00 00 00 ................ . 0080: 02 00 00 00 00 00 00 00 1b 00 00 00 00 00 00 00 ................ . 0090: 00 00 00 00 00 00 00 00 ........ 0 0 0x450 [0x98]: PERF_RECORD_AUXTRACE_INFO type: 1 PMU Type 8 Time Shift 31 perf's isprint() is a custom implementation from the kernel, but the kernel's _ctype appears to include characters from Latin-1 Supplement which is not compatible with, for example, UTF-8. Fix by checking also isascii(). After: $ tools/perf/perf script -D | grep -C10 AUX | head . 0010: 08 00 00 00 00 00 00 00 1f 00 00 00 00 00 00 00 ................ . 0020: 03 84 32 2f 00 00 00 00 63 7c 4f d2 fa ff ff ff ..2/....c|O..... . 0030: 01 00 00 00 00 00 00 00 00 04 00 00 00 00 00 00 ................ . 0040: 00 08 00 00 00 00 00 00 02 00 00 00 00 00 00 00 ................ . 0050: 00 00 00 00 00 00 00 00 01 00 00 00 00 00 00 00 ................ . 0060: 00 02 00 00 00 00 00 00 00 c0 03 00 00 00 00 00 ................ . 0070: e2 00 00 00 00 00 00 00 02 00 00 00 00 00 00 00 ................ . 0080: 02 00 00 00 00 00 00 00 1b 00 00 00 00 00 00 00 ................ . 0090: 00 00 00 00 00 00 00 00 ........ Fixes: 3052ba56bcb58904 ("tools perf: Move from sane_ctype.h obtained from git to the Linux's original") Signed-off-by: Adrian Hunter Cc: Jiri Olsa Link: http://lore.kernel.org/lkml/20220112085057.277205-1-adrian.hunter@intel.com Signed-off-by: Arnaldo Carvalho de Melo

Revert "libtraceevent: Increase libtraceevent logging when verbose"

2022-01-07T19:08:50+00:00

This reverts commit 08efcb4a638d260ef7fcbae64ecf7ceceb3f1841. 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 Link: https://lore.kernel.org/lkml/bc2b0786-8965-1bcd-2316-9d9bb37b9c31@kernel.org Cc: Andrii Nakryiko Cc: Ian Rogers Cc: Jiri Olsa Cc: Namhyung Kim Cc: Song Liu Cc: Steven Rostedt Link: https://lore.kernel.org/lkml/YddGjjmlMZzxUZbN@kernel.org Signed-off-by: Arnaldo Carvalho de Melo

libtraceevent: Increase libtraceevent logging when verbose

2021-09-28T19:09:16+00:00

perf debug: Add debug_set_display_time function

2021-01-20T17:34:20+00:00

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 Cc: Alexander Shishkin Cc: Alexei Budankov Cc: Ian Rogers Cc: Mark Rutland Cc: Michael Petlan Cc: Namhyung Kim Cc: Peter Zijlstra Cc: Stephane Eranian Link: http://lore.kernel.org/lkml/20210102220441.794923-4-jolsa@kernel.org Signed-off-by: Arnaldo Carvalho de Melo