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

[Steven Rostedt]

On Wed, 10 Jun 2015 14:55:09 +0200
Peter Zijlstra <peterz@xxxxxxxxxxxxx> 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;

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/