printk: Softlockup avoidance

259 lines not on this page · raw message

index 1b26263edfa7..b9bb4a7a6dff 100644
@@ -98,6 +98,10 @@ static atomic_t printing_tasks_spinning = ATOMIC_INIT(0);
  * CPUs.
  */
 #define PRINTING_TASKS 2
+/* Pointers to printing kthreads */
+static struct task_struct *printing_kthread[PRINTING_TASKS];
+/* Serialization of changes to printk_offload_chars and kthread creation */
+static DEFINE_MUTEX(printk_kthread_mutex);
 
 /* Wait queue printing kthreads sleep on when idle */
 static DECLARE_WAIT_QUEUE_HEAD(print_queue);

@@ -303,6 +307,13 @@ static u32 clear_idx;
 static char __log_buf[__LOG_BUF_LEN] __aligned(LOG_ALIGN);
 static char *log_buf = __log_buf;
 static u32 log_buf_len = __LOG_BUF_LEN;
+
+static int offload_chars_set(const char *val, const struct kernel_param *kp);
+static struct kernel_param_ops offload_chars_ops = {
+	.set = offload_chars_set,
+	.get = param_get_uint,
+};
+
 /*
  * How many characters can we print in one call of printk before asking
  * other cpus to continue printing. 0 means infinity. Tunable via

@@ -311,7 +322,7 @@ static u32 log_buf_len = __LOG_BUF_LEN;
  */
 static unsigned int __read_mostly printk_offload_chars = 1000;
 
-module_param_named(offload_chars, printk_offload_chars, uint,
+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");

@@ -2778,12 +2789,61 @@ static int printing_task(void *arg)
 	return 0;
 }
 
-static int __init printk_late_init(void)
+static int printk_start_offload_kthreads(void)
 {
-	struct console *con;
 	int i;
 	struct task_struct *task;
 
+	/* Does handover of printing make any sense? */
+	if (printk_offload_chars == 0 || num_possible_cpus() <= 1)
+		return 0;
+	for (i = 0; i < PRINTING_TASKS; i++) {
+		if (printing_kthread[i])
+			continue;
+		task = kthread_run(printing_task, NULL, "print/%d", i);
+		if (IS_ERR(task))
+			goto out_err;
+		printing_kthread[i] = task;
+	}
+	return 0;
+out_err:
+	pr_err("printk: Cannot create printing thread: %ld\n", PTR_ERR(task));
+	/* Disable offloading if creating kthreads failed */
+	printk_offload_chars = 0;
+	return PTR_ERR(task);
+}
+
+static int offload_chars_set(const char *val, const struct kernel_param *kp)
+{
+	int ret;
+
+	/* Protect against parallel change of printk_offload_chars */
+	mutex_lock(&printk_kthread_mutex);
+	ret = param_set_uint(val, kp);
+	if (ret) {
+		mutex_unlock(&printk_kthread_mutex);
+		return ret;
+	}
+	ret = printk_start_offload_kthreads();
+	mutex_unlock(&printk_kthread_mutex);
+	return ret;
+}
+
+static void printk_offload_init(void)
+{
+	mutex_lock(&printk_kthread_mutex);
+	if (num_possible_cpus() <= 1) {
+		/* Offloading doesn't make sense. Disable print offloading. */
+		printk_offload_chars = 0;
+	} else
+		printk_start_offload_kthreads();
+	mutex_unlock(&printk_kthread_mutex);
+}
+
+static int __init printk_late_init(void)
+{
+	struct console *con;
+
 	for_each_console(con) {
 		if (!keep_bootcon && con->flags & CON_BOOT) {
 			unregister_console(con);

@@ -2791,17 +2851,7 @@ static int __init printk_late_init(void)
 	}
 	hotcpu_notifier(console_cpu_notify, 0);
 
-	/* Does any handover of printing have any sence? */
-	if (num_possible_cpus() <= 1)
-		return 0;
-
-	for (i = 0; i < PRINTING_TASKS; i++) {
-		task = kthread_run(printing_task, NULL, "print/%d", i);
-		if (IS_ERR(task)) {
-			pr_err("printk: Cannot create printing thread: %ld\n",
-			       PTR_ERR(task));
-		}
-	}
+	printk_offload_init();
 
 	return 0;
 }

index bd194343c346..96da462cdfeb 100644
@@ -150,6 +150,17 @@ extern int console_trylock(void);
 extern void console_unlock(void);
 extern void console_conditional_schedule(void);
 extern void console_unblank(void);
+#ifdef CONFIG_SMP
+extern void printk_log_buf_drain(void);
+#else
+/*
+ * In non-SMP kernels there won't be much to drain so save some code for tiny
+ * kernels.
+ */
+static inline void printk_log_buf_drain(void)
+{
+}
+#endif
 extern struct tty_driver *console_device(int *);
 extern void console_stop(struct console *);
 extern void console_start(struct console *);

index b9bb4a7a6dff..8dc6c146d022 100644
@@ -2488,6 +2488,31 @@ struct tty_driver *console_device(int *index)
 	return driver;
 }
 
