2022-02-02 14:52:52

by Stephen Brennan

[permalink] [raw]
Subject: [PATCH v3 0/4] printk: reduce deadlocks during panic

When a caller writes heavily to the kernel log (e.g. writing to
/dev/kmsg in a loop) while another panics, there's currently a high
likelihood of a deadlock (see patch 2 for the full description of this
deadlock).

The principle fix is to disable the optimistic spin once panic_cpu is
set, so the panic CPU doesn't spin waiting for a halted CPU to hand over
the console_sem.

However, this exposed us to a livelock situation, where the panic CPU
holds the console_sem, and another CPU could fill up the log buffer
faster than the consoles could drain it, preventing the panic from
progressing and halting the other CPUs. To avoid this, patch 3 adds a
mechanism to suppress printk (from non-panic-CPU) during panic, if we
reach a threshold of dropped messages.

A major goal with all of these patches is to try to decrease the
likelihood that another CPU is holding the console_sem when we halt it
in panic(). This reduces the odds of needing to break locks and
potentially encountering further deadlocks with the console drivers.

To test, I use the following script, kmsg_panic.sh:

#!/bin/bash
date
# 991 chars (based on log buffer size):
chars="$(printf 'a%.0s' {1..991})"
while :; do
echo $chars > /dev/kmsg
done &
echo c > /proc/sysrq-trigger &
date
exit

I defined a hang as any time the system did not reboot to a login prompt
on the serial console within 60 seconds. Here are the statistics on
hangs using this script, before and after the patch.

before: 776 hangs / 1484 trials - 52.3%
after : 0 hangs / 15k trials - 0.0%

v3:
Some mild style changes, none of which affect testing (which has run
continuously and is now over 15 thousand trials without a hang!)
v2:
Each patch has minor updates from code reviews. I've re-done testing and
updated the above statistics. Exact changes are in each patch.

Stephen Brennan (4):
printk: Add panic_in_progress helper
printk: disable optimistic spin during panic
printk: Avoid livelock with heavy printk during panic
printk: Drop console_sem during panic

kernel/printk/printk.c | 55 +++++++++++++++++++++++++++++++++++++++++-
1 file changed, 54 insertions(+), 1 deletion(-)

--
2.30.2


2022-02-02 16:14:46

by Stephen Brennan

[permalink] [raw]
Subject: [PATCH v3 4/4] printk: Drop console_sem during panic

If another CPU is in panic, we are about to be halted. Try to gracefully
abandon the console_sem, leaving it free for the panic CPU to grab.

Suggested-by: Petr Mladek <[email protected]>
Signed-off-by: Stephen Brennan <[email protected]>
---

Notes:
v2: Factor check out to a helper, and check at the end of
console_unlock() to prevent retry as well.

kernel/printk/printk.c | 25 ++++++++++++++++++++++++-
1 file changed, 24 insertions(+), 1 deletion(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index cc7bb86f7bfe..35676e76482e 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2598,6 +2598,25 @@ static int have_callable_console(void)
return 0;
}

+/*
+ * Return true when this CPU should unlock console_sem without pushing all
+ * messages to the console. This reduces the chance that the console is
+ * locked when the panic CPU tries to use it.
+ */
+static bool abandon_console_lock_in_panic(void)
+{
+ if (!panic_in_progress())
+ return false;
+
+ /*
+ * We can use raw_smp_processor_id() here because it is impossible for
+ * the task to be migrated to the panic_cpu, or away from it. If
+ * panic_cpu has already been set, and we're not currently executing on
+ * that CPU, then we never will be.
+ */
+ return atomic_read(&panic_cpu) != raw_smp_processor_id();
+}
+
/*
* Can we actually use the console at this time on this cpu?
*
@@ -2746,6 +2765,10 @@ void console_unlock(void)
if (handover)
return;

+ /* Allow panic_cpu to take over the consoles safely */
+ if (abandon_console_lock_in_panic())
+ break;
+
if (do_cond_resched)
cond_resched();
}
@@ -2763,7 +2786,7 @@ void console_unlock(void)
* flush, no worries.
*/
retry = prb_read_valid(prb, next_seq, NULL);
- if (retry && console_trylock())
+ if (retry && !abandon_console_lock_in_panic() && console_trylock())
goto again;
}
EXPORT_SYMBOL(console_unlock);
--
2.30.2

2022-02-03 20:34:57

by Stephen Brennan

[permalink] [raw]
Subject: [PATCH v3 1/4] printk: Add panic_in_progress helper

