Re: panic context: was: Re: [PATCH printk v2 04/11] printk: nbcon: Provide functions to mark atomic write sections

[John Ogness]

On 2023-10-09, Petr Mladek <pmladek@xxxxxxxx> wrote:
> We really have to distinguish emergency and panic context!

OK.

>> The LPC2022 demo/talk was recorded:
>> 
>> https://www.youtube.com/watch?v=TVhNcKQvzxI
>> 
>> At 55:55 is where the situation occurred and triggered the conversation,
>> ultimately leading to this new feature.
>
> Thanks for the link. My understanding is that the following scenario
> has happened:
>
> 1. System was booting and messages were being flushed using the kthread.
>
> 2. WARN() happened. It printed the 1st line, took over the per-console
>    console lock and started flushing the backlog. There were still
>    many pending messages from the boot.
>
> 3. NMI came and caused panic(). The panic context printed its first line,
>    took over the console from the WARN context, flushed the rest
>    of the backlog and continued printing/flushing more messages from
>    the panic() context.
>
>
> Problem:
>
> People complained that they saw only the first line from WARN().
> The related detailed info, including backtrace, was missing.
>
> It was because panic() interrupted WARN() before it was able
> to flush the backlog and print/flush all WARN() messages.

Thanks for taking the time to review it in detail.

> Proposed solution:
>
> WARN()/emergency context should first store the messages and
> flush them at the end.
>
> It would increase the chance that all WARN() messages will
> be stored in the ring buffer before NMI/panic() is called.
>
> panic() would then flush all pending messages including
> the stored WARN() messages.

OK.

> Important:
>
> The problem is that panic() interrupted WARN().

Ack.

>> You may also want to reread my summary:
>>
>> https://lore.kernel.org/lkml/875yheqh6v.fsf@xxxxxxxxxxxxxxxxxxxxx
>
> Again, thanks for the pointer. Let me paste 2 paragraphs here:
>
> <paste>
> - Printing the backlog is important! If some emergency situation occurs,
>   make sure the backlog gets printed.
>
> - When an emergency occurs, put the full backtrace into the ringbuffer
>   before flushing any backlog. This ensures that the backtrace makes it
>   into the ringbuffer in case a panic occurs while flushing the backlog.
> </paste>
>
> My understanding is:
>
> 1st paragraph is the reason why:
>
>    + we have three priorities: normal, emergency, panic
>
>    + messages in normal context might be offloaded to kthread
>
>    + emergency and panic context should try to flush the messages
>      from this context.
>
>
> 2nd paragraph talks about that emergency context should first store
> the messages and flush them later. And the important part:
>
>      "in case a panic occurs while flushing the backlog.
>
>      => panic might interrupt emergency
>
> It clearly distinguishes emergency and panic context.
>
>
>> as well as Linus' follow-up message:
>> 
>> https://lore.kernel.org/lkml/CAHk-=wieXPMGEm7E=Sz2utzZdW1d=9hJBwGYAaAipxnMXr0Hvg@xxxxxxxxxxxxxx
>
> IMHO, the important part is:
>
> <paste>
> Yeah, I really liked the notion of doing the oops with just filling
> the back buffer but still getting it printed out if something goes
> wrong in the middle.
> </paste>
>
> He was talking about oops => emergency context
>
> Also he wanted to get it out when something goes wrong in the middle
>    => panic in the middle ?
>
>
> And another paragraph:
>
> <paste>
> I doubt it ends up being an issue in practice, but basically I wanted
> to just pipe up and say that the exact details of how much of the back
> buffer needs to be flushed first _could_ be tweaked if it ever does
> come up as an issue.
> </paste>
>
> Linus had doubts that there might be problems with too long backlog
> in practice. And I have the doubts as well.
>
> And this is my view. The deferred flush is trying to solve a corner
> case and we are forgetting what blocked printk kthreads >10 years.

OK. Thank you for the detailed analysis.

For v3 I will do something similar to what you proposed [0], except that
I will use a per-cpu variable (to track printk emergency nesting)
instead of adding a new field to the task struct.

John Ogness

[0] https://lore.kernel.org/lkml/ZRLBxsXPCym2NC5Q@alley/