+/* For non-SMP kernels this function isn't used and would be pointless anyway */
+#ifdef CONFIG_SMP
+/*
+ * Wait until all messages accumulated in the printk buffer are printed to
+ * console. Note that as soon as this function returns, new messages may be
+ * added to the printk buffer by other CPUs.
+ */
+void printk_log_buf_drain(void)
+{
+	bool retry;
+	unsigned long flags;
+
+	while (1) {
+		raw_spin_lock_irqsave(&logbuf_lock, flags);
+		retry = console_seq != log_next_seq;
+		raw_spin_unlock_irqrestore(&logbuf_lock, flags);
+		if (!retry || console_suspended)
+			break;
+		/* Cycle console_sem to wait for outstanding printing */
+		console_lock();
+		console_unlock();
+	}
+}
+#endif
+
 /*
  * Prevent further output on the passed console device so that (for example)
  * serial drivers can disable console output before suspending a port, and can

index 12484e5d5c88..e9496b4a3825 100644
@@ -21,6 +21,7 @@
 #include <linux/smpboot.h>
 #include <linux/atomic.h>
 #include <linux/lglock.h>
+#include <linux/console.h>
 
 /*
  * Structure to determine completion condition and record errors.  May

@@ -543,6 +544,14 @@ static int __stop_machine(cpu_stop_fn_t fn, void *data, const struct cpumask *cp
 		return ret;
 	}
 
+	/*
+	 * If there are lots of outstanding messages, printing them can take a
+	 * long time and all cpus would be spinning waiting for the printing to
+	 * finish thus triggering NMI watchdog, RCU lockups etc. Wait for the
+	 * printing here to avoid these.
+	 */
+	printk_log_buf_drain();
+
 	/* Set the initial state and stop all online cpus. */
 	set_state(&msdata, MULTI_STOP_PREPARE);
 	return stop_cpus(cpu_online_mask, multi_cpu_stop, &msdata);

index 96da462cdfeb..f40084802f3f 100644
@@ -151,13 +151,13 @@ extern void console_unlock(void);
 extern void console_conditional_schedule(void);
 extern void console_unblank(void);
 #ifdef CONFIG_SMP
-extern void printk_log_buf_drain(void);
+extern void printk_log_buf_drain(bool panic);
 #else
 /*
  * In non-SMP kernels there won't be much to drain so save some code for tiny
  * kernels.
  */
-static inline void printk_log_buf_drain(void)
+static inline void printk_log_buf_drain(bool panic)
 {
 }
 #endif

index 04e91ff7560b..d07ed830a9fb 100644
@@ -23,6 +23,7 @@
 #include <linux/sysrq.h>
 #include <linux/init.h>
 #include <linux/nmi.h>
+#include <linux/console.h>
 
 #define PANIC_TIMER_STEP 100
 #define PANIC_BLINK_SPD 18

@@ -147,6 +148,13 @@ void panic(const char *fmt, ...)
 
 	bust_spinlocks(0);
 
+	/*
+	 * We may have ended up stopping the CPU doing printing (in
+	 * smp_send_stop()) while still having some valuable data in the
+	 * console buffer.  Flush it out.
+	 */
+	printk_log_buf_drain(true);
+
 	if (!panic_blink)
 		panic_blink = no_blink;
 

index 8dc6c146d022..e404c429fe87 100644
@@ -2495,11 +2495,14 @@ struct tty_driver *console_device(int *index)
  * console. Note that as soon as this function returns, new messages may be
  * added to the printk buffer by other CPUs.
  */
