[v5,2/4] printk/nmi: warn when some message has been lost in NMI context

Commit Message

Petr Mladek April 21, 2016, 11:48 a.m. UTC

We could not resize the temporary buffer in NMI context.  Let's warn if a
message is lost.

This is rather theoretical.  printk() should not be used in NMI.  The only
sensible use is when we want to print backtrace from all CPUs.  The
current buffer should be enough for this purpose.

[[e-mail]: whitespace fixlet]
Signed-off-by: Petr Mladek <[e-mail]>
Cc: Jan Kara <[e-mail]>
Cc: Peter Zijlstra <[e-mail]>
Cc: Steven Rostedt <[e-mail]>
Cc: Russell King <[e-mail]>
Cc: Daniel Thompson <[e-mail]>
Cc: Jiri Kosina <[e-mail]>
Cc: Ingo Molnar <[e-mail]>
Cc: Thomas Gleixner <[e-mail]>
Cc: Ralf Baechle <[e-mail]>
Cc: Benjamin Herrenschmidt <[e-mail]>
Cc: Martin Schwidefsky <[e-mail]>
Cc: David Miller <[e-mail]>
Cc: Daniel Thompson <[e-mail]>
Signed-off-by: Andrew Morton <[e-mail]>
---
 kernel/printk/internal.h | 11 +++++++++++
 kernel/printk/nmi.c      |  5 ++++-
 kernel/printk/printk.c   | 10 ++++++++++
 3 files changed, 25 insertions(+), 1 deletion(-)

Comments

Russell King - ARM Linux April 27, 2016, 9:34 a.m. UTC | #1

On Thu, Apr 21, 2016 at 01:48:43PM +0200, Petr Mladek wrote:
> @@ -64,8 +65,10 @@ static int vprintk_nmi(const char *fmt, va_list args)
>  again:
>  	len = atomic_read(&s->len);
>  
> -	if (len >= sizeof(s->buffer))
> +	if (len >= sizeof(s->buffer)) {
> +		atomic_inc(&nmi_message_lost);

This should be fine - I think its reasonable to expect that no one is
using a spinlock implementation for their atomic ops for this...

Patch

diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
index 2de99faedfc1..341bedccc065 100644
--- a/kernel/printk/internal.h
+++ b/kernel/printk/internal.h
@@ -34,6 +34,12 @@  static inline __printf(1, 0) int vprintk_func(const char *fmt, va_list args)
 	return this_cpu_read(printk_func)(fmt, args);
 }
 
+extern atomic_t nmi_message_lost;
+static inline int get_nmi_message_lost(void)
+{
+	return atomic_xchg(&nmi_message_lost, 0);
+}
+
 #else /* CONFIG_PRINTK_NMI */
 
 static inline __printf(1, 0) int vprintk_func(const char *fmt, va_list args)
@@ -41,4 +47,9 @@  static inline __printf(1, 0) int vprintk_func(const char *fmt, va_list args)
 	return vprintk_default(fmt, args);
 }
 
+static inline int get_nmi_message_lost(void)
+{
+	return 0;
+}
+
 #endif /* CONFIG_PRINTK_NMI */
diff --git a/kernel/printk/nmi.c b/kernel/printk/nmi.c
index 303cf0d15e57..572f94922230 100644
--- a/kernel/printk/nmi.c
+++ b/kernel/printk/nmi.c
@@ -39,6 +39,7 @@ 
  */
 DEFINE_PER_CPU(printk_func_t, printk_func) = vprintk_default;
 static int printk_nmi_irq_ready;
+atomic_t nmi_message_lost;
 
 #define NMI_LOG_BUF_LEN (4096 - sizeof(atomic_t) - sizeof(struct irq_work))
 
@@ -64,8 +65,10 @@  static int vprintk_nmi(const char *fmt, va_list args)
 again:
 	len = atomic_read(&s->len);
 
-	if (len >= sizeof(s->buffer))
+	if (len >= sizeof(s->buffer)) {
+		atomic_inc(&nmi_message_lost);
 		return 0;
+	}
 
 	/*
 	 * Make sure that all old data have been read before the buffer was
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 71eba0607034..e38579d730f4 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1617,6 +1617,7 @@  asmlinkage int vprintk_emit(int facility, int level,
 	unsigned long flags;
 	int this_cpu;
 	int printed_len = 0;
+	int nmi_message_lost;
 	bool in_sched = false;
 	/* cpu currently holding logbuf_lock in this function */
 	static unsigned int logbuf_cpu = UINT_MAX;
@@ -1667,6 +1668,15 @@  asmlinkage int vprintk_emit(int facility, int level,
 					 strlen(recursion_msg));
 	}
 
+	nmi_message_lost = get_nmi_message_lost();
+	if (unlikely(nmi_message_lost)) {
+		text_len = scnprintf(textbuf, sizeof(textbuf),
+				     "BAD LUCK: lost %d message(s) from NMI context!",
+				     nmi_message_lost);
+		printed_len += log_store(0, 2, LOG_PREFIX|LOG_NEWLINE, 0,
+					 NULL, 0, textbuf, text_len);
+	}
+
 	/*
 	 * The printf needs to come first; we need the syslog
 	 * prefix which might be passed-in as a parameter.