Re: [PATCH 43/50] xtensa: Add show_stack_loglvl()

[Max Filippov]

Hi Dmitry,

On Tue, Nov 5, 2019 at 7:08 PM Dmitry Safonov <dima@xxxxxxxxxx> 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.
>
> Introduce show_stack_loglvl(), that eventually will substitute
> show_stack().
>
> Cc: Chris Zankel <chris@xxxxxxxxxx>
> Cc: Max Filippov <jcmvbkbc@xxxxxxxxx>
> Cc: linux-xtensa@xxxxxxxxxxxxxxxx
> [1]: https://lore.kernel.org/lkml/20190528002412.1625-1-dima@xxxxxxxxxx/T/#u
> Signed-off-by: Dmitry Safonov <dima@xxxxxxxxxx>
> ---
>  arch/xtensa/kernel/traps.c | 16 +++++++++++-----
>  1 file changed, 11 insertions(+), 5 deletions(-)
>
> diff --git a/arch/xtensa/kernel/traps.c b/arch/xtensa/kernel/traps.c
> index cbc0d673f542..ba6c150095c6 100644
> --- a/arch/xtensa/kernel/traps.c
> +++ b/arch/xtensa/kernel/traps.c
> @@ -502,7 +502,8 @@ static void show_trace(struct task_struct *task, unsigned long *sp,
>
>  static int kstack_depth_to_print = 24;
>
> -void show_stack(struct task_struct *task, unsigned long *sp)
> +void show_stack_loglvl(struct task_struct *task, unsigned long *sp,
> +                      const char *loglvl)
>  {
>         int i = 0;
>         unsigned long *stack;
> @@ -511,16 +512,21 @@ void show_stack(struct task_struct *task, unsigned long *sp)
>                 sp = stack_pointer(task);
>         stack = sp;
>
> -       pr_info("Stack:\n");
> +       printk("%sStack:\n", loglvl);
>
>         for (i = 0; i < kstack_depth_to_print; i++) {
>                 if (kstack_end(sp))
>                         break;
> -               pr_cont(" %08lx", *sp++);
> +               printk("%s %08lx", loglvl, *sp++);
>                 if (i % 8 == 7)
> -                       pr_cont("\n");
> +                       printk("%s\n", loglvl);
>         }
> -       show_trace(task, stack, KERN_INFO);
> +       show_trace(task, stack, loglvl);
> +}
> +
> +void show_stack(struct task_struct *task, unsigned long *sp)
> +{
> +       show_stack_loglvl(task, sp, KERN_INFO);
>  }
>
>  DEFINE_SPINLOCK(die_lock);
> --
> 2.23.0

This change doesn't work well with printk timestamps, it changes
the following output on xtensa architecture

[    3.404675] Stack:
[    3.404861]  a05773e2 00000018 bb03dc34 bb03dc30 a0008640 bb03dc70
ba9ba410 37c3f000
[    3.405414]  37c3f000 d7c3f000 00000800 bb03dc50 a02b97ed bb03dc90
ba9ba400 ba9ba410
[    3.405969]  a05fc1bc bbff28dc 00000000 bb03dc70 a02b7fb9 bb03dce0
ba9ba410 a0579044

into this:
[    3.056825] Stack:
[    3.056963]  a04ebb20
[    3.056995]  bb03dc10
[    3.057138]  00000001
[    3.057277]  bb03dc10
[    3.057815]  a00083ca
[    3.057965]  bb03dc50
[    3.058107]  ba9ba410
[    3.058247]  37c3f000
[    3.058387]
[    3.058584]  a05773e2
[    3.058614]  00000001
[    3.058755]  a05ca0bc
[    3.058896]  bb03dc30
[    3.059035]  a000865c
[    3.059180]  bb03dc70
[    3.059319]  ba9ba410
[    3.059459]  37c3f000
[    3.059598]
[    3.059795]  37c3f000
[    3.059824]  d7c3f000
[    3.059964]  00000800
[    3.060103]  bb03dc50
[    3.060241]  a02b9809
[    3.060379]  bb03dc90
[    3.060519]  ba9ba400
[    3.060658]  ba9ba410
[    3.060796]

-- 
Thanks.
-- Max