[PATCH printk v4 00/14] fix console flushing

John Ogness
2024-02-07T13:41:15Z

Hi,

While testing various flushing scenarios, I stumbled on a few
issues that cause console flushing to fail. While at LPC2023 in
Richmond, I sat down with Petr Mladek and we reviewed the
v2 [0] series. This series is the result of that offline
discussion. v3 is here [1].

This series addresses the following issues:

1. The prb_next_seq() optimization caused inconsistent return
values. Fix prb_next_seq() to the originally intended
behavior but keep an optimization.

2. pr_flush() might not wait until the most recently stored
printk() message if non-finalized records precede it. Fix
pr_flush() to wait for all records to print that are at
least reserved at the time of the call.

3. In panic, the panic messages will not print if non-finalized
records precede them. Add a special condition so that
readers on the panic CPU will drop records that are not in
a consistent state.

4. It is possible (and easy to reproduce) a scenario where the
console on the panic CPU hands over to a waiter of a stopped
CPU. Do not use the handover feature in panic.

5. If messages are being dropped during panic, non-panic CPUs
are silenced. But by then it is already too late and most
likely the panic messages have been dropped. Change the
non-panic CPU silencing logic to _immediately_ silence
non-panic CPUs during panic. This also leads to clean panic
output when many CPUs are blasting the kernel log.

6. If a panic occurs in a context where printk() calls defer
printing (NMI or printk_safe section), the printing of the
final panic messages rely on irq_work. If that mechanism is
not available, the final panic messages are not seen (even
though they are finalized in the ringbuffer). Add one last
explicit flush after all printk() calls are finished to
ensure all available messages in the kernel log are printed.

7. When dumping the stacktrace from panic(), do not use the
printk_cpu_sync because it can deadlock if another CPU holds
and is unable to release the printk_cpu_sync.

This series also performs some minor cleanups to remove open
coded checks about the panic context and improve documentation
language regarding data-less records.

Because of multiple refactoring done in recent history, it
would be helpful to provide the LTS maintainers with the proper
backported patches. I am happy to do this.

The changes since v3:

- Drop patch 11 of v3 ("printk: ringbuffer: Consider committed
as finalized in panic"). It adds complexity, may not perform
as expected, and it is questionable as to whether it would
help provide useful messages on panic.

- Changed several comments according to the suggestions by
Petr. Note that I did not include all the suggestions
because IMO they were too vague in describing the related
memory barriers.

- Add a patch to avoid using printk_cpu_sync on panic(). This
was recently discussed [2]. Feel free to drop the patch
14/14 ("dump_stack: Do not get cpu_sync for panic CPU") if
you think it is not appropriate or will significantly delay
this series.

John Ogness

[0] https://lore.kernel.org/lkml/20231106210730.115192-1-john.ogness@linutronix.de
[1] https://lore.kernel.org/lkml/20231214214201.499426-1-john.ogness@linutronix.de
[2] https://lore.kernel.org/lkml/ZcIGKU8sxti38Kok@alley

John Ogness (12):
printk: nbcon: Relocate 32bit seq macros
printk: Use prb_first_seq() as base for 32bit seq macros
printk: ringbuffer: Do not skip non-finalized records with
prb_next_seq()
printk: ringbuffer: Clarify special lpos values
printk: For @suppress_panic_printk check for other CPU in panic
printk: Add this_cpu_in_panic()
printk: ringbuffer: Cleanup reader terminology
printk: Wait for all reserved records with pr_flush()
printk: ringbuffer: Skip non-finalized records in panic
printk: Avoid non-panic CPUs writing to ringbuffer
panic: Flush kernel log buffer at the end
dump_stack: Do not get cpu_sync for panic CPU

Petr Mladek (1):
printk: Disable passing console lock owner completely during panic()

Sebastian Andrzej Siewior (1):
printk: Adjust mapping for 32bit seq macros

include/linux/printk.h | 2 +
kernel/panic.c | 8 +
kernel/printk/nbcon.c | 41 +---
kernel/printk/printk.c | 101 +++++----
kernel/printk/printk_ringbuffer.c | 335 +++++++++++++++++++++++++-----
kernel/printk/printk_ringbuffer.h | 54 ++++-
lib/dump_stack.c | 16 +-
7 files changed, 419 insertions(+), 138 deletions(-)

base-commit: 6c3a34e38436a2a3f7a1fa764c108ee19b05b893
--
2.39.2