-void printk_log_buf_drain(void)
+void printk_log_buf_drain(bool panic)
 {
 	bool retry;
 	unsigned long flags;
 
+	if (panic)
+		zap_locks();
+
 	while (1) {
 		raw_spin_lock_irqsave(&logbuf_lock, flags);
 		retry = console_seq != log_next_seq;

index e9496b4a3825..50a03735893e 100644
@@ -550,7 +550,7 @@ static int __stop_machine(cpu_stop_fn_t fn, void *data, const struct cpumask *cp
 	 * finish thus triggering NMI watchdog, RCU lockups etc. Wait for the
 	 * printing here to avoid these.
 	 */
-	printk_log_buf_drain();
+	printk_log_buf_drain(false);
 
 	/* Set the initial state and stop all online cpus. */
 	set_state(&msdata, MULTI_STOP_PREPARE);

index e404c429fe87..5153c6518b9d 100644
@@ -79,6 +79,7 @@ static DEFINE_SEMAPHORE(console_sem);
 struct console *console_drivers;
 EXPORT_SYMBOL_GPL(console_drivers);
 
+#ifdef CONFIG_PRINTK_OFFLOAD
 /*
  * This spinlock is taken when printing to console. It is used only so that
  * we can spin on it when some other thread wants to take over printing to

@@ -105,6 +106,7 @@ static DEFINE_MUTEX(printk_kthread_mutex);
 
 /* Wait queue printing kthreads sleep on when idle */
 static DECLARE_WAIT_QUEUE_HEAD(print_queue);
+#endif	/* CONFIG_PRINTK_OFFLOAD */
 
 #ifdef CONFIG_LOCKDEP
 static struct lockdep_map console_lock_dep_map = {

@@ -308,6 +310,7 @@ static char __log_buf[__LOG_BUF_LEN] __aligned(LOG_ALIGN);
 static char *log_buf = __log_buf;
 static u32 log_buf_len = __LOG_BUF_LEN;
 
+#ifdef CONFIG_PRINTK_OFFLOAD
 static int offload_chars_set(const char *val, const struct kernel_param *kp);
 static struct kernel_param_ops offload_chars_ops = {
 	.set = offload_chars_set,

@@ -326,6 +329,7 @@ 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
 
 /* Return log buffer address */
 char *log_buf_addr_get(void)

@@ -2255,6 +2259,7 @@ 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

@@ -2279,6 +2284,23 @@ static bool cpu_stop_printing(int printed_chars)
 	return false;
 }
 
+#define spin_lock_print_lock(flags) spin_lock_irqsave(&print_lock, flags)
+
+#define spin_unlock_print_lock(flags) 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
  *

@@ -2317,7 +2339,7 @@ void console_unlock(void)
 	console_cont_flush(text, sizeof(text));
 again:
 	retry = false;
-	spin_lock_irqsave(&print_lock, flags);
+	spin_lock_print_lock(flags);
 	for (;;) {
 		struct printk_log *msg;
 		size_t ext_len = 0;

@@ -2416,7 +2438,7 @@ skip:
 	 * succeeds in getting console_sem (unless someone else takes it and
 	 * then he'll be responsible for printing).
          */
-	spin_unlock_irqrestore(&print_lock, flags);
+	spin_unlock_print_lock(flags);
 
 	/*
 	 * In case we cannot trylock the console_sem again, there's a new owner

@@ -2776,6 +2798,7 @@ int unregister_console(struct console *console)
 }
 EXPORT_SYMBOL(unregister_console);
 
+#ifdef CONFIG_PRINTK_OFFLOAD
 /* Kthread which takes over printing from a CPU which asks for help */
 static int printing_task(void *arg)
 {

@@ -2868,6 +2891,14 @@ static void printk_offload_init(void)
 	mutex_unlock(&printk_kthread_mutex);
 }
 
+#else	/* CONFIG_PRINTK_OFFLOAD */
+
+static void printk_offload_init(void)
+{
+}
+
+#endif	/* CONFIG_PRINTK_OFFLOAD */
+
 static int __init printk_late_init(void)
 {
 	struct console *con;

index 5153c6518b9d..72334ed42942 100644
@@ -101,8 +101,10 @@ static atomic_t printing_tasks_spinning = ATOMIC_INIT(0);
 #define PRINTING_TASKS 2
 /* Pointers to printing kthreads */
 static struct task_struct *printing_kthread[PRINTING_TASKS];
+/* Masks of cpus allowed for printing kthreads */
+static struct cpumask *printing_kthread_mask[PRINTING_TASKS];
 /* Serialization of changes to printk_offload_chars and kthread creation */
-static DEFINE_MUTEX(printk_kthread_mutex);
+static DEFINE_MUTEX(printing_kthread_mutex);
 
 /* Wait queue printing kthreads sleep on when idle */
 static DECLARE_WAIT_QUEUE_HEAD(print_queue);

@@ -2840,28 +2842,113 @@ static int printing_task(void *arg)
 	return 0;
 }
 
+/* Divide online cpus among printing kthreads */
+static void distribute_printing_kthreads(void)
+{
+	int i;
+	unsigned int cpus_per_thread;
+	unsigned int cpu, seen_cpu;
+
+	for (i = 0; i < PRINTING_TASKS; i++)
+		cpumask_clear(printing_kthread_mask[i]);
+
+	cpus_per_thread = DIV_ROUND_UP(num_online_cpus(), PRINTING_TASKS);
+	seen_cpu = 0;
+	for_each_online_cpu(cpu) {
+		cpumask_set_cpu(cpu,
+			printing_kthread_mask[seen_cpu / cpus_per_thread]);
+		seen_cpu++;
+	}
+
+	for (i = 0; i < PRINTING_TASKS; i++)
+		if (!cpumask_empty(printing_kthread_mask[i]))
+			set_cpus_allowed_ptr(printing_kthread[i],
+					     printing_kthread_mask[i]);
+}
+
+static int printing_kthread_cpu_notify(struct notifier_block *nfb,
+				       unsigned long action, void *hcpu)
+{
+	unsigned int cpu = (unsigned long)hcpu;
+	int i;
+
+	if (printk_offload_chars == 0)
+		goto out;
+
+	/* Get exclusion against turning of printk offload off... */
+	mutex_lock(&printing_kthread_mutex);
+	/* Now a reliable check if printk offload is enabled */
+	if (printk_offload_chars == 0) {
+		mutex_unlock(&printing_kthread_mutex);
+		goto out;
+	}
+
+	if (action == CPU_ONLINE) {
+		/*
+		 * Allow some task to use the CPU. We don't want to spend too
+		 * much time with fair distribution so just guess. We do a fair
+		 * redistribution if some task has no cpu to run on.
+		 */
+		i = cpu % PRINTING_TASKS;
+		cpumask_set_cpu(cpu, printing_kthread_mask[i]);
+		set_cpus_allowed_ptr(printing_kthread[i],
+				     printing_kthread_mask[i]);
+	}
+	if (action == CPU_DEAD) {
+
+		for (i = 0; i < PRINTING_TASKS; i++) {
+			if (cpumask_test_cpu(cpu, printing_kthread_mask[i])) {
+				cpumask_clear_cpu(cpu,
+						  printing_kthread_mask[i]);
+				if (cpumask_empty(printing_kthread_mask[i]))
+					distribute_printing_kthreads();
+				break;
+			}
+		}
+	}
+	mutex_unlock(&printing_kthread_mutex);
+out:
+	return NOTIFY_OK;
+}
+
 static int printk_start_offload_kthreads(void)
 {
 	int i;
 	struct task_struct *task;
+	int ret;
 
 	/* Does handover of printing make any sense? */
 	if (printk_offload_chars == 0 || num_possible_cpus() <= 1)
 		return 0;
+
 	for (i = 0; i < PRINTING_TASKS; i++) {
 		if (printing_kthread[i])
 			continue;
+		printing_kthread_mask[i] = kmalloc(cpumask_size(), GFP_KERNEL);
+		if (!printing_kthread_mask[i]) {
+			pr_err("printk: Cannot allocate cpumask for printing "
+			       "thread.\n");
+			ret = -ENOMEM;
+			goto out_err;
+		}
 		task = kthread_run(printing_task, NULL, "print/%d", i);
-		if (IS_ERR(task))
+		if (IS_ERR(task)) {
+			kfree(printing_kthread_mask[i]);
+			pr_err("printk: Cannot create printing thread: %ld\n",
+			       PTR_ERR(task));
+			ret = PTR_ERR(task);
 			goto out_err;
+		}
 		printing_kthread[i] = task;
 	}
+
+	hotcpu_notifier(printing_kthread_cpu_notify, 0);
+	distribute_printing_kthreads();
 	return 0;
 out_err:
-	pr_err("printk: Cannot create printing thread: %ld\n", PTR_ERR(task));
 	/* Disable offloading if creating kthreads failed */
 	printk_offload_chars = 0;
-	return PTR_ERR(task);
+	return ret;
 }
 
 static int offload_chars_set(const char *val, const struct kernel_param *kp)

@@ -2869,26 +2956,26 @@ static int offload_chars_set(const char *val, const struct kernel_param *kp)
 	int ret;
 
 	/* Protect against parallel change of printk_offload_chars */
-	mutex_lock(&printk_kthread_mutex);
+	mutex_lock(&printing_kthread_mutex);
 	ret = param_set_uint(val, kp);
 	if (ret) {
-		mutex_unlock(&printk_kthread_mutex);
+		mutex_unlock(&printing_kthread_mutex);
 		return ret;
 	}
 	ret = printk_start_offload_kthreads();
-	mutex_unlock(&printk_kthread_mutex);
+	mutex_unlock(&printing_kthread_mutex);
 	return ret;
 }
 
 static void printk_offload_init(void)
 {
-	mutex_lock(&printk_kthread_mutex);
+	mutex_lock(&printing_kthread_mutex);
 	if (num_possible_cpus() <= 1) {
 		/* Offloading doesn't make sense. Disable print offloading. */
 		printk_offload_chars = 0;
 	} else
 		printk_start_offload_kthreads();
-	mutex_unlock(&printk_kthread_mutex);
+	mutex_unlock(&printing_kthread_mutex);
 }
 
 #else	/* CONFIG_PRINTK_OFFLOAD */