Subject: [withdrawn] printk-print-initial-logbuf-contents-before-re-enabling-interrupts.patch removed from -mm tree To: will.deacon@xxxxxxx,jack@xxxxxxx,kay@xxxxxxxx,peterz@xxxxxxxxxxxxx,mm-commits@xxxxxxxxxxxxxxx From: akpm@xxxxxxxxxxxxxxxxxxxx Date: Wed, 07 May 2014 11:58:04 -0700 The patch titled Subject: printk: print initial logbuf contents before re-enabling interrupts has been removed from the -mm tree. Its filename was printk-print-initial-logbuf-contents-before-re-enabling-interrupts.patch This patch was dropped because it was withdrawn ------------------------------------------------------ From: Will Deacon <will.deacon@xxxxxxx> Subject: printk: print initial logbuf contents before re-enabling interrupts When running on a hideously slow system (~10Mhz FPGA) with a bunch of debug printk invocations on the timer interrupt path, we end up filling the log buffer faster than we can drain it. The reason is that console_unlock (which is responsible for moving messages out of logbuf to hand over to the console driver) removes one message at a time, briefly re-enabling interrupts between each of them. If the interrupt path prints more than a single message, then we can easily generate more messages than we can print for a regular, recurring interrupt (e.g. a 1khz timer). This results in messages getting silently dropped, leading to counter-intuitive, incomplete printk traces on the console. Rather than run the console_unlock loop with interrupts disabled (which has obvious latency problems), this patch records the sequence number of the last message in the log buffer after taking the logbuf_lock. We can then print this fixed amount of work before re-enabling interrupts again, making sure we keep up with ourself. Other CPUs could still potentially flood the buffer, but there's little that we can do to protect against that. Signed-off-by: Will Deacon <will.deacon@xxxxxxx> Acked-by: Peter Zijlstra <peterz@xxxxxxxxxxxxx> Cc: Kay Sievers <kay@xxxxxxxx> Cc: Jan Kara <jack@xxxxxxx> Signed-off-by: Andrew Morton <akpm@xxxxxxxxxxxxxxxxxxxx> --- kernel/printk/printk.c | 9 +++++++++ 1 file changed, 9 insertions(+) diff -puN kernel/printk/printk.c~printk-print-initial-logbuf-contents-before-re-enabling-interrupts kernel/printk/printk.c --- a/kernel/printk/printk.c~printk-print-initial-logbuf-contents-before-re-enabling-interrupts +++ a/kernel/printk/printk.c @@ -2147,10 +2147,13 @@ void console_unlock(void) again: for (;;) { struct printk_log *msg; + u64 console_end_seq; size_t len; int level; raw_spin_lock_irqsave(&logbuf_lock, flags); + console_end_seq = log_next_seq; +again_noirq: if (seen_seq != log_next_seq) { wake_klogd = true; seen_seq = log_next_seq; @@ -2195,6 +2198,12 @@ skip: stop_critical_timings(); /* don't trace print latency */ call_console_drivers(level, text, len); start_critical_timings(); + + if (console_seq < console_end_seq) { + raw_spin_lock(&logbuf_lock); + goto again_noirq; + } + local_irq_restore(flags); } console_locked = 0; _ Patches currently in -mm which might be from will.deacon@xxxxxxx are printk-report-dropping-of-messages-from-logbuf.patch documentation-devicetree-bindings-add-documentation-for-the-apm-x-gene-soc-rtc-dts-binding.patch drivers-rtc-add-apm-x-gene-soc-rtc-driver.patch arm64-add-apm-x-gene-soc-rtc-dts-entry.patch linux-next.patch -- To unsubscribe from this list: send the line "unsubscribe mm-commits" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html