[PATCH] printk: Poke console and other loggers when cont buffer is flushed

From: Petr Mladek
Date: Tue Oct 25 2016 - 09:23:13 EST


The commit bfd8d3f23b51018388be041 ("printk: make reading the kernel
log flush pending lines") allows to add new message into the log
buffer without flushing it to the console and waking other loggers.

This patch adds wake_up_console() and calls it when the cont
buffer is flushed. The function name will make more sense once
we switch to the async printk.

Note that it is enough to poke console. The other loggers
are waken from console_unlock() when there is a new message.

The patch also renames PRINTK_PENDING flags and wake_up_klogd_work*
stuff to reduce confusion. First, there are more possible log
daemons, e.g. klogd, syslogd. Second, the word "console" is more
descriptive than "output".

This patch is based on top of the fix proposed at
https://lkml.kernel.org/r/CA+55aFwKYnrMJr_vSE+GfDGszeUGyd=CPUD15-zZ8yWQW61GBA@xxxxxxxxxxxxxx

Signed-off-by: Petr Mladek <pmladek@xxxxxxxx>
---
kernel/printk/printk.c | 60 ++++++++++++++++++++++++++++++++++----------------
1 file changed, 41 insertions(+), 19 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index e63aa679614e..f0e72de6ddbc 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -780,6 +780,7 @@ static ssize_t devkmsg_write(struct kiocb *iocb, struct iov_iter *from)
}

static void deferred_cont_flush(void);
+static void __wake_up_console(void);

static ssize_t devkmsg_read(struct file *file, char __user *buf,
size_t count, loff_t *ppos)
@@ -1620,13 +1621,11 @@ static bool cont_flush(void)
static void flush_timer(unsigned long data)
{
unsigned long flags;
- bool did_flush;

raw_spin_lock_irqsave(&logbuf_lock, flags);
- did_flush = cont_flush();
+ if (cont_flush())
+ __wake_up_console();
raw_spin_unlock_irqrestore(&logbuf_lock, flags);
- if (did_flush)
- wake_up_klogd();
}

static void deferred_cont_flush(void)
@@ -2730,40 +2729,57 @@ static int __init printk_late_init(void)

#if defined CONFIG_PRINTK
/*
- * Delayed printk version, for scheduler-internal messages:
+ * Handle console and wakeup loggers via IRQ work so that it can be done
+ * from any context.
*/
-#define PRINTK_PENDING_WAKEUP 0x01
-#define PRINTK_PENDING_OUTPUT 0x02
+#define PRINTK_PENDING_LOGGERS 0x01
+#define PRINTK_PENDING_CONSOLE 0x02

static DEFINE_PER_CPU(int, printk_pending);

-static void wake_up_klogd_work_func(struct irq_work *irq_work)
+static void printk_pending_func(struct irq_work *irq_work)
{
int pending = __this_cpu_xchg(printk_pending, 0);

- if (pending & PRINTK_PENDING_OUTPUT) {
+ if (pending & PRINTK_PENDING_CONSOLE) {
/* If trylock fails, someone else is doing the printing */
if (console_trylock())
console_unlock();
}

- if (pending & PRINTK_PENDING_WAKEUP)
+ if (pending & PRINTK_PENDING_LOGGERS)
wake_up_interruptible(&log_wait);
+
deferred_cont_flush();
}

-static DEFINE_PER_CPU(struct irq_work, wake_up_klogd_work) = {
- .func = wake_up_klogd_work_func,
+static DEFINE_PER_CPU(struct irq_work, printk_pending_work) = {
+ .func = printk_pending_func,
.flags = IRQ_WORK_LAZY,
};

void wake_up_klogd(void)
{
preempt_disable();
+
if (waitqueue_active(&log_wait)) {
- this_cpu_or(printk_pending, PRINTK_PENDING_WAKEUP);
- irq_work_queue(this_cpu_ptr(&wake_up_klogd_work));
+ this_cpu_or(printk_pending, PRINTK_PENDING_LOGGERS);
+ irq_work_queue(this_cpu_ptr(&printk_pending_work));
}
+
+ preempt_enable();
+}
+
+static void __wake_up_console(void)
+{
+ this_cpu_or(printk_pending, PRINTK_PENDING_CONSOLE);
+ irq_work_queue(this_cpu_ptr(&printk_pending_work));
+}
+
+static void wake_up_console(void)
+{
+ preempt_disable();
+ __wake_up_console();
preempt_enable();
}

@@ -2777,8 +2793,7 @@ 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));
+ __wake_up_console();
preempt_enable();

return r;
@@ -2893,6 +2908,7 @@ void kmsg_dump(enum kmsg_dump_reason reason)
{
struct kmsg_dumper *dumper;
unsigned long flags;
+ int did_flush = 0;

if ((reason > KMSG_DUMP_OOPS) && !always_kmsg_dump)
return;
@@ -2906,7 +2922,7 @@ void kmsg_dump(enum kmsg_dump_reason reason)
dumper->active = true;

raw_spin_lock_irqsave(&logbuf_lock, flags);
- cont_flush();
+ did_flush |= cont_flush();
dumper->cur_seq = clear_seq;
dumper->cur_idx = clear_idx;
dumper->next_seq = log_next_seq;
@@ -2920,6 +2936,9 @@ void kmsg_dump(enum kmsg_dump_reason reason)
dumper->active = false;
}
rcu_read_unlock();
+
+ if (did_flush)
+ wake_up_console();
}

/**
@@ -2997,7 +3016,8 @@ bool kmsg_dump_get_line(struct kmsg_dumper *dumper, bool syslog,
bool ret;

raw_spin_lock_irqsave(&logbuf_lock, flags);
- cont_flush();
+ if (cont_flush())
+ __wake_up_console();
ret = kmsg_dump_get_line_nolock(dumper, syslog, line, size, len);
raw_spin_unlock_irqrestore(&logbuf_lock, flags);

@@ -3039,7 +3059,9 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
goto out;

raw_spin_lock_irqsave(&logbuf_lock, flags);
- cont_flush();
+ if (cont_flush())
+ __wake_up_console();
+
if (dumper->cur_seq < log_first_seq) {
/* messages are gone, move to first available one */
dumper->cur_seq = log_first_seq;
--
1.8.5.6