Re: [PATCH next v1 1/3] printk: track/limit recursion

[Sergey Senozhatsky]

On (21/03/22 11:53), John Ogness wrote:
> On 2021-03-21, Sergey Senozhatsky <senozhatsky@xxxxxxxxxxxx> wrote:
> >> @@ -2055,6 +2122,9 @@ int vprintk_store(int facility, int level,
> >>  	 */
> >>  	ts_nsec = local_clock();
> >>  
> >> +	if (!printk_enter_irqsave(&irqflags))
> >> +		return 0;
> >
> > I guess it can be interesting to somehow signal us that we had
> > printk() recursion overflow, and how many messages we lost.
> 
> Honestly, if we hit 3 levels of recursion, we are probably dealing with
> an infinite recursion issue.

I tend to agree.

> I do not see the value of counting the overflows in that case. The
> logged messages at that recursion level would ben enough to point
> us to the problem.
>
> > 3 levels of recursion seem like reasonable limit, but I maybe wouldn't
> > mind one extra level.
>
> With 3 levels, we will see all the messages of:
>
>     printk -> WARN_ON -> WARN_ON -> WARN_ON

Well, not necessarily this simple.

printk
 vsprintf
  handle_foo_specifier
   printk
    call_console_drivers
     timekeeping
      printk
       vsprintf

We saw in the past that enabling CONFIG_DEBUG_OBJECTS (if I'm not
mistaken) can add quite a bit of extra printk recursion paths.

We also have other CONFIG_DEBUG_* config options that can pop up as
recursive printk-s here and there. For instance, from vsprintf::foo_specifier()
where we escape from printk() to various kernel subsystems: net, block,
etc.

Maybe sometimes on level 3+ we'll see something interesting,
but I've no strong opinion on this.

> Keep in mind that each additional level causes the reading of the logs
> to be significantly more complex. Each level increases the output
> exponentially:

Yes, I realize that. That's why I suggested that maybe recursive
printk-s can have some special extra prefix. Recursive printk-s
will interleave with whatever is being printed on this_cpu, so
prefix might be helpful.

	-ss