[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <aL8C375O6Spd4Vne@google.com>
Date: Mon, 8 Sep 2025 16:22:55 +0000
From: Carlos Llamas <cmllamas@...gle.com>
To: "Matthieu Baerts (NGI0)" <matttbe@...nel.org>
Cc: Andrew Morton <akpm@...ux-foundation.org>,
Elliot Berman <quic_eberman@...cinc.com>,
Stephen Boyd <swboyd@...omium.org>,
Breno Leitao <leitao@...ian.org>,
Luca Ceresoli <luca.ceresoli@...tlin.com>,
linux-kernel@...r.kernel.org
Subject: Re: [PATCH 2/3] scripts/decode_stacktrace.sh: symbol: preserve
alignment
On Mon, Sep 08, 2025 at 05:41:58PM +0200, Matthieu Baerts (NGI0) wrote:
> With lines having a symbol to decode, the script was only trying to
> preserve the alignment for the timestamps, but not the rest, nor when
> the caller was set (CONFIG_PRINTK_CALLER=y).
>
> With this sample ...
>
> [ 52.080924] Call Trace:
> [ 52.080926] <TASK>
> [ 52.080931] dump_stack_lvl+0x6f/0xb0
>
> ... the script was producing the following output:
>
> [ 52.080924] Call Trace:
> [ 52.080926] <TASK>
> [ 52.080931] dump_stack_lvl (arch/x86/include/asm/irqflags.h:19)
>
> (dump_stack_lvl is no longer aligned with <TASK>: one missing space)
>
> With this other sample ...
>
> [ 52.080924][ T48] Call Trace:
> [ 52.080926][ T48] <TASK>
> [ 52.080931][ T48] dump_stack_lvl+0x6f/0xb0
>
> ... the script was producing the following output:
>
> [ 52.080924][ T48] Call Trace:
> [ 52.080926][ T48] <TASK>
> [ 52.080931][ T48] dump_stack_lvl (arch/x86/include/asm/irqflags.h:19)
>
> (the misalignment is clearer here)
>
> That's because the script had a workaround for CONFIG_PRINTK_TIME=y
> only, see the previous comment called "Format timestamps with tabs".
>
> To always preserve spaces, they need to be recorded along the words.
> That is what is now done with the new 'spaces' array.
>
> Some notes:
>
> - 'extglob' is needed only for this operation, and that's why it is set
> in a dedicated subshell.
>
> - 'read' is used with '-r' not to treat a <backslash> character in any
> special way, e.g. when followed by a space.
>
> - When a word is removed from the 'words' array, the corresponding space
> needs to be removed from the 'spaces' array as well.
>
> With the last sample, we now have:
>
> [ 52.080924][ T48] Call Trace:
> [ 52.080926][ T48] <TASK>
> [ 52.080931][ T48] dump_stack_lvl (arch/x86/include/asm/irqflags.h:19)
>
> (the alignment is preserved)
>
> Signed-off-by: Matthieu Baerts (NGI0) <matttbe@...nel.org>
> ---
> scripts/decode_stacktrace.sh | 26 ++++++++++++--------------
> 1 file changed, 12 insertions(+), 14 deletions(-)
>
> diff --git a/scripts/decode_stacktrace.sh b/scripts/decode_stacktrace.sh
> index c6b5c14412f0f6f78fb60b0b042d6e22bbb46b79..0c92d6a7f777e1b2d5452dd894a13a71e3d58051 100755
> --- a/scripts/decode_stacktrace.sh
> +++ b/scripts/decode_stacktrace.sh
> @@ -255,10 +255,11 @@ handle_line() {
> basepath=${basepath%/init/main.c:*)}
> fi
>
> - local words
> + local words spaces
>
> - # Tokenize
> - read -a words <<<"$1"
> + # Tokenize: words and spaces to preserve the alignment
> + read -ra words <<<"$1"
> + IFS='#' read -ra spaces <<<"$(shopt -s extglob; echo "${1//+([^[:space:]])/#}")"
>
> # Remove hex numbers. Do it ourselves until it happens in the
> # kernel
> @@ -270,19 +271,13 @@ handle_line() {
> for i in "${!words[@]}"; do
> # Remove the address
> if [[ ${words[$i]} =~ \[\<([^]]+)\>\] ]]; then
> - unset words[$i]
> - fi
> -
> - # Format timestamps with tabs
> - if [[ ${words[$i]} == \[ && ${words[$i+1]} == *\] ]]; then
> - unset words[$i]
> - words[$i+1]=$(printf "[%13s\n" "${words[$i+1]}")
> + unset words[$i] spaces[$i]
> fi
> done
>
> if [[ ${words[$last]} =~ ^[0-9a-f]+\] ]]; then
> words[$last-1]="${words[$last-1]} ${words[$last]}"
> - unset words[$last]
> + unset words[$last] spaces[$last]
> last=$(( $last - 1 ))
> fi
>
> @@ -294,7 +289,7 @@ handle_line() {
> local info_str=""
> if [[ ${words[$last]} =~ \([A-Z]*\) ]]; then
> info_str=${words[$last]}
> - unset words[$last]
> + unset words[$last] spaces[$last]
> last=$(( $last - 1 ))
> fi
>
> @@ -311,7 +306,7 @@ handle_line() {
> modbuildid=
> fi
> symbol=${words[$last-1]}
> - unset words[$last-1]
> + unset words[$last-1] spaces[$last-1]
> else
> # The symbol is the last element, process it
> symbol=${words[$last]}
> @@ -323,7 +318,10 @@ handle_line() {
> parse_symbol # modifies $symbol
>
> # Add up the line number to the symbol
> - echo "${words[@]}" "${symbol}${module:+ ${module}}${info_str:+ ${info_str}}"
> + for i in "${!words[@]}"; do
> + echo -n "${spaces[i]}${words[i]}"
> + done
> + echo "${spaces[$last]}${symbol}${module:+ ${module}}${info_str:+ ${info_str}}"
> }
>
> while read line; do
>
> --
> 2.51.0
>
I just tried this and it works for me. From this...
[ 51.711528][ T6914] ==================================================================
[ 51.712906][ T6914] BUG: KASAN: double-free in __kmem_cache_free (mm/slub.c:3875)
[ 51.713765][ T6914] Free of addr 85ffff8912b19f80 by task sh/6914
[...]
[ 51.717788][ T6914] Call trace:
[ 51.718182][ T6914] dump_backtrace (arch/arm64/kernel/stacktrace.c:236)
[ 51.718734][ T6914] show_stack (arch/arm64/kernel/stacktrace.c:244)
[ 51.719219][ T6914] dump_stack_lvl (lib/dump_stack.c:107)
... to now this:
[ 51.711528][ T6914] ==================================================================
[ 51.712906][ T6914] BUG: KASAN: double-free in __kmem_cache_free (mm/slub.c:3875)
[ 51.713765][ T6914] Free of addr 85ffff8912b19f80 by task sh/6914
[...]
[ 51.717788][ T6914] Call trace:
[ 51.718182][ T6914] dump_backtrace (arch/arm64/kernel/stacktrace.c:236)
[ 51.718734][ T6914] show_stack (arch/arm64/kernel/stacktrace.c:244)
[ 51.719219][ T6914] dump_stack_lvl (lib/dump_stack.c:107)
Tested-by: Carlos Llamas <cmllamas@...gle.com>
Powered by blists - more mailing lists