Messages in this thread | | | Date | Tue, 22 Sep 2015 12:27:43 +0200 | From | Jan Kara <> | Subject | Re: [PATCH 1/4] printk: Hand over printing to console if printing too long |
| |
On Fri 18-09-15 15:14:59, Andrew Morton wrote: > On Wed, 19 Aug 2015 17:38:28 +0200 Jan Kara <jack@suse.com> wrote: > > > From: Jan Kara <jack@suse.cz> > > > > Currently, console_unlock() prints messages from kernel printk buffer to > > console while the buffer is non-empty. When serial console is attached, > > printing is slow and thus other CPUs in the system have plenty of time > > to append new messages to the buffer while one CPU is printing. Thus the > > CPU can spend unbounded amount of time doing printing in console_unlock(). > > This is especially serious problem if the printk() calling > > console_unlock() was called with interrupts disabled. > > > > In practice users have observed a CPU can spend tens of seconds printing > > in console_unlock() (usually during boot when hundreds of SCSI devices > > are discovered) resulting in RCU stalls (CPU doing printing doesn't > > reach quiescent state for a long time), softlockup reports (IPIs for the > > printing CPU don't get served and thus other CPUs are spinning waiting > > for the printing CPU to process IPIs), and eventually a machine death > > (as messages from stalls and lockups append to printk buffer faster than > > we are able to print). So these machines are unable to boot with serial > > console attached. Also during artificial stress testing SATA disk > > disappears from the system because its interrupts aren't served for too > > long. > > > > This patch implements a mechanism where after printing specified number > > of characters (tunable as a kernel parameter printk.offload_chars), CPU > > doing printing asks for help by waking up one of dedicated kthreads. As > > soon as the printing CPU notices kthread got scheduled and is spinning > > on print_lock dedicated for that purpose, it drops console_sem, > > print_lock, and exits console_unlock(). Kthread then takes over printing > > instead. This way no CPU should spend printing too long even if there > > is heavy printk traffic. > > > > ... > > > > @@ -2230,6 +2292,8 @@ void console_unlock(void) > > unsigned long flags; > > bool wake_klogd = false; > > bool retry; > > + bool hand_over = false; > > + int printed_chars = 0; > > > > if (console_suspended) { > > up_console_sem(); > > @@ -2241,12 +2305,18 @@ void console_unlock(void) > > /* flush buffered message fragment immediately to console */ > > console_cont_flush(text, sizeof(text)); > > again: > > + spin_lock(&print_lock); > > I'm surprised this isn't spin_lock_irqsave(). How come this isn't > deadlockable?
Yes, it should be spin_lock_irqsave(). My original plan was to nest print_lock inside logbuf_lock which would provide the protection but later I've ordered them the other way around and forgot to update the irq protection. Will fix.
> > for (;;) { > > struct printk_log *msg; > > size_t ext_len = 0; > > size_t len; > > int level; > > > > + if (cpu_stop_printing(printed_chars)) { > > + hand_over = true; > > + break; > > + } > > + > > raw_spin_lock_irqsave(&logbuf_lock, flags); > > if (seen_seq != log_next_seq) { > > wake_klogd = true; > > > > ... > > > > +/* Kthread which takes over printing from a CPU which asks for help */ > > +static int printing_task(void *arg) > > +{ > > + DEFINE_WAIT(wait); > > + > > + while (1) { > > + prepare_to_wait_exclusive(&print_queue, &wait, > > + TASK_INTERRUPTIBLE); > > + schedule(); > > + finish_wait(&print_queue, &wait); > > + preempt_disable(); > > I don't understand the preempt_disable(). Code comment, please?
We don't want to be scheduled away in preemptible kernels when spinning on print_lock or after we acquired print_lock and before we got console_sem. I'll add a comment.
Thanks for review! Honza
> > > + atomic_inc(&printing_tasks_spinning); > > + /* > > + * Store printing_tasks_spinning value before we spin. Matches > > + * the barrier in cpu_stop_printing(). > > + */ > > + smp_mb__after_atomic(); > > + /* > > + * Wait for currently printing thread to complete. We spin on > > + * print_lock instead of waiting on console_sem since we don't > > + * want to sleep once we got scheduled to make sure we take > > + * over printing without depending on the scheduler. > > + */ > > + spin_lock(&print_lock); > > + atomic_dec(&printing_tasks_spinning); > > + spin_unlock(&print_lock); > > + if (console_trylock()) > > + console_unlock(); > > + preempt_enable(); > > + } > > + return 0; > > +} > > > > ... > > -- Jan Kara <jack@suse.com> SUSE Labs, CR
| |