Messages in this thread | | | Date | Wed, 25 Apr 2018 10:59:39 +0900 | From | Sergey Senozhatsky <> | Subject | Re: [RFC][PATCH] printk: do not call console drivers from printk_safe context |
| |
On (04/24/18 10:51), Steven Rostedt wrote: [..] > > console_lock_spinning_enable(); > > > > + __printk_safe_exit(); > > stop_critical_timings(); /* don't trace print latency */ > > call_console_drivers(ext_text, ext_len, text, len); > > start_critical_timings(); > > + __printk_safe_enter(); > > > > OK, I'm still confused (It's been that kind of week)
No worries, I'm here to help. The email is, once again, a bit long, but hey at least I'm using capitals now ;)
> So, if we do this, and the consoles do a printk(), doesn't that fill > the logbuf?
Yes. It's been this way for many years, and, in fact, even with printk_safe() we still add concole_drivers->printk() messages to the logbuf ASAP, which mostly happens while the printing CPU is still in console_unlock() loop [see #flushing below].
> And then the loop this is in will just continue to perform that loop?
Yes. And it's the same even with printk_safe(). Except that printk_safe() costs us 2 extra IRQ works on that CPU.
In short, what printk_safe() does:
a) protects us from deadlocking on logbuf spin_lock
E.g. vprintk_emit() { raw_spin_lock(&logbuf_lock); vscnprintf(text, sizeof(textbuf), fmt, args) : WARN_ONCE(1, "Unsupported flags modifier....) : printk() : vprintk_emit() : raw_spin_lock(&logbuf_lock); <<<<<<< raw_spin_unlock(&logbuf_lock); }
b) protects us from deadlocking on console_sem (for example, console_sem ->lock spin_lock)
E.g. console_unlock() { for (;;) { if (console_seq == log_next_seq) break; }
up() : raw_spin_lock_irqsave(&sem->lock, flags); : printk() : vprintk_emit() : if (console_trylock_spinning()) : console_trylock() : down_trylock() : raw_spin_lock_irqsave(&sem->lock, flags); <<<<<<< }
c) protects us from deadlocking on console_sem_owner spin_lock Basically, the same as (a) - deadlock on spin_lock, but at the moment I'd say a rather theoretical case.
d) protects us from deadlocking on _some_ external locks. For example, scheduler ->pi_lock lock
> That is, we have: > > for (;;) { > if (console_seq == log_next_seq) > break; > console_seq++; > call_console_drives() { > printk() { > log_next_seq++; > } > } > } > > That looks like an infinite loop to me.
Correct, this is how it works. And I think we need to preserve that "console drivers can add messages to the logbuf" and to avoid any interference [and by interference I mean a deliberate message loss] with the messages. I have provided some links [in another email] to support that claim, let me know.
I'd love to see real backtraces/logs when we actually have that infinite loop.
> Whereas the printk_safe keeps from adding to the logbuf?
#flushing
printk_safe() does not keep console drivers from adding new messages to the logbuf. We flush [move messages to the logbuf] printk_safe() per-CPU buffer the moment we enable local IRQ on that CPU: which is, basically, right after call_console_drivers():
for (;;) { printk_safe_enter_irqsave(flags); raw_spin_lock(&logbuf_lock);
if (console_seq == log_next_seq) break; console_seq++; raw_spin_unlock(&logbuf_lock);
call_console_drives() { printk() printk_safe_log_store() :: irq_work_queue() :: }
printk_safe_exit_irqrestore(flags); ::
<< IRQ >> printk_safe_flush_buffer() printk_deferred() log_store() << log_next_seq++ irq_work_queue() }
In it's current form printk_safe() is redundant here.
-ss
| |