Re: [RFC][PATCH 2/4] printk: offload printing from wake_up_klogd_work_func()

[Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com>]

Hello Petr,

On (03/17/17 13:19), Petr Mladek wrote:
[..]
> A solution might be to rename the variable to something like
> printk_pending_output, always set it in vprintk_emit() and
> clear it in console_unlock() when there are no pending messages.

believe it or not, I thought that I set printk_kthread_need_flush_console
to `true' unconditionally. probably I did so in one of the previous patch
set iterations. weird. I agree that doing this makes sense. thanks for
bringing this up.


....

I don't want that printk_kthread_need_flush_console to exist. instead,
I think, I want to move printk_pending out of per-cpu memory and use a
global printk_pending. set PRINTK_PENDING_OUTPUT bit to true in
vprintk_emit(), clear it in console_unlock(). and make both printk_kthread
scheduling condition and console_unlock() retry path depend on
`printk_pending == 0' being true.

something like below (the code is ugly and lacks a ton of barriers, etc.
etc.)


---

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 601a9ef6db89..a0b231f49052 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -439,8 +439,6 @@ static char *log_buf = __log_buf;
 static u32 log_buf_len = __LOG_BUF_LEN;
 
 static struct task_struct *printk_kthread __read_mostly;
-/* When `true' printing thread has messages to print. */
-static bool printk_kthread_need_flush_console;
 /*
  * We can't call into the scheduler (wake_up() printk kthread), for example,
  * during suspend/kexec. This temporarily switches printk to old behaviour.
@@ -451,6 +449,13 @@ static int printk_kthread_disable __read_mostly;
  * it doesn't go back to 0.
  */
 static bool printk_emergency __read_mostly;
+/*
+ * Delayed printk version, for scheduler-internal messages:
+ */
+#define PRINTK_PENDING_WAKEUP	0x01
+#define PRINTK_PENDING_OUTPUT	0x02
+
+static int printk_pending = 0;
 
 static inline bool printk_kthread_enabled(void)
 {
@@ -1806,6 +1811,7 @@ asmlinkage int vprintk_emit(int facility, int level,
 
 	printed_len += log_output(facility, level, lflags, dict, dictlen, text, text_len);
 
+	printk_pending |= PRINTK_PENDING_OUTPUT;
 	logbuf_unlock_irqrestore(flags);
 
 	/* If called from the scheduler, we can not call up(). */
@@ -1819,8 +1825,6 @@ asmlinkage int vprintk_emit(int facility, int level,
 		 * schedulable context.
 		 */
 		if (printk_kthread_enabled()) {
-			printk_kthread_need_flush_console = true;
-
 			printk_safe_enter_irqsave(flags);
 			wake_up_process(printk_kthread);
 			printk_safe_exit_irqrestore(flags);
@@ -2220,10 +2224,11 @@ void console_unlock(void)
 	static char text[LOG_LINE_MAX + PREFIX_MAX];
 	static u64 seen_seq;
 	unsigned long flags;
-	bool wake_klogd = false;
-	bool do_cond_resched, retry;
+	bool wake_klogd;
+	bool do_cond_resched, retry = false;
 
 	if (console_suspended) {
+		printk_pending &= ~PRINTK_PENDING_OUTPUT;
 		up_console_sem();
 		return;
 	}
@@ -2242,6 +2247,8 @@ void console_unlock(void)
 	console_may_schedule = 0;
 
 again:
+	wake_klogd = printk_pending & PRINTK_PENDING_WAKEUP;
+	printk_pending = 0;
 	/*
 	 * We released the console_sem lock, so we need to recheck if
 	 * cpu is online and (if not) is there at least one CON_ANYTIME
@@ -2330,15 +2337,16 @@ void console_unlock(void)
 	 * flush, no worries.
 	 */
 	raw_spin_lock(&logbuf_lock);
-	retry = console_seq != log_next_seq;
+	if (printk_pending != 0 || console_seq != log_next_seq)
+		retry = true;
 	raw_spin_unlock(&logbuf_lock);
 	printk_safe_exit_irqrestore(flags);
 
-	if (retry && console_trylock())
-		goto again;
-
 	if (wake_klogd)
 		wake_up_klogd();
+
+	if (retry && console_trylock())
+		goto again;
 }
 EXPORT_SYMBOL(console_unlock);
 
@@ -2722,19 +2730,9 @@ static int __init printk_late_init(void)
 late_initcall(printk_late_init);
 
 #if defined CONFIG_PRINTK
-/*
- * Delayed printk version, for scheduler-internal messages:
- */
-#define PRINTK_PENDING_WAKEUP	0x01
-#define PRINTK_PENDING_OUTPUT	0x02
-
-static DEFINE_PER_CPU(int, printk_pending);
-
 static void wake_up_klogd_work_func(struct irq_work *irq_work)
 {
-	int pending = __this_cpu_xchg(printk_pending, 0);
-
-	if (pending & PRINTK_PENDING_OUTPUT) {
+	if (printk_pending & PRINTK_PENDING_OUTPUT) {
 		if (printk_kthread_enabled()) {
 			wake_up_process(printk_kthread);
 		} else {
@@ -2747,8 +2745,10 @@ static void wake_up_klogd_work_func(struct irq_work *irq_work)
 		}
 	}
 
-	if (pending & PRINTK_PENDING_WAKEUP)
+	if (printk_pending & PRINTK_PENDING_WAKEUP) {
+		printk_pending &= ~PRINTK_PENDING_WAKEUP;
 		wake_up_interruptible(&log_wait);
+	}
 }
 
 static DEFINE_PER_CPU(struct irq_work, wake_up_klogd_work) = {
@@ -2760,18 +2760,10 @@ static int printk_kthread_func(void *data)
 {
 	while (1) {
 		set_current_state(TASK_INTERRUPTIBLE);
-		if (!printk_kthread_need_flush_console)
+		if (!(printk_pending & PRINTK_PENDING_OUTPUT))
 			schedule();
 
 		__set_current_state(TASK_RUNNING);
-		/*
-		 * Avoid an infinite loop when console_unlock() cannot
-		 * access consoles, e.g. because console_suspended is
-		 * true. schedule(), someone else will print the messages
-		 * from resume_console().
-		 */
-		printk_kthread_need_flush_console = false;
-
 		console_lock();
 		console_unlock();
 	}
@@ -2802,7 +2794,7 @@ void wake_up_klogd(void)
 {
 	preempt_disable();
 	if (waitqueue_active(&log_wait)) {
-		this_cpu_or(printk_pending, PRINTK_PENDING_WAKEUP);
+		printk_pending |= PRINTK_PENDING_WAKEUP;
 		irq_work_queue(this_cpu_ptr(&wake_up_klogd_work));
 	}
 	preempt_enable();
@@ -2818,7 +2810,6 @@ int printk_deferred(const char *fmt, ...)
 	r = vprintk_emit(0, LOGLEVEL_SCHED, NULL, 0, fmt, args);
 	va_end(args);
 
-	__this_cpu_or(printk_pending, PRINTK_PENDING_OUTPUT);
 	irq_work_queue(this_cpu_ptr(&wake_up_klogd_work));
 	preempt_enable();
 

---


[..]
> If I remember correctly, you were not much happy with this
> solution because it did spread the logic. I think that you did not
> believe that it was worth fixing the second problem.

hm, I think Jan Kara was the first one who said that we
are overcomplicating the whole thing... or may be it was me.
don't deny it either.

	-ss