Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.kernel > #1534109 > unrolled thread

[RFC][PATCHv5 3/7] printk: introduce per-cpu safe_print seq buffer

Back to article view | Back to linux.kernel

This discussion starts older than the indexed window; earlier articles aren't shown. The article labeled Started by below is the oldest one visible, not the original post.

Contents

  [RFC][PATCHv5 3/7] printk: introduce per-cpu safe_print seq buffer Sergey Senozhatsky <sergey.senozhatsky@gmail.com> - 2016-12-01 15:00 +0100
    Re: [RFC][PATCHv5 3/7] printk: introduce per-cpu safe_print seq  buffer Petr Mladek <pmladek@suse.com> - 2016-12-09 17:50 +0100
      Re: [RFC][PATCHv5 3/7] printk: introduce per-cpu safe_print seq  buffer Sergey Senozhatsky <sergey.senozhatsky@gmail.com> - 2016-12-10 04:20 +0100
        Re: [RFC][PATCHv5 3/7] printk: introduce per-cpu safe_print seq  buffer Petr Mladek <pmladek@suse.com> - 2016-12-12 15:00 +0100
          Re: [RFC][PATCHv5 3/7] printk: introduce per-cpu safe_print seq  buffer Sergey Senozhatsky <sergey.senozhatsky@gmail.com> - 2016-12-12 15:20 +0100
            Re: [RFC][PATCHv5 3/7] printk: introduce per-cpu safe_print seq  buffer Petr Mladek <pmladek@suse.com> - 2016-12-12 16:20 +0100
          Re: [RFC][PATCHv5 3/7] printk: introduce per-cpu safe_print seq  buffer Sergey Senozhatsky <sergey.senozhatsky@gmail.com> - 2016-12-12 16:30 +0100

#1534109 — [RFC][PATCHv5 3/7] printk: introduce per-cpu safe_print seq buffer

This patch extends the idea of NMI per-cpu buffers to regions
that may cause recursive printk() calls and possible deadlocks.
Namely, printk() can't handle printk calls from schedule code
or printk() calls from lock debugging code (spin_dump() for instance);
because those may be called with `sem->lock' already taken or any
other `critical' locks (p->pi_lock, etc.). An example of deadlock
can be

 vprintk_emit()
  console_unlock()
   up()                        << raw_spin_lock_irqsave(&sem->lock, flags);
    wake_up_process()
     try_to_wake_up()
      ttwu_queue()
       ttwu_activate()
        activate_task()
         enqueue_task()
          enqueue_task_fair()
           cfs_rq_of()
            task_of()
             WARN_ON_ONCE(!entity_is_task(se))
              vprintk_emit()
               console_trylock()
                down_trylock()
                 raw_spin_lock_irqsave(&sem->lock, flags)
                 ^^^^ deadlock

and some other cases.