This will be used help avoid deadlocks during panics. Although it would
be better to include this in linux/panic.h, it would require that header
to include linux/atomic.h as well. On some architectures, this results
in a circular dependency. So instead add the helper directly to
printk.c.

Suggested-by: Petr Mladek <[email protected]>
Signed-off-by: Stephen Brennan <[email protected]>
Reviewed-by: Petr Mladek <[email protected]>
---

Notes:
v3: Move the helper into printk.c due to circular include
v2: Switch from macro to static inline function

kernel/printk/printk.c | 5 +++++
1 file changed, 5 insertions(+)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 57b132b658e1..b33c2861a8fc 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1762,6 +1762,11 @@ static DEFINE_RAW_SPINLOCK(console_owner_lock);
static struct task_struct *console_owner;
static bool console_waiter;

+static bool panic_in_progress(void)
+{
+ return unlikely(atomic_read(&panic_cpu) != PANIC_CPU_INVALID);
+}
+
/**
* console_lock_spinning_enable - mark beginning of code where another
* thread might safely busy wait
--
2.30.2

2022-02-04 09:26:53

by Stephen Brennan

[permalink] [raw]
Subject: [PATCH v3 3/4] printk: Avoid livelock with heavy printk during panic

During panic(), if another CPU is writing heavily the kernel log (e.g.
via /dev/kmsg), then the panic CPU may livelock writing out its messages
to the console. Note when too many messages are dropped during panic and
suppress further printk, except from the panic CPU. This could result in
some important messages being dropped. However, messages are already
being dropped, so this approach at least prevents a livelock.

Reviewed-by: Petr Mladek <[email protected]>
Signed-off-by: Stephen Brennan <[email protected]>
---

Notes:
v3: Use pr_warn_once, and don't break the message line
v2: Add pr_warn when we suppress printk on non-panic CPU

kernel/printk/printk.c | 15 +++++++++++++++
1 file changed, 15 insertions(+)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 1b96166eea35..cc7bb86f7bfe 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -93,6 +93,12 @@ EXPORT_SYMBOL_GPL(console_drivers);
*/
int __read_mostly suppress_printk;

