Messages in this thread | | | Date | Fri, 18 Sep 2015 15:14:59 -0700 | From | Andrew Morton <> | Subject | Re: [PATCH 1/4] printk: Hand over printing to console if printing too long |
| |
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?
> 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?
> + 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; > +} > > ... >
| |