Just like in NMI implementation, the solution uses a per-cpu
`printk_func' pointer to 'redirect' printk() calls to a 'safe'
callback, that store messages in a per-cpu buffer and flushes
them back to logbuf buffer later.

Usage example:

 printk()
  printk_safe_enter(flags)
  //
  //  any printk() call from here will endup in vprintk_safe(),
  //  that stores messages in a special per-CPU buffer.
  //
  printk_safe_exit(flags)

The 'redirection' mechanism, though, has been reworked, as suggested
by Petr Mladek. Instead of using a per-cpu @print_func callback we now
keep a per-cpu printk-context variable and call either default or nmi
vprintk function depending on its value. printk_nmi_entrer/exit and
printk_safe_enter/exit, thus, just set/celar corresponding bits in
printk-context functions.

The patch only adds printk_safe support, we don't use it yet.

Signed-off-by: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
---
 include/linux/printk.h      |  21 +++++--
 kernel/printk/Makefile      |   2 +-
 kernel/printk/internal.h    |  56 +++++++++++--------
 kernel/printk/printk.c      |   3 -
 kernel/printk/printk_safe.c | 133 ++++++++++++++++++++++++++++++++++----------
 5 files changed, 152 insertions(+), 63 deletions(-)

diff --git a/include/linux/printk.h b/include/linux/printk.h
index 67df41e..f7d291c 100644
--- a/include/linux/printk.h
+++ b/include/linux/printk.h
@@ -147,17 +147,11 @@ void early_printk(const char *s, ...) { }
 #endif
 
 #ifdef CONFIG_PRINTK_NMI
-extern void printk_safe_init(void);
 extern void printk_safe_nmi_enter(void);
 extern void printk_safe_nmi_exit(void);
-extern void printk_safe_flush(void);
-extern void printk_safe_flush_on_panic(void);
 #else
-static inline void printk_safe_init(void) { }
 static inline void printk_safe_nmi_enter(void) { }
 static inline void printk_safe_nmi_exit(void) { }
-static inline void printk_safe_flush(void) { }
-static inline void printk_safe_flush_on_panic(void) { }
 #endif /* PRINTK_NMI */
 
 #ifdef CONFIG_PRINTK
@@ -209,6 +203,9 @@ void __init setup_log_buf(int early);
 __printf(1, 2) void dump_stack_set_arch_desc(const char *fmt, ...);
 void dump_stack_print_info(const char *log_lvl);
 void show_regs_print_info(const char *log_lvl);
+extern void printk_safe_init(void);
+extern void printk_safe_flush(void);
+extern void printk_safe_flush_on_panic(void);
 #else
 static inline __printf(1, 0)
 int vprintk(const char *s, va_list args)
@@ -268,6 +265,18 @@ static inline void dump_stack_print_info(const char *log_lvl)
 static inline void show_regs_print_info(const char *log_lvl)
 {
 }
+
+static inline void printk_safe_init(void)
+{
+}
+
+static inline void printk_safe_flush(void)
+{
+}
+
+static inline void printk_safe_flush_on_panic(void)
+{
+}
 #endif
 
 extern asmlinkage void dump_stack(void) __cold;
diff --git a/kernel/printk/Makefile b/kernel/printk/Makefile
index 6079281..4a2ffc3 100644
--- a/kernel/printk/Makefile
+++ b/kernel/printk/Makefile
@@ -1,3 +1,3 @@
 obj-y	= printk.o
-obj-$(CONFIG_PRINTK_NMI)		+= printk_safe.o
+obj-$(CONFIG_PRINTK)	+= printk_safe.o
 obj-$(CONFIG_A11Y_BRAILLE_CONSOLE)	+= braille.o
diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
index 7fd2838..97cee4f 100644
--- a/kernel/printk/internal.h
+++ b/kernel/printk/internal.h
@@ -16,26 +16,8 @@
  */
 #include <linux/percpu.h>
 
-typedef __printf(1, 0) int (*printk_func_t)(const char *fmt, va_list args);
-
-int __printf(1, 0) vprintk_default(const char *fmt, va_list args);
-
 #ifdef CONFIG_PRINTK_NMI
 
-extern raw_spinlock_t logbuf_lock;
-
-/*
- * printk() could not take logbuf_lock in NMI context. Instead,
- * it temporary stores the strings into a per-CPU buffer.
- * The alternative implementation is chosen transparently
- * via per-CPU variable.
- */
-DECLARE_PER_CPU(printk_func_t, printk_func);
-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)
 {
@@ -44,14 +26,42 @@ static inline int get_nmi_message_lost(void)
 
 #else /* CONFIG_PRINTK_NMI */
 
-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 */
+
+#ifdef CONFIG_PRINTK
+
+#define PRINTK_SAFE_CONTEXT_MASK	0x7fffffff
+#define PRINTK_NMI_CONTEXT_MASK	0x80000000
+
+extern raw_spinlock_t logbuf_lock;
+
+__printf(1, 0) int vprintk_default(const char *fmt, va_list args);
+__printf(1, 0) int vprintk_func(const char *fmt, va_list args);
+void __printk_safe_enter(void);
+void __printk_safe_exit(void);
+
+#define printk_safe_enter(flags)		\
+	do {					\
+		local_irq_save(flags);		\
+		__printk_safe_enter();		\
+	} while (0)
+
+#define printk_safe_exit(flags)		\
+	do {					\
+		__printk_safe_exit();		\
+		local_irq_restore(flags);	\
+	} while (0)
+
+#else
+
+__printf(1, 0) int vprintk_func(const char *fmt, va_list args) { return 0; }
+
+#define printk_safe_enter(f)	((void)(f))
+#define printk_safe_exit(f)	((void)(f))
+
+#endif /* CONFIG_PRINTK */
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 9f2f44a..77446ba 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2010,9 +2010,6 @@ static size_t msg_print_text(const struct printk_log *msg, enum log_flags prev,
 static size_t cont_print_text(char *text, size_t size) { return 0; }
 static bool suppress_message_printing(int level) { return false; }
 
-/* Still needs to be defined for users */
-DEFINE_PER_CPU(printk_func_t, printk_func);
-
 #endif /* CONFIG_PRINTK */
 
 #ifdef CONFIG_EARLY_PRINTK
diff --git a/kernel/printk/printk_safe.c b/kernel/printk/printk_safe.c
index d5a4b6f..c22e286 100644
--- a/kernel/printk/printk_safe.c
+++ b/kernel/printk/printk_safe.c
@@ -1,5 +1,5 @@
 /*
- * printk_safe.c - Safe printk in NMI context
+ * printk_safe.c - Safe printk for printk-deadlock-prone contexts
  *
  * This program is free software; you can redistribute it and/or
  * modify it under the terms of the GNU General Public License
@@ -32,15 +32,14 @@
  * is later flushed into the main ring buffer via IRQ work.
  *
  * The alternative implementation is chosen transparently
- * via @printk_func per-CPU variable.
+ * by examinig current printk() context mask stored in @printk_context
+ * per-CPU variable.
  *
  * The implementation allows to flush the strings also from another CPU.
  * There are situations when we want to make sure that all buffers
  * were handled or when IRQs are blocked.
  */
-DEFINE_PER_CPU(printk_func_t, printk_func) = vprintk_default;
 static int printk_safe_irq_ready;
-atomic_t nmi_message_lost;
 
 #define SAFE_LOG_BUF_LEN ((1 << CONFIG_PRINTK_SAFE_LOG_BUF_SHIFT) -	\
 			 sizeof(atomic_t) - sizeof(struct irq_work))
@@ -50,27 +49,26 @@ struct printk_safe_seq_buf {
 	struct irq_work		work;	/* IRQ work that flushes the buffer */
 	unsigned char		buffer[SAFE_LOG_BUF_LEN];
 };
+
+static DEFINE_PER_CPU(struct printk_safe_seq_buf, safe_print_seq);
+static DEFINE_PER_CPU(int, printk_context);
+
+#ifdef CONFIG_PRINTK_NMI
 static DEFINE_PER_CPU(struct printk_safe_seq_buf, nmi_print_seq);
+atomic_t nmi_message_lost;
+#endif
 
-/*
- * Safe printk() for NMI context. It uses a per-CPU buffer to
- * store the message. NMIs are not nested, so there is always only
- * one writer running. But the buffer might get flushed from another
- * CPU, so we need to be careful.
- */
-static int vprintk_safe_nmi(const char *fmt, va_list args)
+static int printk_safe_log_store(struct printk_safe_seq_buf *s,
+		const char *fmt, va_list args)
 {
-	struct printk_safe_seq_buf *s = this_cpu_ptr(&nmi_print_seq);
-	int add = 0;
+	int add;
 	size_t len;
 
 again:
 	len = atomic_read(&s->len);
 
-	if (len >= sizeof(s->buffer)) {
-		atomic_inc(&nmi_message_lost);
-		return 0;
-	}
+	if (len >= sizeof(s->buffer))
+		return -ENOSPC;
 
 	/*
 	 * Make sure that all old data have been read before the buffer was
@@ -160,7 +158,7 @@ static int printk_safe_flush_buffer(const char *start, size_t len)
 }
 
 /*
- * Flush data from the associated per_CPU buffer. The function
+ * Flush data from the associated per-CPU buffer. The function
  * can be called either via IRQ work or independently.
  */
 static void __printk_safe_flush(struct irq_work *work)
@@ -230,8 +228,12 @@ void printk_safe_flush(void)
 {
 	int cpu;
 
-	for_each_possible_cpu(cpu)
+	for_each_possible_cpu(cpu) {
+#ifdef CONFIG_PRINTK_NMI
 		__printk_safe_flush(&per_cpu(nmi_print_seq, cpu).work);
+#endif
+		__printk_safe_flush(&per_cpu(safe_print_seq, cpu).work);
+	}
 }
 
 /**
@@ -261,14 +263,95 @@ void printk_safe_flush_on_panic(void)
 	printk_safe_flush();
 }
 
+#ifdef CONFIG_PRINTK_NMI
+/*
+ * Safe printk() for NMI context. It uses a per-CPU buffer to
+ * store the message. NMIs are not nested, so there is always only
+ * one writer running. But the buffer might get flushed from another
+ * CPU, so we need to be careful.
+ */
+static int vprintk_safe_nmi(const char *fmt, va_list args)
+{
+	struct printk_safe_seq_buf *s = this_cpu_ptr(&nmi_print_seq);
+	int add;
+
+	add = printk_safe_log_store(s, fmt, args);
+	if (add == -ENOSPC) {
+		atomic_inc(&nmi_message_lost);
+		add = 0;
+	}
+
+	return add;
+}
+
+void printk_safe_nmi_enter(void)
+{
+	this_cpu_or(printk_context, PRINTK_NMI_CONTEXT_MASK);
+}
+
+void printk_safe_nmi_exit(void)
+{
+	this_cpu_and(printk_context, ~PRINTK_NMI_CONTEXT_MASK);
+}
+
+#else
+
+static int vprintk_safe_nmi(const char *fmt, va_list args)
+{
+	return 0;
+}
+
+#endif /* CONFIG_PRINTK_NMI */
+
+/*
+ * Lockless printk(), to avoid deadlocks should the printk() recurse
+ * into itself. It uses a per-CPU buffer to store the message, just like
+ * NMI.
+ */
+static int vprintk_safe(const char *fmt, va_list args)
+{
+	struct printk_safe_seq_buf *s = this_cpu_ptr(&safe_print_seq);
+
+	return printk_safe_log_store(s, fmt, args);
+}
+
+/* Can be preempted by NMI. */
+void __printk_safe_enter(void)
+{
+	this_cpu_inc(printk_context);
+}
+
+/* Can be preempted by NMI. */
+void __printk_safe_exit(void)
+{
+	this_cpu_dec(printk_context);
+}
+
+__printf(1, 0) int vprintk_func(const char *fmt, va_list args)
+{
+	if (this_cpu_read(printk_context) & PRINTK_NMI_CONTEXT_MASK)
+		return vprintk_safe_nmi(fmt, args);
+
+	if (this_cpu_read(printk_context) & PRINTK_SAFE_CONTEXT_MASK)
+		return vprintk_safe(fmt, args);
+
+	return vprintk_default(fmt, args);
+}
+
 void __init printk_safe_init(void)
 {
 	int cpu;
 
 	for_each_possible_cpu(cpu) {
-		struct printk_safe_seq_buf *s = &per_cpu(nmi_print_seq, cpu);
+		struct printk_safe_seq_buf *s;
+
+		s = &per_cpu(safe_print_seq, cpu);
+		init_irq_work(&s->work, __printk_safe_flush);
 
+#ifdef CONFIG_PRINTK_NMI
+		s = &per_cpu(nmi_print_seq, cpu);
 		init_irq_work(&s->work, __printk_safe_flush);
+#endif
 	}
 
 	/* Make sure that IRQ works are initialized before enabling. */
@@ -278,13 +361,3 @@ void __init printk_safe_init(void)
 	/* Flush pending messages that did not have scheduled IRQ works. */
 	printk_safe_flush();
 }
-
-void printk_safe_nmi_enter(void)
-{
-	this_cpu_write(printk_func, vprintk_safe_nmi);
-}
-
-void printk_safe_nmi_exit(void)
-{
-	this_cpu_write(printk_func, vprintk_default);
-}
-- 
2.10.2

[toc] | [next] | [standalone]

#1539551 — Re: [RFC][PATCHv5 3/7] printk: introduce per-cpu safe_print seq buffer

On Thu 2016-12-01 22:55:42, Sergey Senozhatsky wrote:
> This patch extends the idea of NMI per-cpu buffers to regions
> that may cause recursive printk() calls and possible deadlocks.
> Namely, printk() can't handle printk calls from schedule code
> or printk() calls from lock debugging code (spin_dump() for instance);
> because those may be called with `sem->lock' already taken or any
> other `critical' locks (p->pi_lock, etc.). An example of deadlock
> can be
> 
>  vprintk_emit()
>   console_unlock()
>    up()                        << raw_spin_lock_irqsave(&sem->lock, flags);
>     wake_up_process()
>      try_to_wake_up()
>       ttwu_queue()
>        ttwu_activate()
>         activate_task()
>          enqueue_task()
>           enqueue_task_fair()
>            cfs_rq_of()
>             task_of()
>              WARN_ON_ONCE(!entity_is_task(se))
>               vprintk_emit()
>                console_trylock()
>                 down_trylock()
>                  raw_spin_lock_irqsave(&sem->lock, flags)
>                  ^^^^ deadlock
> 
> and some other cases.
> 
> Just like in NMI implementation, the solution uses a per-cpu
> `printk_func' pointer to 'redirect' printk() calls to a 'safe'
> callback, that store messages in a per-cpu buffer and flushes
> them back to logbuf buffer later.
> 
> Usage example:
> 
>  printk()
>   printk_safe_enter(flags)
>   //
>   //  any printk() call from here will endup in vprintk_safe(),
>   //  that stores messages in a special per-CPU buffer.
>   //
>   printk_safe_exit(flags)
> 
> The 'redirection' mechanism, though, has been reworked, as suggested
> by Petr Mladek. Instead of using a per-cpu @print_func callback we now
> keep a per-cpu printk-context variable and call either default or nmi
> vprintk function depending on its value. printk_nmi_entrer/exit and
> printk_safe_enter/exit, thus, just set/celar corresponding bits in
> printk-context functions.
> 
> The patch only adds printk_safe support, we don't use it yet.
> 
> diff --git a/kernel/printk/printk_safe.c b/kernel/printk/printk_safe.c
> index d5a4b6f..c22e286 100644
> --- a/kernel/printk/printk_safe.c
> +++ b/kernel/printk/printk_safe.c
> @@ -50,27 +49,26 @@ struct printk_safe_seq_buf {
>  	struct irq_work		work;	/* IRQ work that flushes the buffer */
>  	unsigned char		buffer[SAFE_LOG_BUF_LEN];
>  };
> +
> +static DEFINE_PER_CPU(struct printk_safe_seq_buf, safe_print_seq);
> +static DEFINE_PER_CPU(int, printk_context);
> +
> +#ifdef CONFIG_PRINTK_NMI
>  static DEFINE_PER_CPU(struct printk_safe_seq_buf, nmi_print_seq);
> +atomic_t nmi_message_lost;
> +#endif
>  
> -/*
> - * Safe printk() for NMI context. It uses a per-CPU buffer to
> - * store the message. NMIs are not nested, so there is always only
> - * one writer running. But the buffer might get flushed from another
> - * CPU, so we need to be careful.
> - */

