[PATCH 2/7] printk: Start printing handover kthreads on demand

[PATCH 2/7] printk: Start printing handover kthreads on demand

[Jan Kara]

From: Jan Kara <jack@suse.cz>

Start kthreads for handing over printing only when printk.offload_chars
is set to value > 0 (i.e., when print offloading gets enabled).

Signed-off-by: Jan Kara <jack@suse.cz>
---
 kernel/printk/printk.c | 78 +++++++++++++++++++++++++++++++++++++++++---------
 1 file changed, 64 insertions(+), 14 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 1b26263edfa7..b9bb4a7a6dff 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -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;
 }
-- 
2.1.4

Re: [PATCH 2/7] printk: Start printing handover kthreads on demand

[Sergey Senozhatsky]

> +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);
> +}

A silly minor nitpick

+	} else {
		printk_start_offload_kthreads();
+	}

	-ss

Re: [PATCH 2/7] printk: Start printing handover kthreads on demand

[Sergey Senozhatsky]

On (12/10/15 23:56), Sergey Senozhatsky wrote:
>
> A silly minor nitpick
>

ah.. nope, I lied.

this part

>+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);
>+}

we can keep printk_offload_chars if we have created at least one thread,
in theory. if we are in heavy or nearly hevy (which is 'a process will spin in
unlock_console() with preemption_disabled for far too long') printk traffic case
(and that's what I want to fix from my side) then we have at least 1 process doing
printk->console_unlock() very often, so breaking that 'while (1)' console_unlock()
loop is a good thing here. which may be a corner case.


if we want to zero `printk_offload_chars' then how about bringing back Tejun Heo's
"printk: do cond_resched() between lines while outputting to consoles"?


Besides, we need this for !CONFIG_PRINTK_OFFLOAD kernel.

===8<====

if printk_start_offload_kthreads() has failed or if for some
other reason `printk_offload_chars' ended up to be 0, we still
need to try to break up long console_unlock() loops and try to
reschedule.

Signed-off-by: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
---
 kernel/printk/printk.c | 27 ++++++++++++++++++++++++++-
 1 file changed, 26 insertions(+), 1 deletion(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 21b0fb9..fc8c493 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2285,6 +2285,16 @@ static bool cpu_stop_printing(int printed_chars)
 	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;
+}
+
 /**
  * console_unlock - unlock the console system
  *
@@ -2309,7 +2319,7 @@ void console_unlock(void)
 	unsigned long flags;
 	bool wake_klogd = false;
 	bool retry;
-	bool hand_over = false;
+	bool hand_over = false, do_cond_resched;
 	int printed_chars = 0;
 
 	if (console_suspended) {
@@ -2317,6 +2327,15 @@ void console_unlock(void)
 		return;
 	}
 
+	/*
+	 * We may end up dumping a lot of lines, for example, if called
+	 * from console registration path, and should invoke cond_resched()
+	 * between lines if allowable.  Not doing so can cause a very long
+	 * scheduling stall on a slow console leading to RCU stall and
+	 * softlockup warnings which exacerbate the issue with more
+	 * messages practically incapacitating the system.
+	 */
+	do_cond_resched = console_may_schedule;
 	console_may_schedule = 0;
 
 	/* flush buffered message fragment immediately to console */
@@ -2397,6 +2416,12 @@ skip:
 		call_console_drivers(level, ext_text, ext_len, text, len);
 		start_critical_timings();
 		printed_chars += len;
+
+		if (unlikely(cpu_should_cond_resched(do_cond_resched))) {
+			raw_spin_unlock_irqrestore(&print_lock, flags);
+			cond_resched();
+			raw_spin_lock_irqsave(&print_lock, flags);
+		}
 	}
 
 	/* Release the exclusive_console once it is used */
-- 
2.6.3