| Message ID | 20191106030542.868541-6-dima@arista.com (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
| Series | None | expand |
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.
On 11/6/19 9:12 AM, Russell King - ARM Linux admin wrote: > On Wed, Nov 06, 2019 at 03:04:56AM +0000, Dmitry Safonov wrote: >> 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? Right, I wanted to keep the old loglevel in this patch - KERN_DEFAULT. But got confused with log level in unwind_backtrace(). Will fix. [..] >> 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... Yes, sorry it's debug for a backtrace - will return pr_debug() for the message. Thanks, Dmitry
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); } #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); if (!tsk) tsk = current; @@ -493,7 +494,7 @@ void unwind_backtrace(struct pt_regs *regs, struct task_struct *tsk) urc = unwind_frame(&frame); if (urc < 0) break; - dump_backtrace_entry(where, frame.pc, frame.sp - 4, NULL); + dump_backtrace_entry(where, frame.pc, frame.sp - 4, loglvl); } }
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(-)