We should keep/create a good description here because the function
has a non-trivial code. What about something like?

/*
 * Print a message into the given per-CPU buffer a safe way.
 * We need to be very careful here.
 *
 * First, the buffer might be flushed from another CPU at the same
 * time. This is solved by repeated write if the buffer length
 * is changed in the meantime.
 *
 * Second, the function might be called recursively if there
 * is an error message printed from this code. The recursion
 * will stop once the buffer is full. It is not ideal but it
 * should be enough to debug.
 */
> -static int vprintk_safe_nmi(const char *fmt, va_list args)
> +static int printk_safe_log_store(struct printk_safe_seq_buf *s,
> +		const char *fmt, va_list args)
>  {
> -	struct printk_safe_seq_buf *s = this_cpu_ptr(&nmi_print_seq);
> -	int add = 0;
> +	int add;
>  	size_t len;
>  
>  again:
>  	len = atomic_read(&s->len);
>  
> -	if (len >= sizeof(s->buffer)) {
> -		atomic_inc(&nmi_message_lost);
> -		return 0;
> -	}
> +	if (len >= sizeof(s->buffer))
> +		return -ENOSPC;

I was curious if we would really leave the cycle if the buffer
is full. And the check has to be

	if (len >= sizeof(s->buffer) - 1)

but it is handled in separate patch that I have already sent.

>  	/*
>  	 * Make sure that all old data have been read before the buffer was
> @@ -261,14 +263,95 @@ void printk_safe_flush_on_panic(void)
>  	printk_safe_flush();
>  }
>  
> +#ifdef CONFIG_PRINTK_NMI
> +/*
> + * Safe printk() for NMI context. It uses a per-CPU buffer to
> + * store the message. NMIs are not nested, so there is always only
> + * one writer running. But the buffer might get flushed from another
> + * CPU, so we need to be careful.
> + */

Hmm, I wanted to describe why we need another per-CPU buffer in NMI
and I am not sure that we really need it.

vprintk_safe_nmi() and vprintk_safe() will never run in parallel.
vprintk_safe_nmi() might be nested into vprintk_safe() but
printk_safe_log_store() is able to handle the nesting.

It is Friday evening, so I am not 100% sure. But if this is true,
we might simplify everything even more. Single per-cpu buffer and
single per-CPU nesting counter might be enough. I have to think
about it.

Best Regards,
Petr

PS: Heh, I was sad that all my comments looked like nitpicking.
But I was not able to help myself. And it seems that a good function
description might actually help to get a better code ;-)

