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

[John Ogness <john.ogness@linutronix.de>]

On 2021-03-21, Sergey Senozhatsky <senozhatsky@chromium.org> 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 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

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

   for every line1 in 1st_WARN_ON {
      for every line2 in 2nd_WARN_ON {
         for every line3 in 3rd_WARN_ON {
            print $line3
         }
         print $line2
      }
      print $line1
   }
   print $line0

IMHO 2 levels is enough because we should _never_ hit 2 levels of
recursion. If we do, the log output at that second level should be
enough to point to the bug. IMHO printing a third level just makes
things unnecessarily difficult to read. (My series uses 3 levels as a
compromise on my part. I would prefer reducing it to 2.)

> And maybe we could add some sort of message prefix for high levels of
> recursion nesting (levels 3+), so that things should not be normal
> will be on the radars and, possibly, will be reported.

I considered this, but am very hesitant to change the output
format. Also, the CUT_HERE usage (combined with PRINTK_CALLER) seem to
be enough.

John Ogness