From ce041c43f22298485122bab15c14d062383fbc67 Mon Sep 17 00:00:00 2001 From: Thierry Escande Date: Wed, 13 Jun 2018 19:18:40 +0200 Subject: lib/test_printf.c: accept "ptrval" as valid result for plain 'p' tests If the test_printf module is loaded before the crng is initialized, the plain 'p' tests will fail because the printed address will not be hashed and the buffer will contain "(____ptrval____)" or "(ptrval)" instead (64-bit vs 32-bit). Since we cannot wait for the crng to be initialized for an undefined time, both plain 'p' tests now accept the strings "(____ptrval____)" or "(ptrval)" as a valid result and print a warning message. Link: http://lkml.kernel.org/r/20180613171840.29827-1-thierry.escande@linaro.org Fixes: ad67b74d2469d9b82 ("printk: hash addresses printed with %p") To: Andrew Morton To: David Miller Cc: Rasmus Villemoes Cc: "Tobin C . Harding" Cc: linux-kernel@vger.kernel.org Signed-off-by: Thierry Escande Reviewed-by: Andy Shevchenko Signed-off-by: Petr Mladek --- lib/test_printf.c | 24 ++++++++++++++++++++++-- 1 file changed, 22 insertions(+), 2 deletions(-) (limited to 'lib') diff --git a/lib/test_printf.c b/lib/test_printf.c index cea592f402ed..53527ea822b5 100644 --- a/lib/test_printf.c +++ b/lib/test_printf.c @@ -206,6 +206,7 @@ test_string(void) #define PTR_WIDTH 16 #define PTR ((void *)0xffff0123456789abUL) #define PTR_STR "ffff0123456789ab" +#define PTR_VAL_NO_CRNG "(____ptrval____)" #define ZEROS "00000000" /* hex 32 zero bits */ static int __init @@ -216,7 +217,16 @@ plain_format(void) nchars = snprintf(buf, PLAIN_BUF_SIZE, "%p", PTR); - if (nchars != PTR_WIDTH || strncmp(buf, ZEROS, strlen(ZEROS)) != 0) + if (nchars != PTR_WIDTH) + return -1; + + if (strncmp(buf, PTR_VAL_NO_CRNG, PTR_WIDTH) == 0) { + pr_warn("crng possibly not yet initialized. plain 'p' buffer contains \"%s\"", + PTR_VAL_NO_CRNG); + return 0; + } + + if (strncmp(buf, ZEROS, strlen(ZEROS)) != 0) return -1; return 0; @@ -227,6 +237,7 @@ plain_format(void) #define PTR_WIDTH 8 #define PTR ((void *)0x456789ab) #define PTR_STR "456789ab" +#define PTR_VAL_NO_CRNG "(ptrval)" static int __init plain_format(void) @@ -245,7 +256,16 @@ plain_hash(void) nchars = snprintf(buf, PLAIN_BUF_SIZE, "%p", PTR); - if (nchars != PTR_WIDTH || strncmp(buf, PTR_STR, PTR_WIDTH) == 0) + if (nchars != PTR_WIDTH) + return -1; + + if (strncmp(buf, PTR_VAL_NO_CRNG, PTR_WIDTH) == 0) { + pr_warn("crng possibly not yet initialized. plain 'p' buffer contains \"%s\"", + PTR_VAL_NO_CRNG); + return 0; + } + + if (strncmp(buf, PTR_STR, PTR_WIDTH) == 0) return -1; return 0; -- cgit v1.2.3 From 22eceb8bf3e8f1f9b2f566062d06b25807725d7f Mon Sep 17 00:00:00 2001 From: Hans de Goede Date: Tue, 19 Jun 2018 13:57:26 +0200 Subject: printk: Make CONSOLE_LOGLEVEL_QUIET configurable The goal of passing the "quiet" option to the kernel is for the kernel to be quiet unless something really is wrong. Sofar passing quiet has been (mostly) equivalent to passing loglevel=4 on the kernel commandline. Which means to show any messages with a level of KERN_ERR or higher severity on the console. In practice this often does not result in a quiet boot though, since there are many false-positive or otherwise harmless error messages printed, defeating the purpose of the quiet option. Esp. the ACPICA code is really bad wrt this, but there are plenty of others too. This commit makes CONSOLE_LOGLEVEL_QUIET configurable. This for example will allow distros which want quiet to really mean quiet to set CONSOLE_LOGLEVEL_QUIET so that only messages with a higher severity then KERN_ERR (CRIT, ALERT, EMERG) get printed, avoiding an endless game of whack-a-mole silencing harmless error messages. Link: http://lkml.kernel.org/r/20180619115726.3098-1-hdegoede@redhat.com To: Petr Mladek To: Sergey Senozhatsky Cc: Hans de Goede Cc: Steven Rostedt Cc: linux-kernel@vger.kernel.org Signed-off-by: Hans de Goede Acked-by: Steven Rostedt (VMware) Reviewed-by: Sergey Senozhatsky Signed-off-by: Petr Mladek --- include/linux/printk.h | 6 +++--- lib/Kconfig.debug | 11 +++++++++++ 2 files changed, 14 insertions(+), 3 deletions(-) (limited to 'lib') diff --git a/include/linux/printk.h b/include/linux/printk.h index 6d7e800affd8..18602bb3eca8 100644 --- a/include/linux/printk.h +++ b/include/linux/printk.h @@ -50,15 +50,15 @@ static inline const char *printk_skip_headers(const char *buffer) /* We show everything that is MORE important than this.. */ #define CONSOLE_LOGLEVEL_SILENT 0 /* Mum's the word */ #define CONSOLE_LOGLEVEL_MIN 1 /* Minimum loglevel we let people use */ -#define CONSOLE_LOGLEVEL_QUIET 4 /* Shhh ..., when booted with "quiet" */ #define CONSOLE_LOGLEVEL_DEBUG 10 /* issue debug messages */ #define CONSOLE_LOGLEVEL_MOTORMOUTH 15 /* You can't shut this one up */ /* - * Default used to be hard-coded at 7, we're now allowing it to be set from - * kernel config. + * Default used to be hard-coded at 7, quiet used to be hardcoded at 4, + * we're now allowing both to be set from kernel config. */ #define CONSOLE_LOGLEVEL_DEFAULT CONFIG_CONSOLE_LOGLEVEL_DEFAULT +#define CONSOLE_LOGLEVEL_QUIET CONFIG_CONSOLE_LOGLEVEL_QUIET extern int console_printk[]; diff --git a/lib/Kconfig.debug b/lib/Kconfig.debug index 76555479ae36..a7ef03009e9e 100644 --- a/lib/Kconfig.debug +++ b/lib/Kconfig.debug @@ -30,6 +30,17 @@ config CONSOLE_LOGLEVEL_DEFAULT usage in the kernel. That is controlled by the MESSAGE_LOGLEVEL_DEFAULT option. +config CONSOLE_LOGLEVEL_QUIET + int "quiet console loglevel (1-15)" + range 1 15 + default "4" + help + loglevel to use when "quiet" is passed on the kernel commandline. + + When "quiet" is passed on the kernel commandline this loglevel + will be used as the loglevel. IOW passing "quiet" will be the + equivalent of passing "loglevel=" + config MESSAGE_LOGLEVEL_DEFAULT int "Default message log level (1-7)" range 1 7 -- cgit v1.2.3 From 03fc7f9c99c1e7ae2925d459e8487f1a6f199f79 Mon Sep 17 00:00:00 2001 From: Petr Mladek Date: Wed, 27 Jun 2018 16:20:28 +0200 Subject: printk/nmi: Prevent deadlock when accessing the main log buffer in NMI The commit 719f6a7040f1bdaf96 ("printk: Use the main logbuf in NMI when logbuf_lock is available") brought back the possible deadlocks in printk() and NMI. The check of logbuf_lock is done only in printk_nmi_enter() to prevent mixed output. But another CPU might take the lock later, enter NMI, and: + Both NMIs might be serialized by yet another lock, for example, the one in nmi_cpu_backtrace(). + The other CPU might get stopped in NMI, see smp_send_stop() in panic(). The only safe solution is to use trylock when storing the message into the main log-buffer. It might cause reordering when some lines go to the main lock buffer directly and others are delayed via the per-CPU buffer. It means that it is not useful in general. This patch replaces the problematic NMI deferred context with NMI direct context. It can be used to mark a code that might produce many messages in NMI and the risk of losing them is more critical than problems with eventual reordering. The context is then used when dumping trace buffers on oops. It was the primary motivation for the original fix. Also the reordering is even smaller issue there because some traces have their own time stamps. Finally, nmi_cpu_backtrace() need not longer be serialized because it will always us the per-CPU buffers again. Fixes: 719f6a7040f1bdaf96 ("printk: Use the main logbuf in NMI when logbuf_lock is available") Cc: stable@vger.kernel.org Link: http://lkml.kernel.org/r/20180627142028.11259-1-pmladek@suse.com To: Steven Rostedt Cc: Peter Zijlstra Cc: Tetsuo Handa Cc: Sergey Senozhatsky Cc: linux-kernel@vger.kernel.org Cc: stable@vger.kernel.org Acked-by: Sergey Senozhatsky Signed-off-by: Petr Mladek --- include/linux/printk.h | 4 ++++ kernel/printk/internal.h | 9 ++++++- kernel/printk/printk_safe.c | 58 +++++++++++++++++++++++++++++---------------- kernel/trace/trace.c | 4 +++- lib/nmi_backtrace.c | 3 --- 5 files changed, 52 insertions(+), 26 deletions(-) (limited to 'lib') diff --git a/include/linux/printk.h b/include/linux/printk.h index 6d7e800affd8..3ede9f46a494 100644 --- a/include/linux/printk.h +++ b/include/linux/printk.h @@ -148,9 +148,13 @@ void early_printk(const char *s, ...) { } #ifdef CONFIG_PRINTK_NMI extern void printk_nmi_enter(void); extern void printk_nmi_exit(void); +extern void printk_nmi_direct_enter(void); +extern void printk_nmi_direct_exit(void); #else static inline void printk_nmi_enter(void) { } static inline void printk_nmi_exit(void) { } +static inline void printk_nmi_direct_enter(void) { } +static inline void printk_nmi_direct_exit(void) { } #endif /* PRINTK_NMI */ #ifdef CONFIG_PRINTK diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h index 2a7d04049af4..0f1898820cba 100644 --- a/kernel/printk/internal.h +++ b/kernel/printk/internal.h @@ -19,11 +19,16 @@ #ifdef CONFIG_PRINTK #define PRINTK_SAFE_CONTEXT_MASK 0x3fffffff -#define PRINTK_NMI_DEFERRED_CONTEXT_MASK 0x40000000 +#define PRINTK_NMI_DIRECT_CONTEXT_MASK 0x40000000 #define PRINTK_NMI_CONTEXT_MASK 0x80000000 extern raw_spinlock_t logbuf_lock; +__printf(5, 0) +int vprintk_store(int facility, int level, + const char *dict, size_t dictlen, + const char *fmt, va_list args); + __printf(1, 0) int vprintk_default(const char *fmt, va_list args); __printf(1, 0) int vprintk_deferred(const char *fmt, va_list args); __printf(1, 0) int vprintk_func(const char *fmt, va_list args); @@ -54,6 +59,8 @@ void __printk_safe_exit(void); local_irq_enable(); \ } while (0) +void defer_console_output(void); + #else __printf(1, 0) int vprintk_func(const char *fmt, va_list args) { return 0; } diff --git a/kernel/printk/printk_safe.c b/kernel/printk/printk_safe.c index d7d091309054..a0a74c533e4b 100644 --- a/kernel/printk/printk_safe.c +++ b/kernel/printk/printk_safe.c @@ -308,24 +308,33 @@ static __printf(1, 0) int vprintk_nmi(const char *fmt, va_list args) void printk_nmi_enter(void) { - /* - * The size of the extra per-CPU buffer is limited. Use it only when - * the main one is locked. If this CPU is not in the safe context, - * the lock must be taken on another CPU and we could wait for it. - */ - if ((this_cpu_read(printk_context) & PRINTK_SAFE_CONTEXT_MASK) && - raw_spin_is_locked(&logbuf_lock)) { - this_cpu_or(printk_context, PRINTK_NMI_CONTEXT_MASK); - } else { - this_cpu_or(printk_context, PRINTK_NMI_DEFERRED_CONTEXT_MASK); - } + this_cpu_or(printk_context, PRINTK_NMI_CONTEXT_MASK); } void printk_nmi_exit(void) { - this_cpu_and(printk_context, - ~(PRINTK_NMI_CONTEXT_MASK | - PRINTK_NMI_DEFERRED_CONTEXT_MASK)); + this_cpu_and(printk_context, ~PRINTK_NMI_CONTEXT_MASK); +} + +/* + * Marks a code that might produce many messages in NMI context + * and the risk of losing them is more critical than eventual + * reordering. + * + * It has effect only when called in NMI context. Then printk() + * will try to store the messages into the main logbuf directly + * and use the per-CPU buffers only as a fallback when the lock + * is not available. + */ +void printk_nmi_direct_enter(void) +{ + if (this_cpu_read(printk_context) & PRINTK_NMI_CONTEXT_MASK) + this_cpu_or(printk_context, PRINTK_NMI_DIRECT_CONTEXT_MASK); +} + +void printk_nmi_direct_exit(void) +{ + this_cpu_and(printk_context, ~PRINTK_NMI_DIRECT_CONTEXT_MASK); } #else @@ -363,6 +372,20 @@ void __printk_safe_exit(void) __printf(1, 0) int vprintk_func(const char *fmt, va_list args) { + /* + * Try to use the main logbuf even in NMI. But avoid calling console + * drivers that might have their own locks. + */ + if ((this_cpu_read(printk_context) & PRINTK_NMI_DIRECT_CONTEXT_MASK) && + raw_spin_trylock(&logbuf_lock)) { + int len; + + len = vprintk_store(0, LOGLEVEL_DEFAULT, NULL, 0, fmt, args); + raw_spin_unlock(&logbuf_lock); + defer_console_output(); + return len; + } + /* Use extra buffer in NMI when logbuf_lock is taken or in safe mode. */ if (this_cpu_read(printk_context) & PRINTK_NMI_CONTEXT_MASK) return vprintk_nmi(fmt, args); @@ -371,13 +394,6 @@ __printf(1, 0) int vprintk_func(const char *fmt, va_list args) if (this_cpu_read(printk_context) & PRINTK_SAFE_CONTEXT_MASK) return vprintk_safe(fmt, args); - /* - * Use the main logbuf when logbuf_lock is available in NMI. - * But avoid calling console drivers that might have their own locks. - */ - if (this_cpu_read(printk_context) & PRINTK_NMI_DEFERRED_CONTEXT_MASK) - return vprintk_deferred(fmt, args); - /* No obstacles. */ return vprintk_default(fmt, args); } diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c index bcd93031d042..f106ad12f72f 100644 --- a/kernel/trace/trace.c +++ b/kernel/trace/trace.c @@ -8265,6 +8265,7 @@ void ftrace_dump(enum ftrace_dump_mode oops_dump_mode) tracing_off(); local_irq_save(flags); + printk_nmi_direct_enter(); /* Simulate the iterator */ trace_init_global_iter(&iter); @@ -8344,7 +8345,8 @@ void ftrace_dump(enum ftrace_dump_mode oops_dump_mode) for_each_tracing_cpu(cpu) { atomic_dec(&per_cpu_ptr(iter.trace_buffer->data, cpu)->disabled); } - atomic_dec(&dump_running); + atomic_dec(&dump_running); + printk_nmi_direct_exit(); local_irq_restore(flags); } EXPORT_SYMBOL_GPL(ftrace_dump); diff --git a/lib/nmi_backtrace.c b/lib/nmi_backtrace.c index 61a6b5aab07e..15ca78e1c7d4 100644 --- a/lib/nmi_backtrace.c +++ b/lib/nmi_backtrace.c @@ -87,11 +87,9 @@ void nmi_trigger_cpumask_backtrace(const cpumask_t *mask, bool nmi_cpu_backtrace(struct pt_regs *regs) { - static arch_spinlock_t lock = __ARCH_SPIN_LOCK_UNLOCKED; int cpu = smp_processor_id(); if (cpumask_test_cpu(cpu, to_cpumask(backtrace_mask))) { - arch_spin_lock(&lock); if (regs && cpu_in_idle(instruction_pointer(regs))) { pr_warn("NMI backtrace for cpu %d skipped: idling at %pS\n", cpu, (void *)instruction_pointer(regs)); @@ -102,7 +100,6 @@ bool nmi_cpu_backtrace(struct pt_regs *regs) else dump_stack(); } - arch_spin_unlock(&lock); cpumask_clear_cpu(cpu, to_cpumask(backtrace_mask)); return true; } -- cgit v1.2.3 From 554ec508653688c21d9b8024af73a1ffaa0164b9 Mon Sep 17 00:00:00 2001 From: Bart Van Assche Date: Mon, 6 Aug 2018 15:34:21 -0700 Subject: lib/vsprintf: Do not handle %pO[^F] as %px This patch avoids that gcc reports the following when building with W=1: lib/vsprintf.c:1941:3: warning: this statement may fall through [-Wimplicit-fallthrough=] switch (fmt[1]) { ^~~~~~ Fixes: 7b1924a1d930eb2 ("vsprintf: add printk specifier %px") Link: http://lkml.kernel.org/r/20180806223421.11995-1-bart.vanassche@wdc.com Cc: linux-kernel@vger.kernel.org Cc: Bart Van Assche Cc: Pantelis Antoniou Cc: Joe Perches Cc: Rob Herring Cc: v4.15+ Signed-off-by: Bart Van Assche Signed-off-by: Petr Mladek --- lib/vsprintf.c | 1 + 1 file changed, 1 insertion(+) (limited to 'lib') diff --git a/lib/vsprintf.c b/lib/vsprintf.c index a48aaa79d352..cda186230287 100644 --- a/lib/vsprintf.c +++ b/lib/vsprintf.c @@ -1942,6 +1942,7 @@ char *pointer(const char *fmt, char *buf, char *end, void *ptr, case 'F': return device_node_string(buf, end, ptr, spec, fmt + 1); } + break; case 'x': return pointer_string(buf, end, ptr, spec); } -- cgit v1.2.3