lkml.org 
[lkml]   [2016]   [Sep]   [29]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
From
SubjectRe: [RFC][PATCH 3/7] printk: introduce per-cpu alt_print seq buffer
On Tue 2016-09-27 23:22:33, 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
> of critical scheduler locks (p->pi_lock, etc.). An example of
> a 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_do_activate()
> 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()
> local_irq_save()
> alt_printk_enter()

We need to make sure that exit() is called on the same CPU.
Therefore we need to disable preemption as well.

> //
> // any printk() call from here will endup in vprintk_alt(),
> // that stores messages in a special per-CPU buffer.
> //
> alt_printk_exit()
> local_irq_restore()
>
> The patch only adds a alt_printk support, we don't use it yet.
>
> Signed-off-by: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
> ---
> kernel/printk/alt_printk.c | 160 +++++++++++++++++++++++++++++++++++++++++----
> kernel/printk/internal.h | 12 ++++
> 2 files changed, 158 insertions(+), 14 deletions(-)
>
> diff --git a/kernel/printk/alt_printk.c b/kernel/printk/alt_printk.c
> index 7178661..8978390 100644
> --- a/kernel/printk/alt_printk.c
> +++ b/kernel/printk/alt_printk.c
> @@ -1,5 +1,5 @@
> /*
> - * alt_printk.c - Safe printk in NMI context
> + * alt_printk.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
> @@ -53,24 +53,39 @@ struct alt_printk_seq_buf {
> static DEFINE_PER_CPU(struct alt_printk_seq_buf, nmi_print_seq);
>
> /*
> - * 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.
> + * There can be two alt_printk contexts at most - a `normal' alt_printk
> + * and NMI alt_printk context. Normal alt_printk context is the one that
> + * direct caller of printk() setups (either a process or IRQ) and it can
> + * be preempted only by NMI (if the platform supports NMI). NMI context
> + * can preempt normal alt_printk context, but cannot be preempted on its
> + * own.
> */
> -static int vprintk_nmi(const char *fmt, va_list args)
> +#ifdef CONFIG_PRINTK_NMI
> +#define MAX_ALT_PRINTK_CTX 2
> +#else
> +#define MAX_ALT_PRINTK_CTX 1
> +#endif
> +
> +struct alt_printk_ctx {
> + atomic_t idx;
> + unsigned int entry_count;
> + printk_func_t saved_printk_func[MAX_ALT_PRINTK_CTX];
> +};
> +
> +static DEFINE_PER_CPU(struct alt_printk_seq_buf, alt_print_seq);
> +static DEFINE_PER_CPU(struct alt_printk_ctx, alt_printk_ctx);
> +
> +static int alt_printk_log_store(struct alt_printk_seq_buf *s,
> + const char *fmt, va_list args)
> {
> - struct alt_printk_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);
> + if (len >= sizeof(s->buffer))
> return 0;
> - }
>
> /*
> * Make sure that all old data have been read before the buffer was
> @@ -99,6 +114,96 @@ static int vprintk_nmi(const char *fmt, va_list args)
> return add;
> }
>
> +/*
> + * 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_alt(const char *fmt, va_list args)
> +{
> + struct alt_printk_seq_buf *s = this_cpu_ptr(&alt_print_seq);
> +
> + return alt_printk_log_store(s, fmt, args);
> +}
> +
> +/*
> + * We must keep the track of `printk_func' because alt_printk
> + * context can be preempted by NMI alt_printk context.
> + *
> + * Consider the following example:
> + *
> + * vprintk_emit()
> + * alt_printk_enter()
> + * printk_func = vprintk_alt;
> + *
> + * -> NMI
> + * printk_nmi_enter()
> + * printk_func = vprintk_nmi;
> + * printk_nmi_exit()
> + * printk_func = vprintk_default;
> + * ^^^^^^^^^^^
> + * <- NMI
> + *
> + * printk("foo") -> vprintk_default();
> + *
> + * Thus we must restore the orignal `printk_func' value, the one
> + * NMI saw at printk_nmi_enter() time.
> + */
> +static void __lockless_printk_enter(printk_func_t new_func)
> +{
> + struct alt_printk_ctx *ctx = this_cpu_ptr(&alt_printk_ctx);
> + int idx = atomic_inc_return(&ctx->idx) - 1;
> +
> + ctx->saved_printk_func[idx] = this_cpu_read(printk_func);
> + this_cpu_write(printk_func, new_func);
> +}
> +
> +static void __lockless_printk_exit(void)
> +{
> + struct alt_printk_ctx *ctx = this_cpu_ptr(&alt_printk_ctx);
> + int idx = atomic_read(&ctx->idx) - 1;
> +
> + this_cpu_write(printk_func, ctx->saved_printk_func[idx]);
> + atomic_dec(&ctx->idx);
> +}
> +
> +/* Local IRQs must be disabled; can be preempted by NMI. */
> +void alt_printk_enter(void)
> +{
> + struct alt_printk_ctx *ctx = this_cpu_ptr(&alt_printk_ctx);
> +
> + /*
> + * We can't switch `printk_func' while the CPU is flushing its
> + * alternative buffers. At the same time, we leave flushing
> + * `unprotected', because we always use vprintk_default() there.
> + *
> + * ->entry_count can detect printk() recursion from flushing context:
> + * -- alt_printk_flush() sets ->entry_count to 1
> + * -- every vprintk_default() call from alt_printk_flush() increments
> + * ->entry_count to 2 when it enters the recursion un-safe region
> + * and decrements it back to 1 when it leaves that region
> + * -- thus, if printk() will recurs from recursion un-safe region, we
> + * will see ->entry_count > 2.
> + */
> + ctx->entry_count++;
> + if (ctx->entry_count > 1)
> + return;
> +
> + /* @TODO: do something sensible in case of printk() recursion */
> +
> + __lockless_printk_enter(vprintk_alt);
> +}
> +
> +/* Local IRQs must be disabled; can be preempted by NMI. */
> +void alt_printk_exit(void)
> +{
> + struct alt_printk_ctx *ctx = this_cpu_ptr(&alt_printk_ctx);
> +
> + if (ctx->entry_count == 1)
> + __lockless_printk_exit();
> + ctx->entry_count--;
> +}

