Re: [PATCH 05/50] arm: Add loglvl to unwind_backtrace() - Russell King

From: Russell King - ARM Linux admin <linux@armlinux.org.uk>
To: Dmitry Safonov <dima@arista.com>
Cc: linux-kernel@vger.kernel.org,
	Dmitry Safonov <0x7f454c46@gmail.com>,
	Andrew Morton <akpm@linux-foundation.org>,
	Greg Kroah-Hartman <gregkh@linuxfoundation.org>,
	Ingo Molnar <mingo@kernel.org>, Jiri Slaby <jslaby@suse.com>,
	Petr Mladek <pmladek@suse.com>,
	Sergey Senozhatsky <sergey.senozhatsky@gmail.com>,
	Steven Rostedt <rostedt@goodmis.org>,
	Tetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp>,
	Will Deacon <will@kernel.org>,
	linux-arm-kernel@lists.infradead.org,
	clang-built-linux@googlegroups.com
Subject: Re: [PATCH 05/50] arm: Add loglvl to unwind_backtrace()
Date: Wed, 6 Nov 2019 09:12:59 +0000	[thread overview]
Message-ID: <20191106091258.GS25745@shell.armlinux.org.uk> (raw)
In-Reply-To: <20191106030542.868541-6-dima@arista.com>

On Wed, Nov 06, 2019 at 03:04:56AM +0000, Dmitry Safonov wrote:
> Currently, the log-level of show_stack() depends on a platform
> realization. It creates situations where the headers are printed with
> lower log level or higher than the stacktrace (depending on
> a platform or user).
> 
> Furthermore, it forces the logic decision from user to an architecture
> side. In result, some users as sysrq/kdb/etc are doing tricks with
> temporary rising console_loglevel while printing their messages.
> And in result it not only may print unwanted messages from other CPUs,
> but also omit printing at all in the unlucky case where the printk()
> was deferred.
> 
> Introducing log-level parameter and KERN_UNSUPPRESSED [1] seems
> an easier approach than introducing more printk buffers.
> Also, it will consolidate printings with headers.
> 
> Add log level argument to unwind_backtrace() as a preparation for
> introducing show_stack_loglvl().
> 
> As a good side-effect arm_syscall() is now printing errors with the same
> log level as the backtrace.
> 
> Cc: Russell King <linux@armlinux.org.uk>
> Cc: Will Deacon <will@kernel.org>
> Cc: linux-arm-kernel@lists.infradead.org
> Cc: clang-built-linux@googlegroups.com
> [1]: https://lore.kernel.org/lkml/20190528002412.1625-1-dima@arista.com/T/#u
> Signed-off-by: Dmitry Safonov <dima@arista.com>
> ---
>  arch/arm/include/asm/unwind.h | 3 ++-
>  arch/arm/kernel/traps.c       | 6 +++---
>  arch/arm/kernel/unwind.c      | 7 ++++---
>  3 files changed, 9 insertions(+), 7 deletions(-)
> 
> diff --git a/arch/arm/include/asm/unwind.h b/arch/arm/include/asm/unwind.h
> index 6e282c33126b..0f8a3439902d 100644
> --- a/arch/arm/include/asm/unwind.h
> +++ b/arch/arm/include/asm/unwind.h
> @@ -36,7 +36,8 @@ extern struct unwind_table *unwind_table_add(unsigned long start,
>  					     unsigned long text_addr,
>  					     unsigned long text_size);
>  extern void unwind_table_del(struct unwind_table *tab);
> -extern void unwind_backtrace(struct pt_regs *regs, struct task_struct *tsk);
> +extern void unwind_backtrace(struct pt_regs *regs, struct task_struct *tsk,
> +			     const char *loglvl);
>  
>  #endif	/* !__ASSEMBLY__ */
>  
> diff --git a/arch/arm/kernel/traps.c b/arch/arm/kernel/traps.c
> index 7c3f32b26585..69e35462c9e9 100644
> --- a/arch/arm/kernel/traps.c
> +++ b/arch/arm/kernel/traps.c
> @@ -202,7 +202,7 @@ static void dump_instr(const char *lvl, struct pt_regs *regs)
>  #ifdef CONFIG_ARM_UNWIND
>  static inline void dump_backtrace(struct pt_regs *regs, struct task_struct *tsk)
>  {
> -	unwind_backtrace(regs, tsk);
> +	unwind_backtrace(regs, tsk, KERN_DEBUG);

Why demote this to debug level?  This is used as part of the kernel
panic message, surely we don't want this at debug level?  What about
the non-unwind version?

>  }
>  #else
>  static void dump_backtrace(struct pt_regs *regs, struct task_struct *tsk)
> @@ -660,10 +660,10 @@ asmlinkage int arm_syscall(int no, struct pt_regs *regs)
>  	if (user_debug & UDBG_SYSCALL) {
>  		pr_err("[%d] %s: arm syscall %d\n",
>  		       task_pid_nr(current), current->comm, no);
> -		dump_instr("", regs);
> +		dump_instr(KERN_ERR, regs);
>  		if (user_mode(regs)) {
>  			__show_regs(regs);
> -			c_backtrace(frame_pointer(regs), processor_mode(regs), NULL);
> +			c_backtrace(frame_pointer(regs), processor_mode(regs), KERN_ERR);
>  		}
>  	}
>  #endif
> diff --git a/arch/arm/kernel/unwind.c b/arch/arm/kernel/unwind.c
> index 0a65005e10f0..caaae1b6f721 100644
> --- a/arch/arm/kernel/unwind.c
> +++ b/arch/arm/kernel/unwind.c
> @@ -455,11 +455,12 @@ int unwind_frame(struct stackframe *frame)
>  	return URC_OK;
>  }
>  
> -void unwind_backtrace(struct pt_regs *regs, struct task_struct *tsk)
> +void unwind_backtrace(struct pt_regs *regs, struct task_struct *tsk,
> +		      const char *loglvl)
>  {
>  	struct stackframe frame;
>  
> -	pr_debug("%s(regs = %p tsk = %p)\n", __func__, regs, tsk);
> +	printk("%s%s(regs = %p tsk = %p)\n", loglvl, __func__, regs, tsk);

Clearly, this isn't supposed to be part of the normal backtrace output...

Overall impression at this point is really not good.

-- 
RMK's Patch system: https://www.armlinux.org.uk/developer/patches/
FTTC broadband for 0.8mile line in suburbia: sync at 12.1Mbps down 622kbps up
According to speedtest.net: 11.9Mbps down 500kbps up