Merge tag 'printk-for-5.15' of git://git.kernel.org/pub/scm/linux/kernel/git/printk...
authorLinus Torvalds <torvalds@linux-foundation.org>
Thu, 2 Sep 2021 01:41:13 +0000 (18:41 -0700)
committerLinus Torvalds <torvalds@linux-foundation.org>
Thu, 2 Sep 2021 01:41:13 +0000 (18:41 -0700)
Pull printk updates from Petr Mladek:

 - Optionally, provide an index of possible printk messages via
   <debugfs>/printk/index/. It can be used when monitoring important
   kernel messages on a farm of various hosts. The monitor has to be
   updated when some messages has changed or are not longer available by
   a newly deployed kernel.

 - Add printk.console_no_auto_verbose boot parameter. It allows to
   generate crash dump even with slow consoles in a reasonable time
   frame.

 - Remove printk_safe buffers. The messages are always stored directly
   to the main logbuffer, even in NMI or recursive context. Also it
   allows to serialize syslog operations by a mutex instead of a spin
   lock.

 - Misc clean up and build fixes.

* tag 'printk-for-5.15' of git://git.kernel.org/pub/scm/linux/kernel/git/printk/linux:
  printk/index: Fix -Wunused-function warning
  lib/nmi_backtrace: Serialize even messages about idle CPUs
  printk: Add printk.console_no_auto_verbose boot parameter
  printk: Remove console_silent()
  lib/test_scanf: Handle n_bits == 0 in random tests
  printk: syslog: close window between wait and read
  printk: convert @syslog_lock to mutex
  printk: remove NMI tracking
  printk: remove safe buffers
  printk: track/limit recursion
  lib/nmi_backtrace: explicitly serialize banner and regs
  printk: Move the printk() kerneldoc comment to its new home
  printk/index: Fix warning about missing prototypes
  MIPS/asm/printk: Fix build failure caused by printk
  printk: index: Add indexing support to dev_printk
  printk: Userspace format indexing support
  printk: Rework parse_prefix into printk_parse_prefix
  printk: Straighten out log_flags into printk_info_flags
  string_helpers: Escape double quotes in escape_special
  printk/console: Check consistent sequence number when handling race in console_unlock()

38 files changed:
Documentation/admin-guide/kernel-parameters.txt
Documentation/core-api/printk-basics.rst
MAINTAINERS
arch/arm/kernel/entry-v7m.S
arch/arm/kernel/smp.c
arch/arm/lib/backtrace-clang.S
arch/arm/lib/backtrace.S
arch/arm/mach-rpc/io-acorn.S
arch/arm/vfp/vfphw.S
arch/ia64/include/uapi/asm/cmpxchg.h
arch/mips/include/asm/asm.h
arch/openrisc/kernel/entry.S
arch/powerpc/kernel/head_fsl_booke.S
arch/powerpc/kernel/traps.c
arch/powerpc/kernel/watchdog.c
arch/powerpc/kexec/crash.c
arch/um/include/shared/user.h
arch/x86/kernel/head_32.S
drivers/base/core.c
include/asm-generic/vmlinux.lds.h
include/linux/dev_printk.h
include/linux/hardirq.h
include/linux/module.h
include/linux/printk.h
init/Kconfig
kernel/kexec_core.c
kernel/module.c
kernel/panic.c
kernel/printk/Makefile
kernel/printk/index.c [new file with mode: 0644]
kernel/printk/internal.h
kernel/printk/printk.c
kernel/printk/printk_safe.c
kernel/trace/trace.c
lib/nmi_backtrace.c
lib/string_helpers.c
lib/test-string_helpers.c
lib/test_scanf.c

index 82c9321..84dc579 100644 (file)
                        Format: <bool>  (1/Y/y=enable, 0/N/n=disable)
                        default: disabled
 
+       printk.console_no_auto_verbose=
+                       Disable console loglevel raise on oops, panic
+                       or lockdep-detected issues (only if lock debug is on).
+                       With an exception to setups with low baudrate on
+                       serial console, keeping this 0 is a good choice
+                       in order to provide more debug information.
+                       Format: <bool>
+                       default: 0 (auto_verbose is enabled)
+
        printk.devkmsg={on,off,ratelimit}
                        Control writing to /dev/kmsg.
                        on - unlimited logging to /dev/kmsg from userspace
index 965e428..2dde24c 100644 (file)
@@ -107,9 +107,6 @@ also ``CONFIG_DYNAMIC_DEBUG`` in the case of pr_debug()) is defined.
 Function reference
 ==================
 
-.. kernel-doc:: kernel/printk/printk.c
-   :functions: printk
-
 .. kernel-doc:: include/linux/printk.h
-   :functions: pr_emerg pr_alert pr_crit pr_err pr_warn pr_notice pr_info
+   :functions: printk pr_emerg pr_alert pr_crit pr_err pr_warn pr_notice pr_info
       pr_fmt pr_debug pr_devel pr_cont
index 63bddf7..0d4b896 100644 (file)
@@ -15021,6 +15021,11 @@ S:     Maintained
 F:     include/linux/printk.h
 F:     kernel/printk/
 
+PRINTK INDEXING
+R:     Chris Down <chris@chrisdown.name>
+S:     Maintained
+F:     kernel/printk/index.c
+
 PROC FILESYSTEM
 L:     linux-kernel@vger.kernel.org
 L:     linux-fsdevel@vger.kernel.org
index d0e8986..7bde93c 100644 (file)
@@ -23,7 +23,7 @@ __invalid_entry:
        adr     r0, strerr
        mrs     r1, ipsr
        mov     r2, lr
-       bl      printk
+       bl      _printk
 #endif
        mov     r0, sp
        bl      show_regs
index c7bb168..842427f 100644 (file)
@@ -667,9 +667,9 @@ static void do_handle_IPI(int ipinr)
                break;
 
        case IPI_CPU_BACKTRACE:
-               printk_nmi_enter();
+               printk_deferred_enter();
                nmi_cpu_backtrace(get_irq_regs());
-               printk_nmi_exit();
+               printk_deferred_exit();
                break;
 
        default:
index 6174c45..5b2cdb1 100644 (file)
@@ -202,7 +202,7 @@ finished_setup:
 1006:          adr     r0, .Lbad
                mov     r1, loglvl
                mov     r2, frame
-               bl      printk
+               bl      _printk
 no_frame:      ldmfd   sp!, {r4 - r9, fp, pc}
 ENDPROC(c_backtrace)
                .pushsection __ex_table,"a"
index 872f658..e8408f2 100644 (file)
@@ -103,7 +103,7 @@ for_each_frame:     tst     frame, mask             @ Check for address exceptions
 1006:          adr     r0, .Lbad
                mov     r1, loglvl
                mov     r2, frame
-               bl      printk
+               bl      _printk
 no_frame:      ldmfd   sp!, {r4 - r9, pc}
 ENDPROC(c_backtrace)
                
index b9082a2..aa9bf0d 100644 (file)
@@ -25,4 +25,4 @@ ENTRY(insl)
 ENTRY(outsl)
                adr     r0, .Liosl_warning
                mov     r1, lr
-               b       printk
+               b       _printk
index d5837bf..6f7926c 100644 (file)
@@ -23,7 +23,7 @@
 #ifdef DEBUG
        stmfd   sp!, {r0-r3, ip, lr}
        ldr     r0, =1f
-       bl      printk
+       bl      _printk
        ldmfd   sp!, {r0-r3, ip, lr}
 
        .pushsection .rodata, "a"
@@ -38,7 +38,7 @@
        stmfd   sp!, {r0-r3, ip, lr}
        mov     r1, \arg
        ldr     r0, =1f
-       bl      printk
+       bl      _printk
        ldmfd   sp!, {r0-r3, ip, lr}
 
        .pushsection .rodata, "a"
@@ -55,7 +55,7 @@
        mov     r2, \arg2
        mov     r1, \arg1
        ldr     r0, =1f
-       bl      printk
+       bl      _printk
        ldmfd   sp!, {r0-r3, ip, lr}
 
        .pushsection .rodata, "a"
index 926c6cb..2c2f3cf 100644 (file)
@@ -143,9 +143,9 @@ extern long ia64_cmpxchg_called_with_bad_pointer(void);
 do {                                                                   \
        if (_cmpxchg_bugcheck_count-- <= 0) {                           \
                void *ip;                                               \
-               extern int printk(const char *fmt, ...);                \
+               extern int _printk(const char *fmt, ...);               \
                ip = (void *) ia64_getreg(_IA64_REG_IP);                \
-               printk("CMPXCHG_BUGCHECK: stuck at %p on word %p\n", ip, (v));\
+               _printk("CMPXCHG_BUGCHECK: stuck at %p on word %p\n", ip, (v));\
                break;                                                  \
        }                                                               \
 } while (0)
index ea4b62e..2f8ce94 100644 (file)
@@ -114,7 +114,7 @@ symbol              =       value
                .set    push;                           \
                .set    reorder;                        \
                PTR_LA  a0, 8f;                         \
-               jal     printk;                         \
+               jal     _printk;                        \
                .set    pop;                            \
                TEXT(string)
 #else
index bc657e5..947613f 100644 (file)
@@ -551,7 +551,7 @@ EXCEPTION_ENTRY(_external_irq_handler)
        l.movhi r3,hi(42f)
        l.ori   r3,r3,lo(42f)
        l.sw    0x0(r1),r3
-       l.jal   printk
+       l.jal   _printk
        l.sw    0x4(r1),r4
        l.addi  r1,r1,0x8
 
@@ -681,8 +681,8 @@ _syscall_debug:
        l.sw    -4(r1),r27
        l.sw    -8(r1),r11
        l.addi  r1,r1,-8
-       l.movhi r27,hi(printk)
-       l.ori   r27,r27,lo(printk)
+       l.movhi r27,hi(_printk)
+       l.ori   r27,r27,lo(_printk)
        l.jalr  r27
         l.nop
        l.addi  r1,r1,8
index 0f9642f..9a2f426 100644 (file)
@@ -858,7 +858,7 @@ KernelSPE:
        ori     r3,r3,87f@l
        mr      r4,r2           /* current */
        lwz     r5,_NIP(r1)
-       bl      printk
+       bl      _printk
 #endif
        b       interrupt_return
 #ifdef CONFIG_PRINTK