Huh, this is complicated like hell. I think that it is like this
because of two reasons. First, it tries to change more values a
lockless way. Second, it tries to be kind of generic.

Note that it is not much generic. idx is increased or decreased only
when entry_count == 1 or when called from nmi_enter()/exit().
Therefore it could not be easily extended to yet another alt buffer.
Also it relies on the fact the nmi_enter()/exit() calls are not
nested.

What do you think about my approach with the printk_context per-CPU
value from the WARN_DEFERRED() patchset? The main idea is that
the entry()/exit() functions manipulate preempt_count-like per-CPU
variable. The printk() function selects the safe implementation
according to the current state.

> static void alt_printk_flush_line(const char *text, int len)
> {
> /*
> @@ -110,7 +215,6 @@ static void alt_printk_flush_line(const char *text, int len)
> printk_deferred("%.*s", len, text);
> else
> printk("%.*s", len, text);
> -
> }
>
> /*
> @@ -135,6 +239,7 @@ static void __alt_printk_flush(struct irq_work *work)
> __RAW_SPIN_LOCK_INITIALIZER(read_lock);
> struct alt_printk_seq_buf *s = container_of(work,
> struct alt_printk_seq_buf, work);
> + struct alt_printk_ctx *ctx = this_cpu_ptr(&alt_printk_ctx);
> unsigned long flags;
> size_t len, size;
> int i, last_i;
> @@ -147,6 +252,11 @@ static void __alt_printk_flush(struct irq_work *work)
> * a backtrace.
> */
> raw_spin_lock_irqsave(&read_lock, flags);
> + /*
> + * Forbid the alt_printk on this CPU, we want to flush messages to
> + * logbuf, not to alt_printk buffer again.
> + */
> + ctx->entry_count++;

This looks very strange. If entry_count is not zero, it means that we
are not in a safe context to flush the alternative buffer. Or do
I miss something, please?


My other concern about this approach was that it would spread printk()
messages to even more buffers. But I am not scared anymore. The
new buffer will be used only for printk-internal errors that would
normally cause a deadlock. The important thing is that we are able
to share the implementation handling the extra buffer.

So, I think that this approach have a chance if we clean it a bit.

Best Regards,
Petr

\
 
 \ /
  Last update: 2016-09-29 14:27    [W:0.195 / U:0.448 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site