[toc] | [prev] | [next] | [standalone]

#1539762 — Re: [RFC][PATCHv5 3/7] printk: introduce per-cpu safe_print seq buffer

On (12/09/16 17:46), Petr Mladek wrote:
> > -/*
> > - * Safe printk() for NMI context. It uses a per-CPU buffer to
> > - * store the message. NMIs are not nested, so there is always only
> > - * one writer running. But the buffer might get flushed from another
> > - * CPU, so we need to be careful.
> > - */
> 
> We should keep/create a good description here because the function
> has a non-trivial code. What about something like?
> 

which is really not related to this patch set.


> >  	 * Make sure that all old data have been read before the buffer was
> > @@ -261,14 +263,95 @@ void printk_safe_flush_on_panic(void)
> >  	printk_safe_flush();
> >  }
> >  
> > +#ifdef CONFIG_PRINTK_NMI
> > +/*
> > + * Safe printk() for NMI context. It uses a per-CPU buffer to
> > + * store the message. NMIs are not nested, so there is always only
> > + * one writer running. But the buffer might get flushed from another
> > + * CPU, so we need to be careful.
> > + */
> 
> Hmm, I wanted to describe why we need another per-CPU buffer in NMI
> and I am not sure that we really need it.

NMI-printk can interrupt safe-printk's vsnprintf() in the middle of
the "while (*fmt)" loop: safe-priNMI-PRINTK


	-ss

