[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <YYVakNdzjrYuBmhf@alley>
Date: Fri, 5 Nov 2021 17:23:44 +0100
From: Petr Mladek <pmladek@...e.com>
To: John Ogness <john.ogness@...utronix.de>
Cc: Nicholas Piggin <npiggin@...il.com>,
Laurent Dufour <ldufour@...ux.ibm.com>,
linux-kernel@...r.kernel.org
Subject: Re: Removal of printk safe buffers delays NMI context printk
On Fri 2021-11-05 15:03:27, John Ogness wrote:
> On 2021-11-05, Nicholas Piggin <npiggin@...il.com> wrote:
> >> What was removed from 93d102f094b was irq_work triggering on all
> >> CPUs.
> >
> > No, it was the caller executing the flush for all remote CPUs itself.
> > irq work was not involved (and irq work can't be raised in a remote
> > CPU from NMI context).
>
> Maybe I am missing something. In 93d102f094b~1 I see:
>
> watchdog_smp_panic
> printk_safe_flush
> __printk_safe_flush
> printk_safe_flush_buffer
> printk_safe_flush_line
> printk_deferred
> vprintk_deferred
> vprintk_emit (but no direct printing)
> defer_console_output
> irq_work_queue
>
> AFAICT, using defer_console_output() instead of your new printk_flush()
> should cause the exact behavior as before.
I agree. printk_safe_flush() used printk_deferred(). It only queued
the irq_work and never called consoles directly.
> > but we do need that printk flush capability back there and for
> > nmi_backtrace.
>
> Agreed. I had not considered this necessary side-effect when I removed
> the NMI safe buffers.
Honestly, I do not understand why it stopped working or how
it worked before.
printk() calls vprintk(). Current vprintk() does:
asmlinkage int vprintk(const char *fmt, va_list args)
{
[...]
/*
* Use the main logbuf even in NMI. But avoid calling console
* drivers that might have their own locks.
*/
if (this_cpu_read(printk_context) || in_nmi()) {
int len;
len = vprintk_store(0, LOGLEVEL_DEFAULT, NULL, fmt, args);
defer_console_output();
return len;
}
/* No obstacles. */
return vprintk_default(fmt, args);
}
By other words, current vprintk():
+ queues irq_work() in NMI context
+ tries to flush consoles immeditely otherwise
> I am just wondering if we should fix the regression by going back to
> using irq_work (such as defer_console_output()) or if we want to
> introduce something new that introduces direct printing.
Yup, defer_console_output() should do the same as printk_safe_flush()
before. We do not longer need to copy the messages because they are
already in the main lockless log buffer.
Well, I am curious about the original code. The commit 93d102f094be9beab28e5
("printk: remove safe buffers") did the following:
diff --git a/arch/powerpc/kernel/watchdog.c b/arch/powerpc/kernel/watchdog.c
index c9a8f4781a10..dc17d8903d4f 100644
--- a/arch/powerpc/kernel/watchdog.c
+++ b/arch/powerpc/kernel/watchdog.c
@@ -183,11 +183,6 @@ static void watchdog_smp_panic(int cpu, u64 tb)
wd_smp_unlock(&flags);
- printk_safe_flush();
- /*
- * printk_safe_flush() seems to require another print
- * before anything actually goes out to console.
- */
if (sysctl_hardlockup_all_cpu_backtrace)
trigger_allbutself_cpu_backtrace();
And I am curious because:
+ Why was printk_safe_flush() called before triggering backtraces
on other CPUs?
+ The comment says that another print is needed before the messages
goes to the console. It makes sense because printk_safe_flush()
only set irq_work. But the patch did not remove any printk().
So, nobody called any printk() even before.
Best Regards,
Petr
Powered by blists - more mailing lists