public inbox for linux-kernel@vger.kernel.org
 help / color / mirror / Atom feed
* Re: [PATCH 5/7] printk: Add config option for disabling printk offloading
@ 2015-12-10 15:10 Sergey Senozhatsky
  0 siblings, 0 replies; 2+ messages in thread
From: Sergey Senozhatsky @ 2015-12-10 15:10 UTC (permalink / raw)
  To: Jan Kara
  Cc: Andrew Morton, Petr Mladek, KY Srinivasan, Steven Rostedt,
	linux-kernel, Sergey Senozhatsky, Sergey Senozhatsky

> Necessity for offloading of printing was observed only for large
> systems. So add a config option (disabled by default) which removes most
> of the overhead added by this functionality.

to be folded:


- add spin_lock_init_print_lock() to be called from zap_lock()
- move PRINTK_OFFLOAD defines up, so zap_lock() sees them

---
 kernel/printk/printk.c | 119 ++++++++++++++++++++++++++-----------------------
 1 file changed, 63 insertions(+), 56 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 2a500a5..86f5abf 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -333,7 +333,66 @@ module_param_cb(offload_chars, &offload_chars_ops, &printk_offload_chars,
 		   S_IRUGO | S_IWUSR);
 MODULE_PARM_DESC(offload_chars, "offload printing to console to a different"
 	" cpu after this number of characters");
-#endif
+
+/*
+ * Returns true iff there is other cpu waiting to take over printing. This
+ * function also takes are of setting PRINTK_HANDOVER_B if we want to hand over
+ * printing to some other cpu.
+ */
+static bool cpu_stop_printing(int printed_chars)
+{
+	/* Oops? Print everything now to maximize chances user will see it */
+	if (oops_in_progress)
+		return false;
+	if (!printk_offload_chars || printed_chars < printk_offload_chars)
+		return false;
+	/*
+	 * Make sure we load fresh value of printing_tasks_spinning. Matches
+	 * the barrier in printing_task()
+	 */
+	smp_rmb();
+	if (atomic_read(&printing_tasks_spinning))
+		return true;
+	wake_up(&print_queue);
+
+	return false;
+}
+
+static bool cpu_should_cond_resched(bool do_cond_resched)
+{
+	/* Oops? Print everything now to maximize chances user will see it */
+	if (oops_in_progress)
+		return false;
+	if (!printk_offload_chars && do_cond_resched)
+		return true;
+	return false;
+}
+
+#define spin_lock_print_lock(flags) raw_spin_lock_irqsave(&print_lock, flags)
+
+#define spin_unlock_print_lock(flags) raw_spin_unlock_irqrestore(&print_lock, flags)
+
+#define spin_lock_init_print_lock() raw_spin_lock_init(&print_lock)
+
+#else /* !CONFIG_PRINTK_OFFLOAD */
+
+static bool cpu_stop_printing(int printed_chars)
+{
+	return false;
+}
+
+static bool cpu_should_cond_resched(bool do_cond_resched)
+{
+	return do_cond_resched && !oops_in_progress;
+}
+
+#define spin_lock_print_lock(flags) local_irq_save(flags)
+
+#define spin_unlock_print_lock(flags) local_irq_restore(flags)
+
+#define spin_lock_init_print_lock()
+
+#endif /* CONFIG_PRINTK_OFFLOAD */
 
 /* Return log buffer address */
 char *log_buf_addr_get(void)
@@ -1531,7 +1590,7 @@ static void zap_locks(void)
 	/* If a crash is occurring, make sure we can't deadlock */
 	raw_spin_lock_init(&logbuf_lock);
 	/* And make sure that we print immediately */
-	raw_spin_lock_init(&print_lock);
+	spin_lock_init_print_lock();
 	sema_init(&console_sem, 1);
 }
 
@@ -2265,58 +2324,6 @@ out:
 	raw_spin_unlock_irqrestore(&logbuf_lock, flags);
 }
 
