Re: [PATCH 2/3] scripts/decode_stacktrace.sh: symbol: preserve alignment

[Carlos Llamas <cmllamas@google.com>]

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@kernel.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@google.com>