[toc] | [prev] | [next] | [standalone]

#1540339 — Re: [RFC][PATCHv5 3/7] printk: introduce per-cpu safe_print seq buffer

On Sat 2016-12-10 12:10:22, Sergey Senozhatsky wrote:
> On (12/09/16 17:46), Petr Mladek wrote:
> > > -/*
> > > - * Safe printk() for NMI context. It uses a per-CPU buffer to
> > > - * store the message. NMIs are not nested, so there is always only
> > > - * one writer running. But the buffer might get flushed from another
> > > - * CPU, so we need to be careful.
> > > - */
> > 
> > We should keep/create a good description here because the function
> > has a non-trivial code. What about something like?
> > 
> 
> which is really not related to this patch set.

I am sorry but I do not understand. This patch removes description
that explained constrains of a rather complex code. In fact, the
constrains has changed because we started using the function also
in other context. When will be the right time/patchset to explain
it?

> 
> > >  	 * Make sure that all old data have been read before the buffer was
> > > @@ -261,14 +263,95 @@ void printk_safe_flush_on_panic(void)
> > >  	printk_safe_flush();
> > >  }
> > >  
> > > +#ifdef CONFIG_PRINTK_NMI
> > > +/*
> > > + * Safe printk() for NMI context. It uses a per-CPU buffer to
> > > + * store the message. NMIs are not nested, so there is always only
> > > + * one writer running. But the buffer might get flushed from another
> > > + * CPU, so we need to be careful.
> > > + */
> > 
> > Hmm, I wanted to describe why we need another per-CPU buffer in NMI
> > and I am not sure that we really need it.
> 
> NMI-printk can interrupt safe-printk's vsnprintf() in the middle of
> the "while (*fmt)" loop: safe-priNMI-PRINTK