+/*
+ * During panic, heavy printk by other CPUs can delay the
+ * panic and risk deadlock on console resources.
+ */
+int __read_mostly suppress_panic_printk;
+
#ifdef CONFIG_LOCKDEP
static struct lockdep_map console_lock_dep_map = {
.name = "console_lock"
@@ -2233,6 +2239,10 @@ asmlinkage int vprintk_emit(int facility, int level,
if (unlikely(suppress_printk))
return 0;

+ if (unlikely(suppress_panic_printk) &&
+ atomic_read(&panic_cpu) != raw_smp_processor_id())
+ return 0;
+
if (level == LOGLEVEL_SCHED) {
level = LOGLEVEL_DEFAULT;
in_sched = true;
@@ -2618,6 +2628,7 @@ void console_unlock(void)
{
static char ext_text[CONSOLE_EXT_LOG_MAX];
static char text[CONSOLE_LOG_MAX];
+ static int panic_console_dropped;
unsigned long flags;
bool do_cond_resched, retry;
struct printk_info info;
@@ -2672,6 +2683,10 @@ void console_unlock(void)
if (console_seq != r.info->seq) {
console_dropped += r.info->seq - console_seq;
console_seq = r.info->seq;
+ if (panic_in_progress() && panic_console_dropped++ > 10) {
+ suppress_panic_printk = 1;
+ pr_warn_once("Too many dropped messages. Supress messages on non-panic CPUs to prevent livelock.\n");
+ }
}

if (suppress_message_printing(r.info->level)) {
--
2.30.2

2022-02-07 10:13:32

by Sergey Senozhatsky

[permalink] [raw]
Subject: Re: [PATCH v3 4/4] printk: Drop console_sem during panic

On (22/02/01 10:58), Stephen Brennan wrote:
> +/*
> + * Return true when this CPU should unlock console_sem without pushing all
> + * messages to the console. This reduces the chance that the console is
> + * locked when the panic CPU tries to use it.
> + */
> +static bool abandon_console_lock_in_panic(void)
> +{
> + if (!panic_in_progress())
> + return false;
> +
> + /*
> + * We can use raw_smp_processor_id() here because it is impossible for
> + * the task to be migrated to the panic_cpu, or away from it. If
> + * panic_cpu has already been set, and we're not currently executing on
> + * that CPU, then we never will be.
> + */
> + return atomic_read(&panic_cpu) != raw_smp_processor_id();
> +}
> +
> /*
> * Can we actually use the console at this time on this cpu?
> *
> @@ -2746,6 +2765,10 @@ void console_unlock(void)
> if (handover)
> return;
>
> + /* Allow panic_cpu to take over the consoles safely */
> + if (abandon_console_lock_in_panic())
> + break;

Sorry, why not just `return` like in handover case?

> +
> if (do_cond_resched)
> cond_resched();
> }
> @@ -2763,7 +2786,7 @@ void console_unlock(void)
> * flush, no worries.
> */
> retry = prb_read_valid(prb, next_seq, NULL);
> - if (retry && console_trylock())
> + if (retry && !abandon_console_lock_in_panic() && console_trylock())
> goto again;
> }
> EXPORT_SYMBOL(console_unlock);

2022-02-07 17:14:51

by Stephen Brennan

[permalink] [raw]
Subject: Re: [PATCH v3 1/4] printk: Add panic_in_progress helper

Stephen Brennan <[email protected]> writes:
> This will be used help avoid deadlocks during panics. Although it would
> be better to include this in linux/panic.h, it would require that header
> to include linux/atomic.h as well. On some architectures, this results
> in a circular dependency. So instead add the helper directly to
> printk.c.
>
> Suggested-by: Petr Mladek <[email protected]>
> Signed-off-by: Stephen Brennan <[email protected]>
> Reviewed-by: Petr Mladek <[email protected]>
> ---
>
> Notes:
> v3: Move the helper into printk.c due to circular include
> v2: Switch from macro to static inline function
>
> kernel/printk/printk.c | 5 +++++
> 1 file changed, 5 insertions(+)
>
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index 57b132b658e1..b33c2861a8fc 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -1762,6 +1762,11 @@ static DEFINE_RAW_SPINLOCK(console_owner_lock);
> static struct task_struct *console_owner;
> static bool console_waiter;
>
> +static bool panic_in_progress(void)
> +{
> + return unlikely(atomic_read(&panic_cpu) != PANIC_CPU_INVALID);
> +}
> +

Unfortunately this is defined within a (very large)
#ifdef CONFIG_PRINTK section. Thanks to the kbuild bot which will have
earned the reported-by tag on this patch :D

v4 will be tomorrow. Sorry for the noise everyone!

> /**
> * console_lock_spinning_enable - mark beginning of code where another
> * thread might safely busy wait
> --
> 2.30.2

2022-02-09 05:28:34

by Sergey Senozhatsky

[permalink] [raw]
Subject: Re: [PATCH v3 4/4] printk: Drop console_sem during panic

On (22/02/04 10:53), Stephen Brennan wrote:
> Sergey Senozhatsky <[email protected]> writes:
> > On (22/02/01 10:58), Stephen Brennan wrote:
> >> +/*
> >> + * Return true when this CPU should unlock console_sem without pushing all
> >> + * messages to the console. This reduces the chance that the console is
> >> + * locked when the panic CPU tries to use it.
> >> + */
> >> +static bool abandon_console_lock_in_panic(void)
> >> +{
> >> + if (!panic_in_progress())
> >> + return false;
> >> +
> >> + /*
> >> + * We can use raw_smp_processor_id() here because it is impossible for
> >> + * the task to be migrated to the panic_cpu, or away from it. If
> >> + * panic_cpu has already been set, and we're not currently executing on
> >> + * that CPU, then we never will be.
> >> + */
> >> + return atomic_read(&panic_cpu) != raw_smp_processor_id();
> >> +}
> >> +
> >> /*
> >> * Can we actually use the console at this time on this cpu?
> >> *
> >> @@ -2746,6 +2765,10 @@ void console_unlock(void)
> >> if (handover)
> >> return;
> >>
> >> + /* Allow panic_cpu to take over the consoles safely */
> >> + if (abandon_console_lock_in_panic())
> >> + break;
> >
> > Sorry, why not just `return` like in handover case?
>
> We need to drop console_sem before returning, since the whole benefit
> here is to increase the chance that console_sem is unlocked when the
> panic_cpu halts this CPU.

Yes, that makes sense.

> in the handover case, there's another cpu waiting, and we're essentially
> transferring the console_sem ownership to that cpu, so we explicitly
> return and skip the unlocking portion.
>
> Does this need some comments to clarify it?

No. Everything looks good. Thanks.