From 44945f908f87501b711299bfe736012ed927526b Mon Sep 17 00:00:00 2001 From: John Ogness Date: Mon, 30 Nov 2020 01:42:10 +0106 Subject: [PATCH 108/323] printk: add pr_flush() Origin: https://www.kernel.org/pub/linux/kernel/projects/rt/5.10/older/patches-5.10.215-rt107.tar.xz Provide a function to allow waiting for console printers to catch up to the latest logged message. Use pr_flush() to give console printers a chance to finish in critical situations if no atomic console is available. For now pr_flush() is only used in the most common error paths: panic(), print_oops_end_marker(), report_bug(), kmsg_dump(). Signed-off-by: John Ogness Signed-off-by: Sebastian Andrzej Siewior Signed-off-by: Luis Claudio R. Goncalves --- include/linux/printk.h | 2 ++ kernel/panic.c | 28 +++++++++------ kernel/printk/printk.c | 79 ++++++++++++++++++++++++++++++++++++++++++ lib/bug.c | 1 + 4 files changed, 99 insertions(+), 11 deletions(-) diff --git a/include/linux/printk.h b/include/linux/printk.h index 410435ac15ea1..83c7734e98025 100644 --- a/include/linux/printk.h +++ b/include/linux/printk.h @@ -481,6 +481,8 @@ extern int kptr_restrict; no_printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__) #endif +bool pr_flush(int timeout_ms, bool reset_on_progress); + /* * ratelimited messages with local ratelimit_state, * no local ratelimit_state used in the !PRINTK case diff --git a/kernel/panic.c b/kernel/panic.c index 7fc35d3675e1b..0681472a2041a 100644 --- a/kernel/panic.c +++ b/kernel/panic.c @@ -244,6 +244,7 @@ void check_panic_on_warn(const char *origin) void panic(const char *fmt, ...) { static char buf[1024]; + va_list args2; va_list args; long i, i_next = 0, len; int state = 0; @@ -260,6 +261,21 @@ void panic(const char *fmt, ...) panic_on_warn = 0; } + console_verbose(); + pr_emerg("Kernel panic - not syncing:\n"); + va_start(args2, fmt); + va_copy(args, args2); + vprintk(fmt, args2); + va_end(args2); +#ifdef CONFIG_DEBUG_BUGVERBOSE + /* + * Avoid nested stack-dumping if a panic occurs during oops processing + */ + if (!test_taint(TAINT_DIE) && oops_in_progress <= 1) + dump_stack(); +#endif + pr_flush(1000, true); + /* * Disable local interrupts. This will prevent panic_smp_self_stop * from deadlocking the first cpu that invokes the panic, since @@ -290,24 +306,13 @@ void panic(const char *fmt, ...) if (old_cpu != PANIC_CPU_INVALID && old_cpu != this_cpu) panic_smp_self_stop(); - console_verbose(); bust_spinlocks(1); - va_start(args, fmt); len = vscnprintf(buf, sizeof(buf), fmt, args); va_end(args); if (len && buf[len - 1] == '\n') buf[len - 1] = '\0'; - pr_emerg("Kernel panic - not syncing: %s\n", buf); -#ifdef CONFIG_DEBUG_BUGVERBOSE - /* - * Avoid nested stack-dumping if a panic occurs during oops processing - */ - if (!test_taint(TAINT_DIE) && oops_in_progress <= 1) - dump_stack(); -#endif - /* * If kgdb is enabled, give it a chance to run before we stop all * the other CPUs or else we won't be able to debug processes left @@ -637,6 +642,7 @@ static void print_oops_end_marker(void) { init_oops_id(); pr_warn("---[ end trace %016llx ]---\n", (unsigned long long)oops_id); + pr_flush(1000, true); } /* diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c index 0cc452e7b1a1c..3fdd06c05f4ea 100644 --- a/kernel/printk/printk.c +++ b/kernel/printk/printk.c @@ -3256,6 +3256,12 @@ void kmsg_dump(enum kmsg_dump_reason reason) sync_mode = true; pr_info("enabled sync mode\n"); } + + /* + * Give the printing threads time to flush, allowing up to + * 1s of no printing forward progress before giving up. + */ + pr_flush(1000, true); } rcu_read_lock(); @@ -3535,3 +3541,76 @@ void console_atomic_unlock(unsigned int flags) prb_unlock(&printk_cpulock, flags); } EXPORT_SYMBOL(console_atomic_unlock); + +static void pr_msleep(bool may_sleep, int ms) +{ + if (may_sleep) { + msleep(ms); + } else { + while (ms--) + udelay(1000); + } +} + +/** + * pr_flush() - Wait for printing threads to catch up. + * + * @timeout_ms: The maximum time (in ms) to wait. + * @reset_on_progress: Reset the timeout if forward progress is seen. + * + * A value of 0 for @timeout_ms means no waiting will occur. A value of -1 + * represents infinite waiting. + * + * If @reset_on_progress is true, the timeout will be reset whenever any + * printer has been seen to make some forward progress. + * + * Context: Any context. + * Return: true if all enabled printers are caught up. + */ +bool pr_flush(int timeout_ms, bool reset_on_progress) +{ + int remaining = timeout_ms; + struct console *con; + u64 last_diff = 0; + bool may_sleep; + u64 printk_seq; + u64 diff; + u64 seq; + + may_sleep = (preemptible() && !in_softirq()); + + seq = prb_next_seq(prb); + + for (;;) { + diff = 0; + + for_each_console(con) { + if (!(con->flags & CON_ENABLED)) + continue; + printk_seq = atomic64_read(&con->printk_seq); + if (printk_seq < seq) + diff += seq - printk_seq; + } + + if (diff != last_diff && reset_on_progress) + remaining = timeout_ms; + + if (!diff || remaining == 0) + break; + + if (remaining < 0) { + pr_msleep(may_sleep, 100); + } else if (remaining < 100) { + pr_msleep(may_sleep, remaining); + remaining = 0; + } else { + pr_msleep(may_sleep, 100); + remaining -= 100; + } + + last_diff = diff; + } + + return (diff == 0); +} +EXPORT_SYMBOL(pr_flush); diff --git a/lib/bug.c b/lib/bug.c index 4ab398a2de938..9c681f29e61e6 100644 --- a/lib/bug.c +++ b/lib/bug.c @@ -202,6 +202,7 @@ enum bug_trap_type report_bug(unsigned long bugaddr, struct pt_regs *regs) else pr_crit("Kernel BUG at %pB [verbose debug info unavailable]\n", (void *)bugaddr); + pr_flush(1000, true); return BUG_TRAP_TYPE_BUG; } -- 2.44.0