But this already happens when any of the WARNs is triggered
inside vsnprintf(). Either this is safe or we are in
trouble.

Well, there is a difference. NMI can come at anytime and vsnprintf()
continues printing the original string once we are back from NMI.
But if we hit WARN() inside vsnprintf(), it usually means an error,
vsnprintf() stops printing into the given buffer and returns. It
means that it does not overwrite the message printed by the nested
printks.

The only exceptions are WARN_ONCE() calls in set_field_width()
and set_precision(). They are self-repairing, vsnprintf()
continues printing and will overwrite the nested warnings.
Well, I am not sure if we should bother.

By other words, we really need separate per-CPU buffer for NMI
and the generic printk_safe. I am sorry for the noise.

Well, is it that bad to ask for better comments? You see that
I ended in quite some doubts, even found problems, when I tried
to review the code carefully. Or am I dumb and it was all obvious?

Best Regards,
Petr

PS: I know that I am sometimes in too nitpicking mode and it
might be annoying and discouraging. I have to find the right
boundaries.

[toc] | [prev] | [next] | [standalone]

#1540346 — Re: [RFC][PATCHv5 3/7] printk: introduce per-cpu safe_print seq buffer

On (12/12/16 14:54), Petr Mladek wrote:
> On Sat 2016-12-10 12:10:22, Sergey Senozhatsky wrote:
> > On (12/09/16 17:46), Petr Mladek wrote:
> > > > -/*
> > > > - * Safe printk() for NMI context. It uses a per-CPU buffer to
> > > > - * store the message. NMIs are not nested, so there is always only
> > > > - * one writer running. But the buffer might get flushed from another
> > > > - * CPU, so we need to be careful.
> > > > - */
> > > 
> > > We should keep/create a good description here because the function
> > > has a non-trivial code. What about something like?
> > > 
> > 
> > which is really not related to this patch set.
> 
> I am sorry but I do not understand. This patch removes description
> that explained constrains of a rather complex code. In fact, the
> constrains has changed because we started using the function also
> in other context. When will be the right time/patchset to explain
> it?

but I didn't remove it.

$ grep -A3 -B3 'But the buffer might get flushed from another' kernel/printk/printk_safe.c

/*
 * Safe printk() for NMI context. It uses a per-CPU buffer to
 * store the message. NMIs are not nested, so there is always only
 * one writer running. But the buffer might get flushed from another
 * CPU, so we need to be careful.
 */
static int vprintk_safe_nmi(const char *fmt, va_list args)


> > > > +#ifdef CONFIG_PRINTK_NMI
> > > > +/*
> > > > + * Safe printk() for NMI context. It uses a per-CPU buffer to
> > > > + * store the message. NMIs are not nested, so there is always only
> > > > + * one writer running. But the buffer might get flushed from another
> > > > + * CPU, so we need to be careful.
> > > > + */
> > > 
> > > Hmm, I wanted to describe why we need another per-CPU buffer in NMI
> > > and I am not sure that we really need it.
> > 
> > NMI-printk can interrupt safe-printk's vsnprintf() in the middle of
> > the "while (*fmt)" loop: safe-priNMI-PRINTK
> 
> But this already happens when any of the WARNs is triggered
> inside vsnprintf(). Either this is safe or we are in
> trouble.

the point was that when printk-safe resumes after being interrupted
by NMI-printk it continues printing from the offset at which it has
been interrupted, writing over the lines that were sprintf-d by NMI
printk; because NMI-printk used the same buffer offset `s->len'. so
at least part of NMI-printk message will be lost.

	-ss

[toc] | [prev] | [next] | [standalone]

#1540376 — Re: [RFC][PATCHv5 3/7] printk: introduce per-cpu safe_print seq buffer

On Mon 2016-12-12 23:12:30, Sergey Senozhatsky wrote:
> On (12/12/16 14:54), Petr Mladek wrote:
> > On Sat 2016-12-10 12:10:22, Sergey Senozhatsky wrote:
> > > On (12/09/16 17:46), Petr Mladek wrote:
> > > > > -/*
> > > > > - * Safe printk() for NMI context. It uses a per-CPU buffer to
> > > > > - * store the message. NMIs are not nested, so there is always only
> > > > > - * one writer running. But the buffer might get flushed from another
> > > > > - * CPU, so we need to be careful.
> > > > > - */
> > > > 
> > > > We should keep/create a good description here because the function
> > > > has a non-trivial code. What about something like?
> > > > 
> > > 
> > > which is really not related to this patch set.
> > 
> > I am sorry but I do not understand. This patch removes description
> > that explained constrains of a rather complex code. In fact, the
> > constrains has changed because we started using the function also
> > in other context. When will be the right time/patchset to explain
> > it?
> 
> but I didn't remove it.
> 
> $ grep -A3 -B3 'But the buffer might get flushed from another' kernel/printk/printk_safe.c
> 
> /*
>  * Safe printk() for NMI context. It uses a per-CPU buffer to
>  * store the message. NMIs are not nested, so there is always only
>  * one writer running. But the buffer might get flushed from another
>  * CPU, so we need to be careful.
>  */
> static int vprintk_safe_nmi(const char *fmt, va_list args)

I know, it is moved to the caller of the complex function.
And the description of the other new caller explicitly talks
about printk() recursion (nesting). It opens question if
it is still safe and there is no single note about it.
Also there is no explanation why we need the other buffer
at all.


> > > > > +#ifdef CONFIG_PRINTK_NMI
> > > > > +/*
> > > > > + * Safe printk() for NMI context. It uses a per-CPU buffer to
> > > > > + * store the message. NMIs are not nested, so there is always only
> > > > > + * one writer running. But the buffer might get flushed from another
> > > > > + * CPU, so we need to be careful.
> > > > > + */
> > > > 
> > > > Hmm, I wanted to describe why we need another per-CPU buffer in NMI
> > > > and I am not sure that we really need it.
> > > 
> > > NMI-printk can interrupt safe-printk's vsnprintf() in the middle of
> > > the "while (*fmt)" loop: safe-priNMI-PRINTK
> > 
> > But this already happens when any of the WARNs is triggered
> > inside vsnprintf(). Either this is safe or we are in
> > trouble.
> 
> the point was that when printk-safe resumes after being interrupted
> by NMI-printk it continues printing from the offset at which it has
> been interrupted, writing over the lines that were sprintf-d by NMI
> printk; because NMI-printk used the same buffer offset `s->len'. so
> at least part of NMI-printk message will be lost.

Yes, I wrote this in the previous mail as well. I remember that
I already thought about this problem when working on the original
NMI implementation and I forgot it. This is what comments are for.
Even authors forget details and they do not want to get into
the same cycles again and again.

I understand that you are tired with respining the patchset.
But hey, updating comments is easy. And if people only ask
to add some comments, it means that it is most likely
the last round and all is almost done.

I do not know. Maybe you take my comments as criticism.
But it is not meant like this. I only want to safe some
work me and other people in the future.

Best Regards,
Petr

[toc] | [prev] | [next] | [standalone]

#1540390 — Re: [RFC][PATCHv5 3/7] printk: introduce per-cpu safe_print seq buffer

On (12/12/16 14:54), Petr Mladek wrote:
[..]
> > > Hmm, I wanted to describe why we need another per-CPU buffer in NMI
> > > and I am not sure that we really need it.
> > 
> > NMI-printk can interrupt safe-printk's vsnprintf() in the middle of
> > the "while (*fmt)" loop: safe-priNMI-PRINTK
> 
> But this already happens when any of the WARNs is triggered
> inside vsnprintf(). Either this is safe or we are in
> trouble.
[..]
> Well, I am not sure if we should bother.

well, I'd probably agree that we shouldn't care. I'd may be even
say that nested warnings from vsnprintf() are not so important to
over-complicated everything (comparing to lost NMI-printk messages,
which are really important).


> Well, is it that bad to ask for better comments?

ok, I'll take a look. gotta re-base the series once again anyway.

> Or am I dumb and it was all obvious?

of course no! I never said that. never! :)
my apologies.

	-ss

[toc] | [prev] | [standalone]

Back to top | Article view | linux.kernel

csiph-web