index d56254f..cd5f633 100644 (file)
@@ -171,7 +171,6 @@ extern void panic_flush_kmsg_start(void)
 
 extern void panic_flush_kmsg_end(void)
 {
-       printk_safe_flush_on_panic();
        kmsg_dump(KMSG_DUMP_PANIC);
        bust_spinlocks(0);
        debug_locks_off();
index a165635..f9ea0e5 100644 (file)
@@ -184,11 +184,6 @@ static void watchdog_smp_panic(int cpu, u64 tb)
 
        wd_smp_unlock(&flags);
 
-       printk_safe_flush();
-       /*
-        * printk_safe_flush() seems to require another print
-        * before anything actually goes out to console.
-        */
        if (sysctl_hardlockup_all_cpu_backtrace)
                trigger_allbutself_cpu_backtrace();
 
index 10f997e..22ceeeb 100644 (file)
@@ -313,7 +313,7 @@ void default_machine_crash_shutdown(struct pt_regs *regs)
        int (*old_handler)(struct pt_regs *regs);
 
        /* Avoid hardlocking with irresponsive CPU holding logbuf_lock */
-       printk_nmi_enter();
+       printk_deferred_enter();
 
        /*
         * This function is only called after the system
index e793e42..dd4badf 100644 (file)
@@ -38,7 +38,8 @@ extern void panic(const char *fmt, ...)
 #define UM_KERN_CONT   KERN_CONT
 
 #ifdef UML_CONFIG_PRINTK
-extern int printk(const char *fmt, ...)
+#define printk(...) _printk(__VA_ARGS__)
+extern int _printk(const char *fmt, ...)
        __attribute__ ((format (printf, 1, 2)));
 #else
 static inline int printk(const char *fmt, ...)
index 67f5904..d8c64da 100644 (file)
@@ -432,7 +432,7 @@ SYM_FUNC_START(early_ignore_irq)
        pushl 32(%esp)
        pushl 40(%esp)
        pushl $int_msg
-       call printk
+       call _printk
 
        call dump_stack
 
index 3a72241..2804254 100644 (file)
@@ -4579,8 +4579,8 @@ static void __dev_printk(const char *level, const struct device *dev,
                printk("%s(NULL device *): %pV", level, vaf);
 }
 
-void dev_printk(const char *level, const struct device *dev,
-               const char *fmt, ...)
+void _dev_printk(const char *level, const struct device *dev,
+                const char *fmt, ...)
 {
        struct va_format vaf;
        va_list args;
@@ -4594,7 +4594,7 @@ void dev_printk(const char *level, const struct device *dev,
 
        va_end(args);
 }
-EXPORT_SYMBOL(dev_printk);
+EXPORT_SYMBOL(_dev_printk);
 
 #define define_dev_printk_level(func, kern_level)              \
 void func(const struct device *dev, const char *fmt, ...)      \
index 62669b3..aa50bf2 100644 (file)
                                                                        \
        TRACEDATA                                                       \
                                                                        \
+       PRINTK_INDEX                                                    \
+                                                                       \
        /* Kernel symbol table: Normal symbols */                       \
        __ksymtab         : AT(ADDR(__ksymtab) - LOAD_OFFSET) {         \
                __start___ksymtab = .;                                  \
 #define TRACEDATA
 #endif
 
+#ifdef CONFIG_PRINTK_INDEX
+#define PRINTK_INDEX                                                   \
+       .printk_index : AT(ADDR(.printk_index) - LOAD_OFFSET) {         \
+               __start_printk_index = .;                               \
+               *(.printk_index)                                        \
+               __stop_printk_index = .;                                \
+       }
+#else
+#define PRINTK_INDEX
+#endif
+
 #define NOTES                                                          \
        .notes : AT(ADDR(.notes) - LOAD_OFFSET) {                       \
                __start_notes = .;                                      \
index 82d3d46..8904063 100644 (file)
@@ -38,8 +38,8 @@ __printf(3, 4) __cold
 int dev_printk_emit(int level, const struct device *dev, const char *fmt, ...);
 
 __printf(3, 4) __cold
-void dev_printk(const char *level, const struct device *dev,
-               const char *fmt, ...);
+void _dev_printk(const char *level, const struct device *dev,
+                const char *fmt, ...);
 __printf(2, 3) __cold
 void _dev_emerg(const struct device *dev, const char *fmt, ...);
 __printf(2, 3) __cold
@@ -69,7 +69,7 @@ static inline void __dev_printk(const char *level, const struct device *dev,
                                struct va_format *vaf)
 {}
 static inline __printf(3, 4)
-void dev_printk(const char *level, const struct device *dev,
+void _dev_printk(const char *level, const struct device *dev,
                 const char *fmt, ...)
 {}
 
@@ -98,24 +98,56 @@ void _dev_info(const struct device *dev, const char *fmt, ...)
 #endif
 
 /*
+ * Need to take variadic arguments even though we don't use them, as dev_fmt()
+ * may only just have been expanded and may result in multiple arguments.
+ */
+#define dev_printk_index_emit(level, fmt, ...) \
+       printk_index_subsys_emit("%s %s: ", level, fmt)
+
+#define dev_printk_index_wrap(_p_func, level, dev, fmt, ...)           \
+       ({                                                              \
+               dev_printk_index_emit(level, fmt);                      \
+               _p_func(dev, fmt, ##__VA_ARGS__);                       \
+       })
+
+/*
+ * Some callsites directly call dev_printk rather than going through the
+ * dev_<level> infrastructure, so we need to emit here as well as inside those
+ * level-specific macros. Only one index entry will be produced, either way,
+ * since dev_printk's `fmt` isn't known at compile time if going through the
+ * dev_<level> macros.
+ *
+ * dev_fmt() isn't called for dev_printk when used directly, as it's used by
+ * the dev_<level> macros internally which already have dev_fmt() processed.
+ *
+ * We also can't use dev_printk_index_wrap directly, because we have a separate
+ * level to process.
+ */
+#define dev_printk(level, dev, fmt, ...)                               \
+       ({                                                              \
+               dev_printk_index_emit(level, fmt);                      \
+               _dev_printk(level, dev, fmt, ##__VA_ARGS__);            \
+       })
+
+/*
  * #defines for all the dev_<level> macros to prefix with whatever
  * possible use of #define dev_fmt(fmt) ...
  */
 
-#define dev_emerg(dev, fmt, ...)                                       \
-       _dev_emerg(dev, dev_fmt(fmt), ##__VA_ARGS__)
-#define dev_crit(dev, fmt, ...)                                                \
-       _dev_crit(dev, dev_fmt(fmt), ##__VA_ARGS__)
-#define dev_alert(dev, fmt, ...)                                       \
-       _dev_alert(dev, dev_fmt(fmt), ##__VA_ARGS__)
-#define dev_err(dev, fmt, ...)                                         \
-       _dev_err(dev, dev_fmt(fmt), ##__VA_ARGS__)
-#define dev_warn(dev, fmt, ...)                                                \
-       _dev_warn(dev, dev_fmt(fmt), ##__VA_ARGS__)
-#define dev_notice(dev, fmt, ...)                                      \
-       _dev_notice(dev, dev_fmt(fmt), ##__VA_ARGS__)
-#define dev_info(dev, fmt, ...)                                                \
-       _dev_info(dev, dev_fmt(fmt), ##__VA_ARGS__)
+#define dev_emerg(dev, fmt, ...) \
+       dev_printk_index_wrap(_dev_emerg, KERN_EMERG, dev, dev_fmt(fmt), ##__VA_ARGS__)
+#define dev_crit(dev, fmt, ...) \
+       dev_printk_index_wrap(_dev_crit, KERN_CRIT, dev, dev_fmt(fmt), ##__VA_ARGS__)
+#define dev_alert(dev, fmt, ...) \
+       dev_printk_index_wrap(_dev_alert, KERN_ALERT, dev, dev_fmt(fmt), ##__VA_ARGS__)
+#define dev_err(dev, fmt, ...) \
+       dev_printk_index_wrap(_dev_err, KERN_ERR, dev, dev_fmt(fmt), ##__VA_ARGS__)
+#define dev_warn(dev, fmt, ...) \
+       dev_printk_index_wrap(_dev_warn, KERN_WARNING, dev, dev_fmt(fmt), ##__VA_ARGS__)
+#define dev_notice(dev, fmt, ...) \
+       dev_printk_index_wrap(_dev_notice, KERN_NOTICE, dev, dev_fmt(fmt), ##__VA_ARGS__)
+#define dev_info(dev, fmt, ...) \
+       dev_printk_index_wrap(_dev_info, KERN_INFO, dev, dev_fmt(fmt), ##__VA_ARGS__)
 
 #if defined(CONFIG_DYNAMIC_DEBUG) || \
        (defined(CONFIG_DYNAMIC_DEBUG_CORE) && defined(DYNAMIC_DEBUG_MODULE))
index 69bc86e..76878b3 100644 (file)
@@ -116,7 +116,6 @@ extern void rcu_nmi_exit(void);
        do {                                                    \
                lockdep_off();                                  \
                arch_nmi_enter();                               \
-               printk_nmi_enter();                             \
                BUG_ON(in_nmi() == NMI_MASK);                   \
                __preempt_count_add(NMI_OFFSET + HARDIRQ_OFFSET);       \
        } while (0)
@@ -135,7 +134,6 @@ extern void rcu_nmi_exit(void);
        do {                                                    \
                BUG_ON(!in_nmi());                              \
                __preempt_count_sub(NMI_OFFSET + HARDIRQ_OFFSET);       \
-               printk_nmi_exit();                              \
                arch_nmi_exit();                                \
                lockdep_on();                                   \
        } while (0)
index 8a298d8..c9f1200 100644 (file)
@@ -511,6 +511,11 @@ struct module {
        struct klp_modinfo *klp_info;
 #endif
 
+#ifdef CONFIG_PRINTK_INDEX
+       unsigned int printk_index_size;
+       struct pi_entry **printk_index_start;
+#endif
+
 #ifdef CONFIG_MODULE_UNLOAD
        /* What modules depend on me? */
        struct list_head source_list;
index e834d78..259af4f 100644 (file)
@@ -70,16 +70,7 @@ extern int console_printk[];
 #define minimum_console_loglevel (console_printk[2])
 #define default_console_loglevel (console_printk[3])
 
-static inline void console_silent(void)
-{
-       console_loglevel = CONSOLE_LOGLEVEL_SILENT;
-}
-
-static inline void console_verbose(void)
-{
-       if (console_loglevel)
-               console_loglevel = CONSOLE_LOGLEVEL_MOTORMOUTH;
-}
+extern void console_verbose(void);
 
 /* strlen("ratelimit") + 1 */
 #define DEVKMSG_STR_MAX_SIZE 10
@@ -150,18 +141,6 @@ static inline __printf(1, 2) __cold
 void early_printk(const char *s, ...) { }
 #endif
 
-#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 */
-
 struct dev_printk_info;
 
 #ifdef CONFIG_PRINTK
@@ -174,12 +153,22 @@ asmlinkage __printf(1, 0)
 int vprintk(const char *fmt, va_list args);
 
 asmlinkage __printf(1, 2) __cold
-int printk(const char *fmt, ...);
+int _printk(const char *fmt, ...);
 
 /*
  * Special printk facility for scheduler/timekeeping use only, _DO_NOT_USE_ !
  */
-__printf(1, 2) __cold int printk_deferred(const char *fmt, ...);
+__printf(1, 2) __cold int _printk_deferred(const char *fmt, ...);
+
+extern void __printk_safe_enter(void);
+extern void __printk_safe_exit(void);
+/*
+ * The printk_deferred_enter/exit macros are available only as a hack for
+ * some code paths that need to defer all printk console printing. Interrupts
+ * must be disabled for the deferred duration.
+ */
+#define printk_deferred_enter __printk_safe_enter
+#define printk_deferred_exit __printk_safe_exit
 
 /*
  * Please don't use printk_ratelimit(), because it shares ratelimiting state
@@ -209,8 +198,6 @@ void dump_stack_print_info(const char *log_lvl);
 void show_regs_print_info(const char *log_lvl);
 extern asmlinkage void dump_stack_lvl(const char *log_lvl) __cold;
 extern asmlinkage void dump_stack(void) __cold;
-extern void printk_safe_flush(void);
-extern void printk_safe_flush_on_panic(void);
 #else
 static inline __printf(1, 0)
 int vprintk(const char *s, va_list args)
@@ -218,15 +205,24 @@ int vprintk(const char *s, va_list args)
        return 0;
 }
 static inline __printf(1, 2) __cold
-int printk(const char *s, ...)
+int _printk(const char *s, ...)
 {
        return 0;
 }
 static inline __printf(1, 2) __cold
-int printk_deferred(const char *s, ...)
+int _printk_deferred(const char *s, ...)
 {
        return 0;
 }
+
+static inline void printk_deferred_enter(void)
+{
+}
+
+static inline void printk_deferred_exit(void)
+{
+}
+
 static inline int printk_ratelimit(void)
 {
        return 0;
@@ -278,14 +274,6 @@ static inline void dump_stack_lvl(const char *log_lvl)
 static inline void dump_stack(void)
 {
 }
-
-static inline void printk_safe_flush(void)
-{
-}
-
-static inline void printk_safe_flush_on_panic(void)
-{
-}
 #endif
 
 #ifdef CONFIG_SMP
@@ -348,6 +336,117 @@ extern int kptr_restrict;
 #define pr_fmt(fmt) fmt
 #endif
 
+struct module;
+
+#ifdef CONFIG_PRINTK_INDEX
+struct pi_entry {
+       const char *fmt;
+       const char *func;
+       const char *file;
+       unsigned int line;
+
+       /*
+        * While printk and pr_* have the level stored in the string at compile
+        * time, some subsystems dynamically add it at runtime through the
+        * format string. For these dynamic cases, we allow the subsystem to
+        * tell us the level at compile time.
+        *
+        * NULL indicates that the level, if any, is stored in fmt.
+        */
+       const char *level;
+
+       /*
+        * The format string used by various subsystem specific printk()
+        * wrappers to prefix the message.
+        *
+        * Note that the static prefix defined by the pr_fmt() macro is stored
+        * directly in the message format (@fmt), not here.
+        */
+       const char *subsys_fmt_prefix;
+} __packed;
+
+#define __printk_index_emit(_fmt, _level, _subsys_fmt_prefix)          \
+       do {                                                            \
+               if (__builtin_constant_p(_fmt) && __builtin_constant_p(_level)) { \
+                       /*
+                        * We check __builtin_constant_p multiple times here
+                        * for the same input because GCC will produce an error
+                        * if we try to assign a static variable to fmt if it
+                        * is not a constant, even with the outer if statement.
+                        */                                             \
+                       static const struct pi_entry _entry             \
+                       __used = {                                      \
+                               .fmt = __builtin_constant_p(_fmt) ? (_fmt) : NULL, \
+                               .func = __func__,                       \
+                               .file = __FILE__,                       \
+                               .line = __LINE__,                       \
+                               .level = __builtin_constant_p(_level) ? (_level) : NULL, \
+                               .subsys_fmt_prefix = _subsys_fmt_prefix,\
+                       };                                              \
+                       static const struct pi_entry *_entry_ptr        \
+                       __used __section(".printk_index") = &_entry;    \
+               }                                                       \
+       } while (0)
+
+#else /* !CONFIG_PRINTK_INDEX */
+#define __printk_index_emit(...) do {} while (0)
+#endif /* CONFIG_PRINTK_INDEX */
+
+/*
+ * Some subsystems have their own custom printk that applies a va_format to a
+ * generic format, for example, to include a device number or other metadata
+ * alongside the format supplied by the caller.
+ *
+ * In order to store these in the way they would be emitted by the printk
+ * infrastructure, the subsystem provides us with the start, fixed string, and
+ * any subsequent text in the format string.
+ *
+ * We take a variable argument list as pr_fmt/dev_fmt/etc are sometimes passed
+ * as multiple arguments (eg: `"%s: ", "blah"`), and we must only take the
+ * first one.
+ *
+ * subsys_fmt_prefix must be known at compile time, or compilation will fail
+ * (since this is a mistake). If fmt or level is not known at compile time, no
+ * index entry will be made (since this can legitimately happen).
+ */
+#define printk_index_subsys_emit(subsys_fmt_prefix, level, fmt, ...) \
+       __printk_index_emit(fmt, level, subsys_fmt_prefix)
+
+#define printk_index_wrap(_p_func, _fmt, ...)                          \
+       ({                                                              \
+               __printk_index_emit(_fmt, NULL, NULL);                  \
+               _p_func(_fmt, ##__VA_ARGS__);                           \
+       })
+
+
+/**
+ * printk - print a kernel message
+ * @fmt: format string
+ *
+ * This is printk(). It can be called from any context. We want it to work.
+ *
+ * If printk indexing is enabled, _printk() is called from printk_index_wrap.
+ * Otherwise, printk is simply #defined to _printk.
+ *
+ * We try to grab the console_lock. If we succeed, it's easy - we log the
+ * output and call the console drivers.  If we fail to get the semaphore, we
+ * place the output into the log buffer and return. The current holder of
+ * the console_sem will notice the new output in console_unlock(); and will
+ * send it to the consoles before releasing the lock.
+ *
+ * One effect of this deferred printing is that code which calls printk() and
+ * then changes console_loglevel may break. This is because console_loglevel
+ * is inspected when the actual printing occurs.
+ *
+ * See also:
+ * printf(3)
+ *
+ * See the vsnprintf() documentation for format string extensions over C99.
+ */
+#define printk(fmt, ...) printk_index_wrap(_printk, fmt, ##__VA_ARGS__)
+#define printk_deferred(fmt, ...)                                      \
+       printk_index_wrap(_printk_deferred, fmt, ##__VA_ARGS__)
+
 /**
  * pr_emerg - Print an emergency-level message
  * @fmt: format string
index 55f9f77..e708180 100644 (file)
@@ -775,6 +775,20 @@ config PRINTK_SAFE_LOG_BUF_SHIFT
                     13 =>   8 KB for each CPU
                     12 =>   4 KB for each CPU
 
+config PRINTK_INDEX
+       bool "Printk indexing debugfs interface"
+       depends on PRINTK && DEBUG_FS
+       help
+         Add support for indexing of all printk formats known at compile time
+         at <debugfs>/printk/index/<module>.
+
+         This can be used as part of maintaining daemons which monitor
+         /dev/kmsg, as it permits auditing the printk formats present in a
+         kernel, allowing detection of cases where monitored printks are
+         changed or no longer present.
+
+         There is no additional runtime cost to printk with this enabled.
+
 #
 # Architectures with an unreliable sched_clock() should select this:
 #
@@ -1509,11 +1523,6 @@ config PRINTK
          very difficult to diagnose system problems, saying N here is
          strongly discouraged.
 
-config PRINTK_NMI
-       def_bool y
-       depends on PRINTK
-       depends on HAVE_NMI
-
 config BUG
        bool "BUG() support" if EXPERT
        default y
index 4b34a9a..5a5d192 100644 (file)
@@ -979,7 +979,6 @@ void crash_kexec(struct pt_regs *regs)
        old_cpu = atomic_cmpxchg(&panic_cpu, PANIC_CPU_INVALID, this_cpu);
        if (old_cpu == PANIC_CPU_INVALID) {
                /* This is the 1st CPU which comes here, so go ahead. */
-               printk_safe_flush_on_panic();
                __crash_kexec(regs);
 
                /*
index ed13917..40ec9a0 100644 (file)
@@ -3355,6 +3355,11 @@ static int find_module_sections(struct module *mod, struct load_info *info)
                                                sizeof(unsigned long),
                                                &mod->num_kprobe_blacklist);
 #endif
+#ifdef CONFIG_PRINTK_INDEX
+       mod->printk_index_start = section_objs(info, ".printk_index",
+                                              sizeof(*mod->printk_index_start),
+                                              &mod->printk_index_size);
+#endif
 #ifdef CONFIG_HAVE_STATIC_CALL_INLINE
        mod->static_call_sites = section_objs(info, ".static_call_sites",
                                              sizeof(*mod->static_call_sites),
index edad896..cefd7d8 100644 (file)
@@ -248,7 +248,6 @@ void panic(const char *fmt, ...)
         * Bypass the panic_cpu check and call __crash_kexec directly.
         */
        if (!_crash_kexec_post_notifiers) {
-               printk_safe_flush_on_panic();
                __crash_kexec(NULL);
 
                /*
@@ -272,8 +271,6 @@ void panic(const char *fmt, ...)
         */
        atomic_notifier_call_chain(&panic_notifier_list, 0, buf);
 
-       /* Call flush even twice. It tries harder with a single online CPU */
-       printk_safe_flush_on_panic();
        kmsg_dump(KMSG_DUMP_PANIC);
 
        /*
index eee3dc9..d118739 100644 (file)
@@ -3,3 +3,4 @@ obj-y   = printk.o
 obj-$(CONFIG_PRINTK)   += printk_safe.o
 obj-$(CONFIG_A11Y_BRAILLE_CONSOLE)     += braille.o
 obj-$(CONFIG_PRINTK)   += printk_ringbuffer.o
+obj-$(CONFIG_PRINTK_INDEX)     += index.o
diff --git a/kernel/printk/index.c b/kernel/printk/index.c
new file mode 100644 (file)
index 0000000..d370940
--- /dev/null
@@ -0,0 +1,195 @@
+// SPDX-License-Identifier: GPL-2.0
+/*
+ * Userspace indexing of printk formats
+ */
+
+#include <linux/debugfs.h>
+#include <linux/module.h>
+#include <linux/printk.h>
+#include <linux/slab.h>
+#include <linux/string_helpers.h>
+
+#include "internal.h"
+
+extern struct pi_entry *__start_printk_index[];
+extern struct pi_entry *__stop_printk_index[];
+
+/* The base dir for module formats, typically debugfs/printk/index/ */
+static struct dentry *dfs_index;
+
+static struct pi_entry *pi_get_entry(const struct module *mod, loff_t pos)
+{
+       struct pi_entry **entries;
+       unsigned int nr_entries;
+
+#ifdef CONFIG_MODULES
+       if (mod) {
+               entries = mod->printk_index_start;
+               nr_entries = mod->printk_index_size;
+       }
+#endif
+
+       if (!mod) {
+               /* vmlinux, comes from linker symbols */
+               entries = __start_printk_index;
+               nr_entries = __stop_printk_index - __start_printk_index;
+       }
+
+       if (pos >= nr_entries)
+               return NULL;
+
+       return entries[pos];
+}
+
+static void *pi_next(struct seq_file *s, void *v, loff_t *pos)
+{
+       const struct module *mod = s->file->f_inode->i_private;
+       struct pi_entry *entry = pi_get_entry(mod, *pos);
+
+       (*pos)++;
+
+       return entry;
+}
+
+static void *pi_start(struct seq_file *s, loff_t *pos)
+{
+       /*
+        * Make show() print the header line. Do not update *pos because
+        * pi_next() still has to return the entry at index 0 later.
+        */
+       if (*pos == 0)
+               return SEQ_START_TOKEN;
+
+       return pi_next(s, NULL, pos);
+}
+
+/*
+ * We need both ESCAPE_ANY and explicit characters from ESCAPE_SPECIAL in @only
+ * because otherwise ESCAPE_NAP will cause double quotes and backslashes to be
+ * ignored for quoting.
+ */
+#define seq_escape_printf_format(s, src) \
+       seq_escape_str(s, src, ESCAPE_ANY | ESCAPE_NAP | ESCAPE_APPEND, "\"\\")
+
+static int pi_show(struct seq_file *s, void *v)
+{
+       const struct pi_entry *entry = v;
+       int level = LOGLEVEL_DEFAULT;
+       enum printk_info_flags flags = 0;
+       u16 prefix_len = 0;
+
+       if (v == SEQ_START_TOKEN) {
+               seq_puts(s, "# <level/flags> filename:line function \"format\"\n");
+               return 0;
+       }
+
+       if (!entry->fmt)
+               return 0;
+
+       if (entry->level)
+               printk_parse_prefix(entry->level, &level, &flags);
+       else
+               prefix_len = printk_parse_prefix(entry->fmt, &level, &flags);
+
+
+       if (flags & LOG_CONT) {
+               /*
+                * LOGLEVEL_DEFAULT here means "use the same level as the
+                * message we're continuing from", not the default message
+                * loglevel, so don't display it as such.
+                */
+               if (level == LOGLEVEL_DEFAULT)
+                       seq_puts(s, "<c>");
+               else
+                       seq_printf(s, "<%d,c>", level);
+       } else
+               seq_printf(s, "<%d>", level);
+
+       seq_printf(s, " %s:%d %s \"", entry->file, entry->line, entry->func);
+       if (entry->subsys_fmt_prefix)
+               seq_escape_printf_format(s, entry->subsys_fmt_prefix);
+       seq_escape_printf_format(s, entry->fmt + prefix_len);
+       seq_puts(s, "\"\n");
+
+       return 0;
+}
+
+static void pi_stop(struct seq_file *p, void *v) { }
+
+static const struct seq_operations dfs_index_sops = {
+       .start = pi_start,
+       .next  = pi_next,
+       .show  = pi_show,
+       .stop  = pi_stop,
+};
+
+DEFINE_SEQ_ATTRIBUTE(dfs_index);
+
+#ifdef CONFIG_MODULES
+static const char *pi_get_module_name(struct module *mod)
+{
+       return mod ? mod->name : "vmlinux";
+}
+#else
+static const char *pi_get_module_name(struct module *mod)
+{
+       return "vmlinux";
+}
+#endif
+
+static void pi_create_file(struct module *mod)
+{
+       debugfs_create_file(pi_get_module_name(mod), 0444, dfs_index,
+                                      mod, &dfs_index_fops);
+}
+
+#ifdef CONFIG_MODULES
+static void pi_remove_file(struct module *mod)
+{
+       debugfs_remove(debugfs_lookup(pi_get_module_name(mod), dfs_index));
+}
+
+static int pi_module_notify(struct notifier_block *nb, unsigned long op,
+                           void *data)
+{
+       struct module *mod = data;
+
+       switch (op) {
+       case MODULE_STATE_COMING:
+               pi_create_file(mod);
+               break;
+       case MODULE_STATE_GOING:
+               pi_remove_file(mod);
+               break;
+       default: /* we don't care about other module states */
+               break;
+       }
+
+       return NOTIFY_OK;
+}
+
+static struct notifier_block module_printk_fmts_nb = {
+       .notifier_call = pi_module_notify,
+};
+
+static void __init pi_setup_module_notifier(void)
+{
+       register_module_notifier(&module_printk_fmts_nb);
+}
+#else
+static inline void __init pi_setup_module_notifier(void) { }
+#endif
+
+static int __init pi_init(void)
+{
+       struct dentry *dfs_root = debugfs_create_dir("printk", NULL);
+
+       dfs_index = debugfs_create_dir("index", dfs_root);
+       pi_setup_module_notifier();
+       pi_create_file(NULL);
+
+       return 0;
+}
+
+/* debugfs comes up on core and must be initialised first */
+postcore_initcall(pi_init);
index 51615c9..9f3ed2f 100644 (file)
@@ -6,11 +6,11 @@
 
 #ifdef CONFIG_PRINTK
 
-#define PRINTK_SAFE_CONTEXT_MASK       0x007ffffff
-#define PRINTK_NMI_DIRECT_CONTEXT_MASK 0x008000000
-#define PRINTK_NMI_CONTEXT_MASK                0xff0000000
-
-#define PRINTK_NMI_CONTEXT_OFFSET      0x010000000
+/* Flags for a single printk record. */
+enum printk_info_flags {
+       LOG_NEWLINE     = 2,    /* text ended with a newline */
+       LOG_CONT        = 8,    /* text is a fragment of a continuation line */
+};
 
 __printf(4, 0)
 int vprintk_store(int facility, int level,
@@ -19,10 +19,7 @@ int vprintk_store(int facility, int level,
 
 __printf(1, 0) int vprintk_default(const char *fmt, va_list args);
 __printf(1, 0) int vprintk_deferred(const char *fmt, va_list args);
-void __printk_safe_enter(void);
-void __printk_safe_exit(void);
 
-void printk_safe_init(void);
 bool printk_percpu_data_ready(void);
 
 #define printk_safe_enter_irqsave(flags)       \
@@ -37,20 +34,10 @@ bool printk_percpu_data_ready(void);
                local_irq_restore(flags);       \
        } while (0)
 
-#define printk_safe_enter_irq()                \
-       do {                                    \
-               local_irq_disable();            \
-               __printk_safe_enter();          \
-       } while (0)
-
-#define printk_safe_exit_irq()                 \
-       do {                                    \
-               __printk_safe_exit();           \
-               local_irq_enable();             \
-       } while (0)
-
 void defer_console_output(void);
 
+u16 printk_parse_prefix(const char *text, int *level,
+                       enum printk_info_flags *flags);
 #else
 
 /*
@@ -61,9 +48,5 @@ void defer_console_output(void);
 #define printk_safe_enter_irqsave(flags) local_irq_save(flags)
 #define printk_safe_exit_irqrestore(flags) local_irq_restore(flags)
 
-#define printk_safe_enter_irq() local_irq_disable()
-#define printk_safe_exit_irq() local_irq_enable()
-
-static inline void printk_safe_init(void) { }
 static inline bool printk_percpu_data_ready(void) { return false; }
 #endif /* CONFIG_PRINTK */
index 142a58d..825277e 100644 (file)
@@ -350,13 +350,8 @@ static int console_msg_format = MSG_FORMAT_DEFAULT;
  * non-prinatable characters are escaped in the "\xff" notation.
  */
 
-enum log_flags {
-       LOG_NEWLINE     = 2,    /* text ended with a newline */
-       LOG_CONT        = 8,    /* text is a fragment of a continuation line */
-};
-
 /* syslog_lock protects syslog_* variables and write access to clear_seq. */
-static DEFINE_RAW_SPINLOCK(syslog_lock);
+static DEFINE_MUTEX(syslog_lock);
 
 #ifdef CONFIG_PRINTK
 DECLARE_WAIT_QUEUE_HEAD(log_wait);
@@ -732,27 +727,22 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
        if (ret)
                return ret;
 
-       printk_safe_enter_irq();
        if (!prb_read_valid(prb, atomic64_read(&user->seq), r)) {
                if (file->f_flags & O_NONBLOCK) {
                        ret = -EAGAIN;
-                       printk_safe_exit_irq();
                        goto out;
                }
 
-               printk_safe_exit_irq();
                ret = wait_event_interruptible(log_wait,
                                prb_read_valid(prb, atomic64_read(&user->seq), r));
                if (ret)
                        goto out;
-               printk_safe_enter_irq();
        }
 
        if (r->info->seq != atomic64_read(&user->seq)) {
                /* our last seen message is gone, return error and reset */
                atomic64_set(&user->seq, r->info->seq);
                ret = -EPIPE;
-               printk_safe_exit_irq();
                goto out;
        }
 
@@ -762,7 +752,6 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
                                  &r->info->dev_info);
 
        atomic64_set(&user->seq, r->info->seq + 1);
-       printk_safe_exit_irq();
 
        if (len > count) {
                ret = -EINVAL;
@@ -797,7 +786,6 @@ static loff_t devkmsg_llseek(struct file *file, loff_t offset, int whence)
        if (offset)
                return -ESPIPE;
 
-       printk_safe_enter_irq();
        switch (whence) {
        case SEEK_SET:
                /* the first record */
@@ -818,7 +806,6 @@ static loff_t devkmsg_llseek(struct file *file, loff_t offset, int whence)
        default:
                ret = -EINVAL;
        }
-       printk_safe_exit_irq();
        return ret;
 }
 
@@ -833,7 +820,6 @@ static __poll_t devkmsg_poll(struct file *file, poll_table *wait)
 
        poll_wait(file, &log_wait, wait);
 
-       printk_safe_enter_irq();
        if (prb_read_valid_info(prb, atomic64_read(&user->seq), &info, NULL)) {
                /* return error when data has vanished underneath us */
                if (info.seq != atomic64_read(&user->seq))
@@ -841,7 +827,6 @@ static __poll_t devkmsg_poll(struct file *file, poll_table *wait)
                else
                        ret = EPOLLIN|EPOLLRDNORM;
        }
-       printk_safe_exit_irq();
 
        return ret;
 }
@@ -874,9 +859,7 @@ static int devkmsg_open(struct inode *inode, struct file *file)
        prb_rec_init_rd(&user->record, &user->info,
                        &user->text_buf[0], sizeof(user->text_buf));
 
-       printk_safe_enter_irq();
        atomic64_set(&user->seq, prb_first_valid_seq(prb));
-       printk_safe_exit_irq();
 
        file->private_data = user;
        return 0;
@@ -1042,9 +1025,6 @@ static inline void log_buf_add_cpu(void) {}
 
 static void __init set_percpu_data_ready(void)
 {
-       printk_safe_init();
-       /* Make sure we set this flag only after printk_safe() init is done */
-       barrier();
        __printk_percpu_data_ready = true;
 }
 
@@ -1082,6 +1062,7 @@ void __init setup_log_buf(int early)
        struct prb_desc *new_descs;
        struct printk_info info;
        struct printk_record r;
+       unsigned int text_size;
        size_t new_descs_size;
        size_t new_infos_size;
        unsigned long flags;
@@ -1142,24 +1123,37 @@ void __init setup_log_buf(int early)
                 new_descs, ilog2(new_descs_count),
                 new_infos);
 
-       printk_safe_enter_irqsave(flags);
+       local_irq_save(flags);
 
        log_buf_len = new_log_buf_len;
        log_buf = new_log_buf;
        new_log_buf_len = 0;
 
        free = __LOG_BUF_LEN;
-       prb_for_each_record(0, &printk_rb_static, seq, &r)
-               free -= add_to_rb(&printk_rb_dynamic, &r);
+       prb_for_each_record(0, &printk_rb_static, seq, &r) {
+               text_size = add_to_rb(&printk_rb_dynamic, &r);
+               if (text_size > free)
+                       free = 0;
+               else
+                       free -= text_size;
+       }
 
-       /*
-        * This is early enough that everything is still running on the
-        * boot CPU and interrupts are disabled. So no new messages will
-        * appear during the transition to the dynamic buffer.
-        */
        prb = &printk_rb_dynamic;
 
-       printk_safe_exit_irqrestore(flags);
+       local_irq_restore(flags);
+
+       /*
+        * Copy any remaining messages that might have appeared from
+        * NMI context after copying but before switching to the
+        * dynamic buffer.
+        */
+       prb_for_each_record(seq, &printk_rb_static, seq, &r) {
+               text_size = add_to_rb(&printk_rb_dynamic, &r);
+               if (text_size > free)
+                       free = 0;
+               else
+                       free -= text_size;
+       }
 
        if (seq != prb_next_seq(&printk_rb_static)) {
                pr_err("dropped %llu messages\n",
@@ -1481,12 +1475,14 @@ static u64 find_first_fitting_seq(u64 start_seq, u64 max_seq, size_t size,
        return seq;
 }
 
+/* The caller is responsible for making sure @size is greater than 0. */
 static int syslog_print(char __user *buf, int size)
 {
        struct printk_info info;
        struct printk_record r;
        char *text;
        int len = 0;
+       u64 seq;
 
        text = kmalloc(CONSOLE_LOG_MAX, GFP_KERNEL);
        if (!text)
@@ -1494,17 +1490,35 @@ static int syslog_print(char __user *buf, int size)
 
        prb_rec_init_rd(&r, &info, text, CONSOLE_LOG_MAX);
 
-       while (size > 0) {
+       mutex_lock(&syslog_lock);
+
+       /*
+        * Wait for the @syslog_seq record to be available. @syslog_seq may
+        * change while waiting.
+        */
+       do {
+               seq = syslog_seq;
+
+               mutex_unlock(&syslog_lock);
+               len = wait_event_interruptible(log_wait, prb_read_valid(prb, seq, NULL));
+               mutex_lock(&syslog_lock);
+
+               if (len)
+                       goto out;
+       } while (syslog_seq != seq);
+
+       /*
+        * Copy records that fit into the buffer. The above cycle makes sure
+        * that the first record is always available.
+        */
+       do {
                size_t n;
                size_t skip;
+               int err;
 
-               printk_safe_enter_irq();
-               raw_spin_lock(&syslog_lock);
-               if (!prb_read_valid(prb, syslog_seq, &r)) {
-                       raw_spin_unlock(&syslog_lock);
-                       printk_safe_exit_irq();
+               if (!prb_read_valid(prb, syslog_seq, &r))
                        break;
-               }
+
                if (r.info->seq != syslog_seq) {
                        /* message is gone, move to next valid one */
                        syslog_seq = r.info->seq;
@@ -1531,13 +1545,15 @@ static int syslog_print(char __user *buf, int size)
                        syslog_partial += n;
                } else
                        n = 0;
-               raw_spin_unlock(&syslog_lock);
-               printk_safe_exit_irq();
 
                if (!n)
                        break;
 
-               if (copy_to_user(buf, text + skip, n)) {
+               mutex_unlock(&syslog_lock);
+               err = copy_to_user(buf, text + skip, n);
+               mutex_lock(&syslog_lock);
+
+               if (err) {
                        if (!len)
                                len = -EFAULT;
                        break;
@@ -1546,8 +1562,9 @@ static int syslog_print(char __user *buf, int size)
                len += n;
                size -= n;
                buf += n;
-       }
-
+       } while (size);
+out:
+       mutex_unlock(&syslog_lock);
        kfree(text);
        return len;
 }
@@ -1566,7 +1583,6 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
                return -ENOMEM;
 
        time = printk_time;
-       printk_safe_enter_irq();
        /*
         * Find first record that fits, including all following records,
         * into the user-provided buffer for this dump.
@@ -1587,23 +1603,20 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
                        break;
                }
 
-               printk_safe_exit_irq();
                if (copy_to_user(buf + len, text, textlen))
                        len = -EFAULT;
                else
                        len += textlen;
-               printk_safe_enter_irq();
 
                if (len < 0)
                        break;
        }
 
        if (clear) {
-               raw_spin_lock(&syslog_lock);
+               mutex_lock(&syslog_lock);
                latched_seq_write(&clear_seq, seq);
-               raw_spin_unlock(&syslog_lock);
+               mutex_unlock(&syslog_lock);
        }
-       printk_safe_exit_irq();
 
        kfree(text);
        return len;
@@ -1611,23 +1624,9 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
 
 static void syslog_clear(void)
 {
-       printk_safe_enter_irq();
-       raw_spin_lock(&syslog_lock);
+       mutex_lock(&syslog_lock);
        latched_seq_write(&clear_seq, prb_next_seq(prb));
-       raw_spin_unlock(&syslog_lock);
-       printk_safe_exit_irq();
-}
-
-/* Return a consistent copy of @syslog_seq. */
-static u64 read_syslog_seq_irq(void)
-{
-       u64 seq;
-
-       raw_spin_lock_irq(&syslog_lock);
-       seq = syslog_seq;
-       raw_spin_unlock_irq(&syslog_lock);
-
-       return seq;
+       mutex_unlock(&syslog_lock);
 }
 
 int do_syslog(int type, char __user *buf, int len, int source)
@@ -1653,11 +1652,6 @@ int do_syslog(int type, char __user *buf, int len, int source)
                        return 0;
                if (!access_ok(buf, len))
                        return -EFAULT;
-
-               error = wait_event_interruptible(log_wait,
-                               prb_read_valid(prb, read_syslog_seq_irq(), NULL));
-               if (error)
-                       return error;
                error = syslog_print(buf, len);
                break;
        /* Read/clear last kernel messages */
@@ -1703,12 +1697,10 @@ int do_syslog(int type, char __user *buf, int len, int source)
                break;
        /* Number of chars in the log buffer */
        case SYSLOG_ACTION_SIZE_UNREAD:
-               printk_safe_enter_irq();
-               raw_spin_lock(&syslog_lock);
+               mutex_lock(&syslog_lock);
                if (!prb_read_valid_info(prb, syslog_seq, &info, NULL)) {
                        /* No unread messages. */
-                       raw_spin_unlock(&syslog_lock);
-                       printk_safe_exit_irq();
+                       mutex_unlock(&syslog_lock);
                        return 0;
                }
                if (info.seq != syslog_seq) {
@@ -1736,8 +1728,7 @@ int do_syslog(int type, char __user *buf, int len, int source)
                        }
                        error -= syslog_partial;
                }
-               raw_spin_unlock(&syslog_lock);
-               printk_safe_exit_irq();
+               mutex_unlock(&syslog_lock);
                break;
        /* Size of the log buffer */
        case SYSLOG_ACTION_SIZE_BUFFER:
@@ -1940,6 +1931,76 @@ static void call_console_drivers(const char *ext_text, size_t ext_len,
        }
 }
 
+/*
+ * Recursion is tracked separately on each CPU. If NMIs are supported, an
+ * additional NMI context per CPU is also separately tracked. Until per-CPU
+ * is available, a separate "early tracking" is performed.
+ */
+static DEFINE_PER_CPU(u8, printk_count);
+static u8 printk_count_early;
+#ifdef CONFIG_HAVE_NMI
+static DEFINE_PER_CPU(u8, printk_count_nmi);
+static u8 printk_count_nmi_early;
+#endif
+
+/*
+ * Recursion is limited to keep the output sane. printk() should not require
+ * more than 1 level of recursion (allowing, for example, printk() to trigger
+ * a WARN), but a higher value is used in case some printk-internal errors
+ * exist, such as the ringbuffer validation checks failing.
+ */
+#define PRINTK_MAX_RECURSION 3
+
+/*
+ * Return a pointer to the dedicated counter for the CPU+context of the
+ * caller.
+ */
+static u8 *__printk_recursion_counter(void)
+{
+#ifdef CONFIG_HAVE_NMI
+       if (in_nmi()) {
+               if (printk_percpu_data_ready())
+                       return this_cpu_ptr(&printk_count_nmi);
+               return &printk_count_nmi_early;
+       }
+#endif
+       if (printk_percpu_data_ready())
+               return this_cpu_ptr(&printk_count);
+       return &printk_count_early;
+}
+
+/*
+ * Enter recursion tracking. Interrupts are disabled to simplify tracking.
+ * The caller must check the boolean return value to see if the recursion is
+ * allowed. On failure, interrupts are not disabled.
+ *
+ * @recursion_ptr must be a variable of type (u8 *) and is the same variable
+ * that is passed to printk_exit_irqrestore().
+ */
+#define printk_enter_irqsave(recursion_ptr, flags)     \
+({                                                     \
+       bool success = true;                            \
+                                                       \
+       typecheck(u8 *, recursion_ptr);                 \
+       local_irq_save(flags);                          \
+       (recursion_ptr) = __printk_recursion_counter(); \
+       if (*(recursion_ptr) > PRINTK_MAX_RECURSION) {  \
+               local_irq_restore(flags);               \
+               success = false;                        \
+       } else {                                        \
+               (*(recursion_ptr))++;                   \
+       }                                               \
+       success;                                        \
+})
+
+/* Exit recursion tracking, restoring interrupts. */
+#define printk_exit_irqrestore(recursion_ptr, flags)   \
+       do {                                            \
+               typecheck(u8 *, recursion_ptr);         \
+               (*(recursion_ptr))--;                   \
+               local_irq_restore(flags);               \
+       } while (0)
+
 int printk_delay_msec __read_mostly;
 
 static inline void printk_delay(void)
@@ -1961,23 +2022,24 @@ static inline u32 printk_caller_id(void)
 }
 
 /**
- * parse_prefix - Parse level and control flags.
+ * printk_parse_prefix - Parse level and control flags.
  *
  * @text:     The terminated text message.
  * @level:    A pointer to the current level value, will be updated.
- * @lflags:   A pointer to the current log flags, will be updated.
+ * @flags:    A pointer to the current printk_info flags, will be updated.
  *
  * @level may be NULL if the caller is not interested in the parsed value.
  * Otherwise the variable pointed to by @level must be set to
  * LOGLEVEL_DEFAULT in order to be updated with the parsed value.
  *
- * @lflags may be NULL if the caller is not interested in the parsed value.
- * Otherwise the variable pointed to by @lflags will be OR'd with the parsed
+ * @flags may be NULL if the caller is not interested in the parsed value.
+ * Otherwise the variable pointed to by @flags will be OR'd with the parsed
  * value.
  *
  * Return: The length of the parsed level and control flags.
  */
-static u16 parse_prefix(char *text, int *level, enum log_flags *lflags)
+u16 printk_parse_prefix(const char *text, int *level,
+                       enum printk_info_flags *flags)
 {
        u16 prefix_len = 0;
        int kern_level;
@@ -1993,8 +2055,8 @@ static u16 parse_prefix(char *text, int *level, enum log_flags *lflags)
                                *level = kern_level - '0';
                        break;
                case 'c':       /* KERN_CONT */
-                       if (lflags)
-                               *lflags |= LOG_CONT;
+                       if (flags)
+                               *flags |= LOG_CONT;
                }
 
                prefix_len += 2;
@@ -2004,8 +2066,9 @@ static u16 parse_prefix(char *text, int *level, enum log_flags *lflags)
        return prefix_len;
 }
 
-static u16 printk_sprint(char *text, u16 size, int facility, enum log_flags *lflags,
-                        const char *fmt, va_list args)
+static u16 printk_sprint(char *text, u16 size, int facility,
+                        enum printk_info_flags *flags, const char *fmt,
+                        va_list args)
 {
        u16 text_len;
 
@@ -2014,14 +2077,14 @@ static u16 printk_sprint(char *text, u16 size, int facility, enum log_flags *lfl
        /* Mark and strip a trailing newline. */
        if (text_len && text[text_len - 1] == '\n') {
                text_len--;
-               *lflags |= LOG_NEWLINE;
+               *flags |= LOG_NEWLINE;
        }
 
        /* Strip log level and control flags. */
        if (facility == 0) {
                u16 prefix_len;
 
-               prefix_len = parse_prefix(text, NULL, NULL);
+               prefix_len = printk_parse_prefix(text, NULL, NULL);
                if (prefix_len) {
                        text_len -= prefix_len;
                        memmove(text, text + prefix_len, text_len);
@@ -2038,13 +2101,16 @@ int vprintk_store(int facility, int level,
 {
        const u32 caller_id = printk_caller_id();
        struct prb_reserved_entry e;
-       enum log_flags lflags = 0;
+       enum printk_info_flags flags = 0;
        struct printk_record r;
+       unsigned long irqflags;
        u16 trunc_msg_len = 0;
        char prefix_buf[8];
+       u8 *recursion_ptr;
        u16 reserve_size;
        va_list args2;
        u16 text_len;
+       int ret = 0;
        u64 ts_nsec;
 
        /*
@@ -2055,6 +2121,9 @@ int vprintk_store(int facility, int level,
         */
        ts_nsec = local_clock();
 
+       if (!printk_enter_irqsave(recursion_ptr, irqflags))
+               return 0;
+
        /*
         * The sprintf needs to come first since the syslog prefix might be
         * passed in as a parameter. An extra byte must be reserved so that
@@ -2070,29 +2139,30 @@ int vprintk_store(int facility, int level,
 
        /* Extract log level or control flags. */
        if (facility == 0)
-               parse_prefix(&prefix_buf[0], &level, &lflags);
+               printk_parse_prefix(&prefix_buf[0], &level, &flags);
 
        if (level == LOGLEVEL_DEFAULT)
                level = default_message_loglevel;
 
        if (dev_info)
-               lflags |= LOG_NEWLINE;
+               flags |= LOG_NEWLINE;
 
-       if (lflags & LOG_CONT) {
+       if (flags & LOG_CONT) {
                prb_rec_init_wr(&r, reserve_size);
                if (prb_reserve_in_last(&e, prb, &r, caller_id, LOG_LINE_MAX)) {
                        text_len = printk_sprint(&r.text_buf[r.info->text_len], reserve_size,
-                                                facility, &lflags, fmt, args);
+                                                facility, &flags, fmt, args);
                        r.info->text_len += text_len;
 
-                       if (lflags & LOG_NEWLINE) {
+                       if (flags & LOG_NEWLINE) {
                                r.info->flags |= LOG_NEWLINE;
                                prb_final_commit(&e);
                        } else {
                                prb_commit(&e);
                        }
 
-                       return text_len;
+                       ret = text_len;
+                       goto out;
                }
        }
 
@@ -2108,29 +2178,32 @@ int vprintk_store(int facility, int level,
 
                prb_rec_init_wr(&r, reserve_size + trunc_msg_len);
                if (!prb_reserve(&e, prb, &r))
-                       return 0;
+                       goto out;
        }
 
        /* fill message */
-       text_len = printk_sprint(&r.text_buf[0], reserve_size, facility, &lflags, fmt, args);
+       text_len = printk_sprint(&r.text_buf[0], reserve_size, facility, &flags, fmt, args);
        if (trunc_msg_len)
                memcpy(&r.text_buf[text_len], trunc_msg, trunc_msg_len);
        r.info->text_len = text_len + trunc_msg_len;
        r.info->facility = facility;
        r.info->level = level & 7;
-       r.info->flags = lflags & 0x1f;
+       r.info->flags = flags & 0x1f;
        r.info->ts_nsec = ts_nsec;
        r.info->caller_id = caller_id;
        if (dev_info)
                memcpy(&r.info->dev_info, dev_info, sizeof(r.info->dev_info));
 
        /* A message without a trailing newline can be continued. */
-       if (!(lflags & LOG_NEWLINE))
+       if (!(flags & LOG_NEWLINE))
                prb_commit(&e);
        else
                prb_final_commit(&e);
 
-       return (text_len + trunc_msg_len);
+       ret = text_len + trunc_msg_len;
+out:
+       printk_exit_irqrestore(recursion_ptr, irqflags);
+       return ret;
 }
 
 asmlinkage int vprintk_emit(int facility, int level,
@@ -2139,7 +2212,6 @@ asmlinkage int vprintk_emit(int facility, int level,
 {
        int printed_len;
        bool in_sched = false;
-       unsigned long flags;
 
        /* Suppress unimportant messages after panic happens */
        if (unlikely(suppress_printk))
@@ -2153,9 +2225,7 @@ asmlinkage int vprintk_emit(int facility, int level,
        boot_delay_msec(level);
        printk_delay();
 
-       printk_safe_enter_irqsave(flags);
        printed_len = vprintk_store(facility, level, dev_info, fmt, args);
-       printk_safe_exit_irqrestore(flags);
 
        /* If called from the scheduler, we can not call up(). */
        if (!in_sched) {
@@ -2186,28 +2256,7 @@ int vprintk_default(const char *fmt, va_list args)
 }
 EXPORT_SYMBOL_GPL(vprintk_default);
 
-/**
- * printk - print a kernel message
- * @fmt: format string
- *
- * This is printk(). It can be called from any context. We want it to work.
- *
- * We try to grab the console_lock. If we succeed, it's easy - we log the
- * output and call the console drivers.  If we fail to get the semaphore, we
- * place the output into the log buffer and return. The current holder of
- * the console_sem will notice the new output in console_unlock(); and will
- * send it to the consoles before releasing the lock.
- *
- * One effect of this deferred printing is that code which calls printk() and
- * then changes console_loglevel may break. This is because console_loglevel
- * is inspected when the actual printing occurs.
- *
- * See also:
- * printf(3)
- *
- * See the vsnprintf() documentation for format string extensions over C99.
- */
-asmlinkage __visible int printk(const char *fmt, ...)
+asmlinkage __visible int _printk(const char *fmt, ...)
 {
        va_list args;
        int r;
@@ -2218,7 +2267,7 @@ asmlinkage __visible int printk(const char *fmt, ...)
 
        return r;
 }
-EXPORT_SYMBOL(printk);
+EXPORT_SYMBOL(_printk);
 
 #else /* CONFIG_PRINTK */
 
@@ -2404,6 +2453,18 @@ module_param_named(console_suspend, console_suspend_enabled,
 MODULE_PARM_DESC(console_suspend, "suspend console during suspend"
        " and hibernate operations");
 
+static bool printk_console_no_auto_verbose;
+
+void console_verbose(void)
+{
+       if (console_loglevel && !printk_console_no_auto_verbose)
+               console_loglevel = CONSOLE_LOGLEVEL_MOTORMOUTH;
+}
+EXPORT_SYMBOL_GPL(console_verbose);
+
+module_param_named(console_no_auto_verbose, printk_console_no_auto_verbose, bool, 0644);
+MODULE_PARM_DESC(console_no_auto_verbose, "Disable console loglevel raise to highest on oops/panic/etc");
+
 /**
  * suspend_console - suspend the console subsystem
  *
@@ -2545,6 +2606,7 @@ void console_unlock(void)
        bool do_cond_resched, retry;
        struct printk_info info;
        struct printk_record r;
+       u64 __maybe_unused next_seq;
 
        if (console_suspended) {
                up_console_sem();
@@ -2584,9 +2646,9 @@ again:
 
        for (;;) {
                size_t ext_len = 0;
+               int handover;
                size_t len;
 
-               printk_safe_enter_irqsave(flags);
 skip:
                if (!prb_read_valid(prb, console_seq, &r))
                        break;
@@ -2636,26 +2698,31 @@ skip:
                 * were to occur on another CPU, it may wait for this one to
                 * finish. This task can not be preempted if there is a
                 * waiter waiting to take over.
+                *
+                * Interrupts are disabled because the hand over to a waiter
+                * must not be interrupted until the hand over is completed
+                * (@console_waiter is cleared).
                 */
+               printk_safe_enter_irqsave(flags);
                console_lock_spinning_enable();
 
                stop_critical_timings();        /* don't trace print latency */
                call_console_drivers(ext_text, ext_len, text, len);
                start_critical_timings();
 
-               if (console_lock_spinning_disable_and_check()) {
-                       printk_safe_exit_irqrestore(flags);
-                       return;
-               }
-
+               handover = console_lock_spinning_disable_and_check();
                printk_safe_exit_irqrestore(flags);
+               if (handover)
+                       return;
 
                if (do_cond_resched)
                        cond_resched();
        }
 
-       console_locked = 0;
+       /* Get consistent value of the next-to-be-used sequence number. */
+       next_seq = console_seq;
 
+       console_locked = 0;
        up_console_sem();
 
        /*
@@ -2664,9 +2731,7 @@ skip:
         * there's a new owner and the console_unlock() from them will do the
         * flush, no worries.
         */
-       retry = prb_read_valid(prb, console_seq, NULL);
-       printk_safe_exit_irqrestore(flags);
-
+       retry = prb_read_valid(prb, next_seq, NULL);
        if (retry && console_trylock())
                goto again;
 }
@@ -2728,13 +2793,8 @@ void console_flush_on_panic(enum con_flush_mode mode)
        console_trylock();
        console_may_schedule = 0;
 
-       if (mode == CONSOLE_REPLAY_ALL) {
-               unsigned long flags;
-
-               printk_safe_enter_irqsave(flags);
+       if (mode == CONSOLE_REPLAY_ALL)
                console_seq = prb_first_valid_seq(prb);
-               printk_safe_exit_irqrestore(flags);
-       }
        console_unlock();
 }
 
@@ -2869,7 +2929,6 @@ static int try_enable_new_console(struct console *newcon, bool user_specified)
  */
 void register_console(struct console *newcon)
 {
-       unsigned long flags;
        struct console *bcon = NULL;
        int err;
 
@@ -2974,9 +3033,9 @@ void register_console(struct console *newcon)
                exclusive_console_stop_seq = console_seq;
 
                /* Get a consistent copy of @syslog_seq. */
-               raw_spin_lock_irqsave(&syslog_lock, flags);
+               mutex_lock(&syslog_lock);
                console_seq = syslog_seq;
-               raw_spin_unlock_irqrestore(&syslog_lock, flags);
+               mutex_unlock(&syslog_lock);
        }
        console_unlock();
        console_sysfs_notify();
@@ -3203,7 +3262,7 @@ int vprintk_deferred(const char *fmt, va_list args)
        return r;
 }
 
-int printk_deferred(const char *fmt, ...)
+int _printk_deferred(const char *fmt, ...)
 {
        va_list args;
        int r;
@@ -3386,14 +3445,12 @@ bool kmsg_dump_get_line(struct kmsg_dump_iter *iter, bool syslog,
        struct printk_info info;
        unsigned int line_count;
        struct printk_record r;
-       unsigned long flags;
        size_t l = 0;
        bool ret = false;
 
        if (iter->cur_seq < min_seq)
                iter->cur_seq = min_seq;
 
-       printk_safe_enter_irqsave(flags);
        prb_rec_init_rd(&r, &info, line, size);
 
        /* Read text or count text lines? */
@@ -3414,7 +3471,6 @@ bool kmsg_dump_get_line(struct kmsg_dump_iter *iter, bool syslog,
        iter->cur_seq = r.info->seq + 1;
        ret = true;
 out:
-       printk_safe_exit_irqrestore(flags);
        if (len)
                *len = l;
        return ret;
@@ -3446,7 +3502,6 @@ bool kmsg_dump_get_buffer(struct kmsg_dump_iter *iter, bool syslog,
        u64 min_seq = latched_seq_read_nolock(&clear_seq);
        struct printk_info info;
        struct printk_record r;
-       unsigned long flags;
        u64 seq;
        u64 next_seq;
        size_t len = 0;
@@ -3459,7 +3514,6 @@ bool kmsg_dump_get_buffer(struct kmsg_dump_iter *iter, bool syslog,
        if (iter->cur_seq < min_seq)
                iter->cur_seq = min_seq;
 
-       printk_safe_enter_irqsave(flags);
        if (prb_read_valid_info(prb, iter->cur_seq, &info, NULL)) {
                if (info.seq != iter->cur_seq) {
                        /* messages are gone, move to first available one */
@@ -3468,10 +3522,8 @@ bool kmsg_dump_get_buffer(struct kmsg_dump_iter *iter, bool syslog,
        }
 
        /* last entry */
-       if (iter->cur_seq >= iter->next_seq) {
-               printk_safe_exit_irqrestore(flags);
+       if (iter->cur_seq >= iter->next_seq)
                goto out;
-       }
 
        /*
         * Find first record that fits, including all following records,
@@ -3503,7 +3555,6 @@ bool kmsg_dump_get_buffer(struct kmsg_dump_iter *iter, bool syslog,
 
        iter->next_seq = next_seq;
        ret = true;
-       printk_safe_exit_irqrestore(flags);
 out:
        if (len_out)
                *len_out = len;
@@ -3521,12 +3572,8 @@ EXPORT_SYMBOL_GPL(kmsg_dump_get_buffer);
  */
 void kmsg_dump_rewind(struct kmsg_dump_iter *iter)
 {
-       unsigned long flags;
-
-       printk_safe_enter_irqsave(flags);
        iter->cur_seq = latched_seq_read_nolock(&clear_seq);
        iter->next_seq = prb_next_seq(prb);
-       printk_safe_exit_irqrestore(flags);
 }
 EXPORT_SYMBOL_GPL(kmsg_dump_rewind);
 
index 9423218..ef0f9a2 100644 (file)
  */
 
 #include <linux/preempt.h>
-#include <linux/spinlock.h>
-#include <linux/debug_locks.h>
 #include <linux/kdb.h>
 #include <linux/smp.h>
 #include <linux/cpumask.h>
-#include <linux/irq_work.h>
 #include <linux/printk.h>
 #include <linux/kprobes.h>
 
 #include "internal.h"
 
-/*
- * In NMI and safe mode, printk() avoids taking locks. Instead,
- * it uses an alternative implementation that temporary stores
- * the strings into a per-CPU buffer. The content of the buffer
- * is later flushed into the main ring buffer via IRQ work.
- *
- * The alternative implementation is chosen transparently
- * by examining current printk() context mask stored in @printk_context
- * per-CPU variable.
- *
- * The implementation allows to flush the strings also from another CPU.
- * There are situations when we want to make sure that all buffers
- * were handled or when IRQs are blocked.
- */
-
-#define SAFE_LOG_BUF_LEN ((1 << CONFIG_PRINTK_SAFE_LOG_BUF_SHIFT) -    \
-                               sizeof(atomic_t) -                      \
-                               sizeof(atomic_t) -                      \
-                               sizeof(struct irq_work))
-
-struct printk_safe_seq_buf {
-       atomic_t                len;    /* length of written data */
-       atomic_t                message_lost;
-       struct irq_work         work;   /* IRQ work that flushes the buffer */
-       unsigned char           buffer[SAFE_LOG_BUF_LEN];
-};
-
-static DEFINE_PER_CPU(struct printk_safe_seq_buf, safe_print_seq);
 static DEFINE_PER_CPU(int, printk_context);
 
-static DEFINE_RAW_SPINLOCK(safe_read_lock);
-
-#ifdef CONFIG_PRINTK_NMI
-static DEFINE_PER_CPU(struct printk_safe_seq_buf, nmi_print_seq);
-#endif
-
-/* Get flushed in a more safe context. */
-static void queue_flush_work(struct printk_safe_seq_buf *s)
-{
-       if (printk_percpu_data_ready())
-               irq_work_queue(&s->work);
-}
-
-/*
- * Add a message to per-CPU context-dependent buffer. NMI and printk-safe
- * have dedicated buffers, because otherwise printk-safe preempted by
- * NMI-printk would have overwritten the NMI messages.
- *
- * The messages are flushed from irq work (or from panic()), possibly,
- * from other CPU, concurrently with printk_safe_log_store(). Should this
- * happen, printk_safe_log_store() will notice the buffer->len mismatch
- * and repeat the write.
- */
-static __printf(2, 0) int printk_safe_log_store(struct printk_safe_seq_buf *s,
-                                               const char *fmt, va_list args)
-{
-       int add;
-       size_t len;
-       va_list ap;
-
-again:
-       len = atomic_read(&s->len);
-
-       /* The trailing '\0' is not counted into len. */
-       if (len >= sizeof(s->buffer) - 1) {
-               atomic_inc(&s->message_lost);
-               queue_flush_work(s);
-               return 0;
-       }
-
-       /*
-        * Make sure that all old data have been read before the buffer
-        * was reset. This is not needed when we just append data.
-        */
-       if (!len)
-               smp_rmb();
-
-       va_copy(ap, args);
-       add = vscnprintf(s->buffer + len, sizeof(s->buffer) - len, fmt, ap);
-       va_end(ap);
-       if (!add)
-               return 0;
-
-       /*
-        * Do it once again if the buffer has been flushed in the meantime.
-        * Note that atomic_cmpxchg() is an implicit memory barrier that
-        * makes sure that the data were written before updating s->len.
-        */
-       if (atomic_cmpxchg(&s->len, len, len + add) != len)
-               goto again;
-
-       queue_flush_work(s);
-       return add;
-}
-
-static inline void printk_safe_flush_line(const char *text, int len)
-{
-       /*
-        * Avoid any console drivers calls from here, because we may be
-        * in NMI or printk_safe context (when in panic). The messages
-        * must go only into the ring buffer at this stage.  Consoles will
-        * get explicitly called later when a crashdump is not generated.
-        */
-       printk_deferred("%.*s", len, text);
-}
-
-/* printk part of the temporary buffer line by line */
-static int printk_safe_flush_buffer(const char *start, size_t len)
-{
-       const char *c, *end;
-       bool header;
-
-       c = start;
-       end = start + len;
-       header = true;
-
-       /* Print line by line. */
-       while (c < end) {
-               if (*c == '\n') {
-                       printk_safe_flush_line(start, c - start + 1);
-                       start = ++c;
-                       header = true;
-                       continue;
-               }
-
-               /* Handle continuous lines or missing new line. */
-               if ((c + 1 < end) && printk_get_level(c)) {
-                       if (header) {
-                               c = printk_skip_level(c);
-                               continue;
-                       }
-
-                       printk_safe_flush_line(start, c - start);
-                       start = c++;
-                       header = true;
-                       continue;
-               }
-
-               header = false;
-               c++;
-       }
-
-       /* Check if there was a partial line. Ignore pure header. */
-       if (start < end && !header) {
-               static const char newline[] = KERN_CONT "\n";
-
-               printk_safe_flush_line(start, end - start);
-               printk_safe_flush_line(newline, strlen(newline));
-       }
-
-       return len;
-}
-
-static void report_message_lost(struct printk_safe_seq_buf *s)
-{
-       int lost = atomic_xchg(&s->message_lost, 0);
-
-       if (lost)
-               printk_deferred("Lost %d message(s)!\n", lost);
-}
-
-/*
- * Flush data from the associated per-CPU buffer. The function
- * can be called either via IRQ work or independently.
- */
-static void __printk_safe_flush(struct irq_work *work)
-{
-       struct printk_safe_seq_buf *s =
-               container_of(work, struct printk_safe_seq_buf, work);
-       unsigned long flags;
-       size_t len;
-       int i;
-
-       /*
-        * The lock has two functions. First, one reader has to flush all
-        * available message to make the lockless synchronization with
-        * writers easier. Second, we do not want to mix messages from
-        * different CPUs. This is especially important when printing
-        * a backtrace.
-        */
-       raw_spin_lock_irqsave(&safe_read_lock, flags);
-
-       i = 0;
-more:
-       len = atomic_read(&s->len);
-
-       /*
-        * This is just a paranoid check that nobody has manipulated
-        * the buffer an unexpected way. If we printed something then
-        * @len must only increase. Also it should never overflow the
-        * buffer size.
-        */
-       if ((i && i >= len) || len > sizeof(s->buffer)) {
-               const char *msg = "printk_safe_flush: internal error\n";
-
-               printk_safe_flush_line(msg, strlen(msg));
-               len = 0;
-       }
-
-       if (!len)
-               goto out; /* Someone else has already flushed the buffer. */
-
-       /* Make sure that data has been written up to the @len */
-       smp_rmb();
-       i += printk_safe_flush_buffer(s->buffer + i, len - i);
-
-       /*
-        * Check that nothing has got added in the meantime and truncate
-        * the buffer. Note that atomic_cmpxchg() is an implicit memory
-        * barrier that makes sure that the data were copied before
-        * updating s->len.
-        */
-       if (atomic_cmpxchg(&s->len, len, 0) != len)
-               goto more;
-
-out:
-       report_message_lost(s);
-       raw_spin_unlock_irqrestore(&safe_read_lock, flags);
-}
-
-/**
- * printk_safe_flush - flush all per-cpu nmi buffers.
- *
- * The buffers are flushed automatically via IRQ work. This function
- * is useful only when someone wants to be sure that all buffers have
- * been flushed at some point.
- */
-void printk_safe_flush(void)
-{
-       int cpu;
-
-       for_each_possible_cpu(cpu) {
-#ifdef CONFIG_PRINTK_NMI
-               __printk_safe_flush(&per_cpu(nmi_print_seq, cpu).work);
-#endif
-               __printk_safe_flush(&per_cpu(safe_print_seq, cpu).work);
-       }
-}
-
-/**
- * printk_safe_flush_on_panic - flush all per-cpu nmi buffers when the system
- *     goes down.
- *
- * Similar to printk_safe_flush() but it can be called even in NMI context when
- * the system goes down. It does the best effort to get NMI messages into
- * the main ring buffer.
- *
- * Note that it could try harder when there is only one CPU online.
- */
-void printk_safe_flush_on_panic(void)
-{
-       /*
-        * Make sure that we could access the safe buffers.
-        * Do not risk a double release when more CPUs are up.
-        */
-       if (raw_spin_is_locked(&safe_read_lock)) {
-               if (num_online_cpus() > 1)
-                       return;
-
-               debug_locks_off();
-               raw_spin_lock_init(&safe_read_lock);
-       }
-
-       printk_safe_flush();
-}
-
-#ifdef CONFIG_PRINTK_NMI
-/*
- * 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.
- */
-static __printf(1, 0) int vprintk_nmi(const char *fmt, va_list args)
-{
-       struct printk_safe_seq_buf *s = this_cpu_ptr(&nmi_print_seq);
-
-       return printk_safe_log_store(s, fmt, args);
-}
-
-void noinstr printk_nmi_enter(void)
-{
-       this_cpu_add(printk_context, PRINTK_NMI_CONTEXT_OFFSET);
-}
-
-void noinstr printk_nmi_exit(void)
-{
-       this_cpu_sub(printk_context, PRINTK_NMI_CONTEXT_OFFSET);
-}
-
-/*
- * 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 store the messages into the main logbuf directly.
- */
-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
-
-static __printf(1, 0) int vprintk_nmi(const char *fmt, va_list args)
-{
-       return 0;
-}
-
-#endif /* CONFIG_PRINTK_NMI */
-
-/*
- * Lock-less printk(), to avoid deadlocks should the printk() recurse
- * into itself. It uses a per-CPU buffer to store the message, just like
- * NMI.
- */
-static __printf(1, 0) int vprintk_safe(const char *fmt, va_list args)
-{
-       struct printk_safe_seq_buf *s = this_cpu_ptr(&safe_print_seq);
-
-       return printk_safe_log_store(s, fmt, args);
-}
-
 /* Can be preempted by NMI. */
 void __printk_safe_enter(void)
 {
@@ -369,46 +38,15 @@ asmlinkage int vprintk(const char *fmt, va_list args)
         * 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)) {
-               unsigned long flags;
+       if (this_cpu_read(printk_context) || in_nmi()) {
                int len;
 
-               printk_safe_enter_irqsave(flags);
                len = vprintk_store(0, LOGLEVEL_DEFAULT, NULL, fmt, args);
-               printk_safe_exit_irqrestore(flags);
                defer_console_output();
                return len;
        }
 
-       /* Use extra buffer in NMI. */
-       if (this_cpu_read(printk_context) & PRINTK_NMI_CONTEXT_MASK)
-               return vprintk_nmi(fmt, args);
-
-       /* Use extra buffer to prevent a recursion deadlock in safe mode. */
-       if (this_cpu_read(printk_context) & PRINTK_SAFE_CONTEXT_MASK)
-               return vprintk_safe(fmt, args);
-
        /* No obstacles. */
        return vprintk_default(fmt, args);
 }
 EXPORT_SYMBOL(vprintk);
-
-void __init printk_safe_init(void)
-{
-       int cpu;
-
-       for_each_possible_cpu(cpu) {
-               struct printk_safe_seq_buf *s;
-
-               s = &per_cpu(safe_print_seq, cpu);
-               init_irq_work(&s->work, __printk_safe_flush);
-
-#ifdef CONFIG_PRINTK_NMI
-               s = &per_cpu(nmi_print_seq, cpu);
-               init_irq_work(&s->work, __printk_safe_flush);
-#endif
-       }
-
-       /* Flush pending messages that did not have scheduled IRQ works. */
-       printk_safe_flush();
-}
index a1adb29..2755534 100644 (file)
@@ -9815,7 +9815,6 @@ 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);
@@ -9897,7 +9896,6 @@ void ftrace_dump(enum ftrace_dump_mode oops_dump_mode)
                atomic_dec(&per_cpu_ptr(iter.array_buffer->data, cpu)->disabled);
        }
        atomic_dec(&dump_running);
-       printk_nmi_direct_exit();
        local_irq_restore(flags);
 }
 EXPORT_SYMBOL_GPL(ftrace_dump);
index 8abe187..f9e8900 100644 (file)
@@ -75,12 +75,6 @@ void nmi_trigger_cpumask_backtrace(const cpumask_t *mask,
                touch_softlockup_watchdog();
        }
 
-       /*
-        * Force flush any remote buffers that might be stuck in IRQ context
-        * and therefore could not run their irq_work.
-        */
-       printk_safe_flush();
-
        clear_bit_unlock(0, &backtrace_flag);
        put_cpu();
 }
@@ -92,8 +86,14 @@ module_param(backtrace_idle, bool, 0644);
 bool nmi_cpu_backtrace(struct pt_regs *regs)
 {
        int cpu = smp_processor_id();
+       unsigned long flags;
 
        if (cpumask_test_cpu(cpu, to_cpumask(backtrace_mask))) {
+               /*
+                * Allow nested NMI backtraces while serializing
+                * against other CPUs.
+                */
+               printk_cpu_lock_irqsave(flags);
                if (!READ_ONCE(backtrace_idle) && regs && cpu_in_idle(instruction_pointer(regs))) {
                        pr_warn("NMI backtrace for cpu %d skipped: idling at %pS\n",
                                cpu, (void *)instruction_pointer(regs));
@@ -104,6 +104,7 @@ bool nmi_cpu_backtrace(struct pt_regs *regs)
                        else
                                dump_stack();
                }
+               printk_cpu_unlock_irqrestore(flags);
                cpumask_clear_cpu(cpu, to_cpumask(backtrace_mask));
                return true;
        }
index 5a35c7e..3806a52 100644 (file)
@@ -361,6 +361,9 @@ static bool escape_special(unsigned char c, char **dst, char *end)
        case '\e':
                to = 'e';
                break;
+       case '"':
+               to = '"';
+               break;
        default:
                return false;
        }
@@ -474,6 +477,7 @@ static bool escape_hex(unsigned char c, char **dst, char *end)
  *             '\t' - horizontal tab
  *             '\v' - vertical tab
  *     %ESCAPE_SPECIAL:
+ *             '\"' - double quote
  *             '\\' - backslash
  *             '\a' - alert (BEL)
  *             '\e' - escape
index 2185d71..437d8e6 100644 (file)
@@ -140,13 +140,13 @@ static const struct test_string_2 escape0[] __initconst = {{
 },{
        .in = "\\h\\\"\a\e\\",
        .s1 = {{
-               .out = "\\\\h\\\\\"\\a\\e\\\\",
+               .out = "\\\\h\\\\\\\"\\a\\e\\\\",
                .flags = ESCAPE_SPECIAL,
        },{
-               .out = "\\\\\\150\\\\\\042\\a\\e\\\\",
+               .out = "\\\\\\150\\\\\\\"\\a\\e\\\\",
                .flags = ESCAPE_SPECIAL | ESCAPE_OCTAL,
        },{
-               .out = "\\\\\\x68\\\\\\x22\\a\\e\\\\",
+               .out = "\\\\\\x68\\\\\\\"\\a\\e\\\\",
                .flags = ESCAPE_SPECIAL | ESCAPE_HEX,
        },{
                /* terminator */
@@ -157,10 +157,10 @@ static const struct test_string_2 escape0[] __initconst = {{
                .out = "\eb \\C\007\"\x90\\r]",
                .flags = ESCAPE_SPACE,
        },{
-               .out = "\\eb \\\\C\\a\"\x90\r]",
+               .out = "\\eb \\\\C\\a\\\"\x90\r]",
                .flags = ESCAPE_SPECIAL,
        },{
-               .out = "\\eb \\\\C\\a\"\x90\\r]",
+               .out = "\\eb \\\\C\\a\\\"\x90\\r]",
                .flags = ESCAPE_SPACE | ESCAPE_SPECIAL,
        },{
                .out = "\\033\\142\\040\\134\\103\\007\\042\\220\\015\\135",
@@ -169,10 +169,10 @@ static const struct test_string_2 escape0[] __initconst = {{
                .out = "\\033\\142\\040\\134\\103\\007\\042\\220\\r\\135",
                .flags = ESCAPE_SPACE | ESCAPE_OCTAL,
        },{
-               .out = "\\e\\142\\040\\\\\\103\\a\\042\\220\\015\\135",
+               .out = "\\e\\142\\040\\\\\\103\\a\\\"\\220\\015\\135",
                .flags = ESCAPE_SPECIAL | ESCAPE_OCTAL,
        },{
-               .out = "\\e\\142\\040\\\\\\103\\a\\042\\220\\r\\135",
+               .out = "\\e\\142\\040\\\\\\103\\a\\\"\\220\\r\\135",
                .flags = ESCAPE_SPACE | ESCAPE_SPECIAL | ESCAPE_OCTAL,
        },{
                .out = "\eb \\C\007\"\x90\r]",
index 84fe09e..abae888 100644 (file)
@@ -271,7 +271,7 @@ static u32 __init next_test_random(u32 max_bits)
 {
        u32 n_bits = hweight32(prandom_u32_state(&rnd_state)) % (max_bits + 1);
 
-       return prandom_u32_state(&rnd_state) & (UINT_MAX >> (32 - n_bits));
+       return prandom_u32_state(&rnd_state) & GENMASK(n_bits, 0);
 }
 
 static unsigned long long __init next_test_random_ull(void)
@@ -280,7 +280,7 @@ static unsigned long long __init next_test_random_ull(void)
        u32 n_bits = (hweight32(rand1) * 3) % 64;
        u64 val = (u64)prandom_u32_state(&rnd_state) * rand1;
 
-       return val & (ULLONG_MAX >> (64 - n_bits));
+       return val & GENMASK_ULL(n_bits, 0);
 }
 
 #define random_for_type(T)                             \