-#ifdef CONFIG_PRINTK_OFFLOAD
-/*
- * Returns true iff there is other cpu waiting to take over printing. This
- * function also takes are of setting PRINTK_HANDOVER_B if we want to hand over
- * printing to some other cpu.
- */
-static bool cpu_stop_printing(int printed_chars)
-{
-	/* Oops? Print everything now to maximize chances user will see it */
-	if (oops_in_progress)
-		return false;
-	if (!printk_offload_chars || printed_chars < printk_offload_chars)
-		return false;
-	/*
-	 * Make sure we load fresh value of printing_tasks_spinning. Matches
-	 * the barrier in printing_task()
-	 */
-	smp_rmb();
-	if (atomic_read(&printing_tasks_spinning))
-		return true;
-	wake_up(&print_queue);
-
-	return false;
-}
-
-static bool cpu_should_cond_resched(bool do_cond_resched)
-{
-	/* Oops? Print everything now to maximize chances user will see it */
-	if (oops_in_progress)
-		return false;
-	if (!printk_offload_chars && do_cond_resched)
-		return true;
-	return false;
-}
-
-#define spin_lock_print_lock(flags) raw_spin_lock_irqsave(&print_lock, flags)
-
-#define spin_unlock_print_lock(flags) raw_spin_unlock_irqrestore(&print_lock, flags)
-
-#else
-
-static bool cpu_stop_printing(int printed_chars)
-{
-	return false;
-}
-
-#define spin_lock_print_lock(flags) local_irq_save(flags)
-
-#define spin_unlock_print_lock(flags) local_irq_restore(flags)
-
-#endif
-
 /**
  * console_unlock - unlock the console system
  *
@@ -2440,9 +2447,9 @@ skip:
 		printed_chars += len;
 
 		if (unlikely(cpu_should_cond_resched(do_cond_resched))) {
-			raw_spin_unlock_irqrestore(&print_lock, flags);
+			spin_unlock_print_lock(flags);
 			cond_resched();
-			raw_spin_lock_irqsave(&print_lock, flags);
+			spin_lock_print_lock(flags);
 		}
 	}
 
-- 
2.6.3


^ permalink raw reply related	[flat|nested] 2+ messages in thread
* [PATCH 0/6 v2] printk: Softlockup avoidance
@ 2015-10-26  4:52 Jan Kara
  2015-10-26  4:52 ` [PATCH 5/7] printk: Add config option for disabling printk offloading Jan Kara
  0 siblings, 1 reply; 2+ messages in thread
From: Jan Kara @ 2015-10-26  4:52 UTC (permalink / raw)
  To: Andrew Morton; +Cc: LKML, pmladek, KY Srinivasan, rostedt, Jan Kara

From: Jan Kara <jack@suse.cz>

Hello,

here is another posting of the revived patch set to avoid lockups during heavy
printing. Lately there were several attempts at dealing with softlockups due to
heavy printk traffic [1] [2] and I've been also privately pinged by couple of
people about the state of the patch set, so I've decided to revive the patch
set. Patches (their older version) are present in SUSE enterprise kernels for
several years and we didn't observe any issues with them.

Patch set passes my stress testing where serial console is slowed down to print
~1000 chars per second and there are 100 delayed works printing together some
64k of text and in parallel modules are inserted which generates quite some
additional messages, stop_machine() calls etc.

Changes since v1:
* printing kthreads now check for kthread_should_stop()
* printing kthreads are now bound to CPUs so that scheduler cannot decide to
  schedule both kthreads on one CPU which effectively makes it impossible to
  hand over printing between them. This happened relatively frequently in
  virtual machines.
* use printk buffer draining code in panic() to force all messages out when
  the system is dying
* better naming of logbuf flushing functions suggested by AKPM
* fixed irq safety of printing lock as pointed out by AKMP
* fixed various smaller issues pointed by AKPM


Changes since the the old patch set [3]:
* I have replaced the state machine to pass printing and spinning on
  console_sem with a simple spinlock which makes the code
  somewhat easier to read and verify.
* Some of the patches were merged so I dropped them.

To remind the original problem:

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 when printk() gets called under some critical
spinlock or 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 series addresses the problem in the following way: If CPU has printed
more that printk_offload (defaults to 1000) characters, it wakes up one
of dedicated printk kthreads (we don't use workqueue because that has
deadlock potential if printk was called from workqueue code). Once we find
out kthread is spinning on a lock, we stop printing, drop console_sem, and
let kthread continue printing. Since there are two printing kthreads, they
will pass printing between them and thus no CPU gets hogged by printing.

								Honza

[1] https://lkml.org/lkml/2015/7/8/215
[2] http://marc.info/?l=linux-kernel&m=143929238407816&w=2
[3] https://lkml.org/lkml/2014/3/17/68

^ permalink raw reply	[flat|nested] 2+ messages in thread
end of thread, other threads:[~2015-12-10 15:12 UTC | newest]

Thread overview: 2+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2015-12-10 15:10 [PATCH 5/7] printk: Add config option for disabling printk offloading Sergey Senozhatsky
  -- strict thread matches above, loose matches on Subject: below --
2015-10-26  4:52 [PATCH 0/6 v2] printk: Softlockup avoidance Jan Kara
2015-10-26  4:52 ` [PATCH 5/7] printk: Add config option for disabling printk offloading Jan Kara

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox