Re: [RFC][PATCH] printk: Fixup the nmi printk mess

Steven Rostedt
2015-06-10T16:03:06Z

On Wed, 10 Jun 2015 14:55:09 +0200
Peter Zijlstra <peterz@infradead.org> wrote:

> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -1821,13 +1821,125 @@ int vprintk_default(const char *fmt, va_list args)
> }
> EXPORT_SYMBOL_GPL(vprintk_default);
>
> +#ifdef CONFIG_PRINTK_NMI
> +
> +typedef int(*printk_func_t)(const char *fmt, va_list args);
> /*
> * This allows printk to be diverted to another function per cpu.
> * This is useful for calling printk functions from within NMI
> * without worrying about race conditions that can lock up the
> * box.
> */
> -DEFINE_PER_CPU(printk_func_t, printk_func) = vprintk_default;
> +static DEFINE_PER_CPU(printk_func_t, printk_func) = vprintk_default;
> +
> +#include <linux/seq_buf.h>
> +
> +struct nmi_seq_buf {
> + struct seq_buf seq;
> + struct irq_work work;
> + unsigned char buffer[PAGE_SIZE -
> + sizeof(struct seq_buf) -
> + sizeof(struct irq_work)];
> +};
> +
> +/* Safe printing in NMI context */
> +static DEFINE_PER_CPU(struct nmi_seq_buf, nmi_print_seq);
> +
> +static void print_seq_line(struct nmi_seq_buf *s, int start, int end)
> +{
> + const char *buf = s->buffer + start;
> +
> + printk("%.*s", (end - start) + 1, buf);
> +}
> +
> +static void __printk_nmi_flush(struct irq_work *work)
> +{
> + struct nmi_seq_buf *s = container_of(work, struct nmi_seq_buf, work);
> + int len, last_i = 0, i = 0;
> +
> +again:
> + len = seq_buf_used(&s->seq);
> + if (!len)
> + return;
> +
> + /* Print line by line. */
> + for (; i < len; i++) {
> + if (s->buffer[i] == '\n') {
> + print_seq_line(s, last_i, i);
> + last_i = i + 1;
> + }
> + }
> + /* Check if there was a partial line. */
> + if (last_i < len) {
> + print_seq_line(s, last_i, len - 1);
> + pr_cont("\n");
> + }
> +
> + /*
> + * Another NMI could have come in while we were printing
> + * check if nothing has been added to the buffer.
> + */
> + if (cmpxchg_local(&s->seq.len, len, 0) != len)
> + goto again;
> +}
> +
> +void printk_init(void)
> +{
> + int cpu;
> +
> + for_each_possible_cpu(cpu) {
> + struct nmi_seq_buf *s = &per_cpu(nmi_print_seq, cpu);
> +
> + init_irq_work(&s->work, __printk_nmi_flush);
> + seq_buf_init(&s->seq, s->buffer, sizeof(s->buffer));
> + }
> +}
> +
> +/*
> + * It is not safe to call printk() directly from NMI handlers.
> + * It may be fine if the NMI detected a lock up and we have no choice
> + * but to do so, but doing a NMI on all other CPUs to get a back trace
> + * can be done with a sysrq-l. We don't want that to lock up, which
> + * can happen if the NMI interrupts a printk in progress.
> + *
> + * Instead, we redirect the vprintk() to this nmi_vprintk() that writes
> + * the content into a per cpu seq_buf buffer. Then when the NMIs are
> + * all done, we can safely dump the contents of the seq_buf to a printk()
> + * from a non NMI context.
> + */
> +static int vprintk_nmi(const char *fmt, va_list args)
> +{
> + struct nmi_seq_buf *s = this_cpu_ptr(&nmi_print_seq);
> + unsigned int len = seq_buf_used(&s->seq);
> +
> + irq_work_queue(&s->work);
> + seq_buf_vprintf(&s->seq, fmt, args);
> + return seq_buf_used(&s->seq) - len;
> +}
> +
> +void printk_nmi_enter(void)
> +{
> + this_cpu_write(printk_func, vprintk_nmi);
> +}
> +
> +void printk_nmi_exit(void)
> +{
> + this_cpu_write(printk_func, vprintk_default);
> +}
> +
> +static inline int vprintk_func(const char *fmt, va_list args)
> +{
> + return this_cpu_read(printk_func)(fmt, args);
> +}
> +
> +#else
> +
> +static inline int vprintk_func(const char *fmt, va_list args)
> +{
> + return vprintk_default(fmt, args);
> +}
> +
> +#endif /* PRINTK_NMI */

BTW, the printk.c file is getting rather big. Can we make a
kernel/printk/nmi.c file that does this work. We can add a local
printk_common.h that can share the global data structures, and this
would move most of the #ifdef out of the C files.

obj-$(CONFIG_PRINTK_NMI) += nmi.o

And the header file could have:

#ifdef CONFIG_PRINTK_NMI
typedef int(*printk_func_t)(const char *fmt, va_list args);
DECLARE_PER_CPU(printk_func_t, printk_func);

static inline int vprintk_func(const char *fmt, va_list args)
{
return this_cpu_read(printk_func)(fmt, args);
}
#else
static inline int vprintk_func(const char *fmt, va_list args)
{
return vprintk_default(fmt, args);
}
#endif /* PRINTK_NMI */

-- Steve

>
> /**
> * printk - print a kernel message
> @@ -1852,21 +1964,11 @@ DEFINE_PER_CPU(printk_func_t, printk_func) = vprintk_default;
> */
> asmlinkage __visible int printk(const char *fmt, ...)
> {
> - printk_func_t vprintk_func;
> va_list args;
> int r;
>
> va_start(args, fmt);
> -
> - /*
> - * If a caller overrides the per_cpu printk_func, then it needs
> - * to disable preemption when calling printk(). Otherwise
> - * the printk_func should be set to the default. No need to
> - * disable preemption here.
> - */
> - vprintk_func = this_cpu_read(printk_func);
> r = vprintk_func(fmt, args);
> -
> va_end(args);
>
> return r;