Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]
Groups > linux.kernel > #1493440
| From | Petr Mladek <pmladek@suse.com> |
|---|---|
| Newsgroups | linux.kernel |
| Subject | Re: [RFC][PATCH 3/7] printk: introduce per-cpu alt_print seq buffer |
| Date | 2016-09-29 14:30 +0200 |
| Message-ID | <smIDo-45v-23@gated-at.bofh.it> (permalink) |
| References | <sm1yp-29m-3@gated-at.bofh.it> <sm1yq-29m-9@gated-at.bofh.it> |
| Organization | linux.* mail to news gateway |
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
Back to linux.kernel | Previous | Next — Previous in thread | Next in thread | Find similar | Unroll thread
[RFC][PATCH 0/7] printk: use alt_printk to handle printk() recursive calls Sergey Senozhatsky <sergey.senozhatsky@gmail.com> - 2016-09-27 16:30 +0200
[RFC][PATCH 5/7] printk: drop vprintk_func function Sergey Senozhatsky <sergey.senozhatsky@gmail.com> - 2016-09-27 16:30 +0200
[RFC][PATCH 3/7] printk: introduce per-cpu alt_print seq buffer Sergey Senozhatsky <sergey.senozhatsky@gmail.com> - 2016-09-27 16:30 +0200
Re: [RFC][PATCH 3/7] printk: introduce per-cpu alt_print seq buffer Petr Mladek <pmladek@suse.com> - 2016-09-29 14:30 +0200
Re: [RFC][PATCH 3/7] printk: introduce per-cpu alt_print seq buffer Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2016-09-30 03:10 +0200
Re: [RFC][PATCH 3/7] printk: introduce per-cpu alt_print seq buffer Petr Mladek <pmladek@suse.com> - 2016-09-30 13:40 +0200
[RFC][PATCH 1/7] printk: use vprintk_func in vprintk() Sergey Senozhatsky <sergey.senozhatsky@gmail.com> - 2016-09-27 16:30 +0200
[RFC][PATCH 2/7] printk: rename nmi.c and exported api Sergey Senozhatsky <sergey.senozhatsky@gmail.com> - 2016-09-27 16:30 +0200
[RFC][PATCH 6/7] printk: use alternative printk buffers Sergey Senozhatsky <sergey.senozhatsky@gmail.com> - 2016-09-27 16:30 +0200
Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Petr Mladek <pmladek@suse.com> - 2016-09-29 15:10 +0200
Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2016-09-30 03:20 +0200
Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Petr Mladek <pmladek@suse.com> - 2016-09-30 13:20 +0200
Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2016-10-01 04:50 +0200
Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Petr Mladek <pmladek@suse.com> - 2016-10-04 14:30 +0200
Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2016-10-05 03:40 +0200
Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Petr Mladek <pmladek@suse.com> - 2016-10-05 12:20 +0200
Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Sergey Senozhatsky <sergey.senozhatsky@gmail.com> - 2016-10-03 10:00 +0200
Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Petr Mladek <pmladek@suse.com> - 2016-10-04 17:00 +0200
Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2016-10-05 03:30 +0200
Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Petr Mladek <pmladek@suse.com> - 2016-10-05 12:00 +0200
Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2016-10-06 06:30 +0200
Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Petr Mladek <pmladek@suse.com> - 2016-10-06 13:40 +0200
Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2016-10-10 06:20 +0200
Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Petr Mladek <pmladek@suse.com> - 2016-10-10 13:20 +0200
Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2016-10-11 09:40 +0200
Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Petr Mladek <pmladek@suse.com> - 2016-10-11 11:40 +0200
[RFC][PATCH 4/7] printk: make alt_printk available when config printk set Sergey Senozhatsky <sergey.senozhatsky@gmail.com> - 2016-09-27 16:30 +0200
[RFC][PATCH 7/7] printk: new printk() recursion detection Sergey Senozhatsky <sergey.senozhatsky@gmail.com> - 2016-09-27 16:30 +0200
Re: [RFC][PATCH 7/7] printk: new printk() recursion detection Petr Mladek <pmladek@suse.com> - 2016-09-29 15:30 +0200
Re: [RFC][PATCH 7/7] printk: new printk() recursion detection Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2016-09-30 04:10 +0200
Re: [RFC][PATCH 0/7] printk: use alt_printk to handle printk() recursive calls Petr Mladek <pmladek@suse.com> - 2016-09-29 15:30 +0200
Re: [RFC][PATCH 0/7] printk: use alt_printk to handle printk() recursive calls Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2016-09-30 04:50 +0200
Re: [RFC][PATCH 0/7] printk: use alt_printk to handle printk() recursive calls Petr Mladek <pmladek@suse.com> - 2016-09-30 13:30 +0200
Re: [RFC][PATCH 0/7] printk: use alt_printk to handle printk() recursive calls Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2016-10-01 05:10 +0200
Re: [RFC][PATCH 0/7] printk: use alt_printk to handle printk() recursive calls Petr Mladek <pmladek@suse.com> - 2016-10-04 13:40 +0200
csiph-web