LKML Archive on lore.kernel.org
help / color / mirror / Atom feed
* [PATCH printk v4 0/6] printk: remove safe buffers
@ 2021-07-15 19:33 John Ogness
  2021-07-15 19:33 ` [PATCH printk v4 1/6] lib/nmi_backtrace: explicitly serialize banner and regs John Ogness
                   ` (6 more replies)
  0 siblings, 7 replies; 16+ messages in thread
From: John Ogness @ 2021-07-15 19:33 UTC (permalink / raw)
  To: Petr Mladek
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner,
	linux-kernel, Paul E. McKenney, Michael Ellerman,
	Benjamin Herrenschmidt, Paul Mackerras, Eric Biederman,
	Nicholas Piggin, Christophe Leroy, Cédric Le Goater,
	Andrew Morton, Kees Cook, Tiezhu Yang, Alexey Kardashevskiy,
	Yue Hu, linuxppc-dev, kexec, Russell King, Ingo Molnar,
	Marc Zyngier, Valentin Schneider, Geert Uytterhoeven,
	Mike Rapoport, Wolfram Sang (Renesas),
	Anshuman Khandual, Xiongwei Song, Frederic Weisbecker,
	Peter Zijlstra, Masahiro Yamada, Nathan Chancellor,
	Nick Desaulniers, Nick Terrell, Vipin Sharma, Rasmus Villemoes,
	Daniel Borkmann, Vlastimil Babka, linux-arm-kernel

Hi,

Here is v4 of a series to remove the safe buffers. v3 can be
found here [0]. The safe buffers are no longer needed because
messages can be stored directly into the log buffer from any
context.

However, the safe buffers also provided a form of recursion
protection. For that reason, explicit recursion protection is
implemented for this series.

The safe buffers also implicitly provided serialization
between multiple CPUs executing in NMI context. This was
particularly necessary for the nmi_backtrace() output. This
serializiation is now preserved by using the printk cpulock.

With the removal of the safe buffers, there is no need for
extra NMI enter/exit tracking. So this is also removed
(which includes removing the config option CONFIG_PRINTK_NMI).

And finally, there are a few places in the kernel that need to
specify code blocks where all printk calls are to be deferred
printing. Previously the NMI tracking API was being (mis)used
for this purpose. This series introduces an official and
explicit interface for such cases. (Note that all deferred
printing will be removed anyway, once printing kthreads are
introduced.)

Changes since v3:

- Remove safe context tracking in vprintk().

- Add safe context tracking for @console_owner usage since that
  is also a component of the printing code.

- Refactor syslog_print() so that it is easier to understand
  and follow the locking logic.

- Introduce printk_deferred_enter/exit functions to be used by
  code that needs to specify code block where all printk calls
  are to be deferred printing.

John Ogness

[0] https://lore.kernel.org/lkml/20210624111148.5190-1-john.ogness@linutronix.de

John Ogness (6):
  lib/nmi_backtrace: explicitly serialize banner and regs
  printk: track/limit recursion
  printk: remove safe buffers
  printk: remove NMI tracking
  printk: convert @syslog_lock to mutex
  printk: syslog: close window between wait and read

 arch/arm/kernel/smp.c          |   4 +-
 arch/powerpc/kernel/traps.c    |   1 -
 arch/powerpc/kernel/watchdog.c |   5 -
 arch/powerpc/kexec/crash.c     |   2 +-
 include/linux/hardirq.h        |   2 -
 include/linux/printk.h         |  41 ++--
 init/Kconfig                   |   5 -
 kernel/kexec_core.c            |   1 -
 kernel/panic.c                 |   3 -
 kernel/printk/internal.h       |  25 ---
 kernel/printk/printk.c         | 268 ++++++++++++++----------
 kernel/printk/printk_safe.c    | 364 +--------------------------------
 kernel/trace/trace.c           |   4 +-
 lib/nmi_backtrace.c            |  13 +-
 14 files changed, 194 insertions(+), 544 deletions(-)


base-commit: 70333dec446292cd896cd051d2ebd6808b328949
-- 
2.20.1


^ permalink raw reply	[flat|nested] 16+ messages in thread

* [PATCH printk v4 1/6] lib/nmi_backtrace: explicitly serialize banner and regs
  2021-07-15 19:33 [PATCH printk v4 0/6] printk: remove safe buffers John Ogness
@ 2021-07-15 19:33 ` John Ogness
  2021-07-15 19:33 ` [PATCH printk v4 2/6] printk: track/limit recursion John Ogness
                   ` (5 subsequent siblings)
  6 siblings, 0 replies; 16+ messages in thread
From: John Ogness @ 2021-07-15 19:33 UTC (permalink / raw)
  To: Petr Mladek
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner,
	linux-kernel, Paul E. McKenney

Currently the nmi_backtrace is serialized against other CPUs because
the messages are sent to the NMI buffers. Once these buffers are
removed, only the dumped stack will be serialized against other CPUs
(via the printk_cpu_lock).

Also serialize the nmi_backtrace banner and regs using the
printk_cpu_lock so that per-CPU serialization will be preserved even
after the NMI buffers are removed.

Signed-off-by: John Ogness <john.ogness@linutronix.de>
Reviewed-by: Petr Mladek <pmladek@suse.com>
---
 lib/nmi_backtrace.c | 7 +++++++
 1 file changed, 7 insertions(+)

diff --git a/lib/nmi_backtrace.c b/lib/nmi_backtrace.c
index 8abe1870dba4..dae233c5f597 100644
--- a/lib/nmi_backtrace.c
+++ b/lib/nmi_backtrace.c
@@ -92,17 +92,24 @@ 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))) {
 		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));
 		} else {
+			/*
+			 * Allow nested NMI backtraces while serializing
+			 * against other CPUs.
+			 */
+			printk_cpu_lock_irqsave(flags);
 			pr_warn("NMI backtrace for cpu %d\n", cpu);
 			if (regs)
 				show_regs(regs);
 			else
 				dump_stack();
+			printk_cpu_unlock_irqrestore(flags);
 		}
 		cpumask_clear_cpu(cpu, to_cpumask(backtrace_mask));
 		return true;
-- 
2.20.1


^ permalink raw reply	[flat|nested] 16+ messages in thread

* [PATCH printk v4 2/6] printk: track/limit recursion
  2021-07-15 19:33 [PATCH printk v4 0/6] printk: remove safe buffers John Ogness
  2021-07-15 19:33 ` [PATCH printk v4 1/6] lib/nmi_backtrace: explicitly serialize banner and regs John Ogness
@ 2021-07-15 19:33 ` John Ogness
  2021-07-15 19:33 ` [PATCH printk v4 3/6] printk: remove safe buffers John Ogness
                   ` (4 subsequent siblings)
  6 siblings, 0 replies; 16+ messages in thread
From: John Ogness @ 2021-07-15 19:33 UTC (permalink / raw)
  To: Petr Mladek
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner, linux-kernel

Currently the printk safe buffers provide a form of recursion
protection by redirecting to the safe buffers whenever printk() is
recursively called.

In preparation for removal of the safe buffers, provide an alternate
explicit recursion protection. Recursion is limited to 3 levels
per-CPU and per-context.

Signed-off-by: John Ogness <john.ogness@linutronix.de>
Reviewed-by: Petr Mladek <pmladek@suse.com>
---
 kernel/printk/printk.c | 86 ++++++++++++++++++++++++++++++++++++++++--
 1 file changed, 83 insertions(+), 3 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 6dad7da8f383..2f9d783373ed 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1940,6 +1940,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)
@@ -2040,11 +2110,14 @@ int vprintk_store(int facility, int level,
 	struct prb_reserved_entry e;
 	enum log_flags lflags = 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 +2128,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
@@ -2092,7 +2168,8 @@ int vprintk_store(int facility, int level,
 				prb_commit(&e);
 			}
 
-			return text_len;
+			ret = text_len;
+			goto out;
 		}
 	}
 
@@ -2108,7 +2185,7 @@ 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 */
@@ -2130,7 +2207,10 @@ int vprintk_store(int facility, int level,
 	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,
-- 
2.20.1


^ permalink raw reply	[flat|nested] 16+ messages in thread

* [PATCH printk v4 3/6] printk: remove safe buffers
  2021-07-15 19:33 [PATCH printk v4 0/6] printk: remove safe buffers John Ogness
  2021-07-15 19:33 ` [PATCH printk v4 1/6] lib/nmi_backtrace: explicitly serialize banner and regs John Ogness
  2021-07-15 19:33 ` [PATCH printk v4 2/6] printk: track/limit recursion John Ogness
@ 2021-07-15 19:33 ` John Ogness
  2021-07-21 11:25   ` Petr Mladek
  2021-09-02 16:48   ` Geert Uytterhoeven
  2021-07-15 19:33 ` [PATCH printk v4 4/6] printk: remove NMI tracking John Ogness
                   ` (3 subsequent siblings)
  6 siblings, 2 replies; 16+ messages in thread
From: John Ogness @ 2021-07-15 19:33 UTC (permalink / raw)
  To: Petr Mladek
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner,
	linux-kernel, Michael Ellerman, Benjamin Herrenschmidt,
	Paul Mackerras, Eric Biederman, Nicholas Piggin,
	Christophe Leroy, Cédric Le Goater, Andrew Morton,
	Kees Cook, Tiezhu Yang, Alexey Kardashevskiy, Yue Hu,
	Paul E. McKenney, linuxppc-dev, kexec

With @logbuf_lock removed, the high level printk functions for
storing messages are lockless. Messages can be stored from any
context, so there is no need for the NMI and safe buffers anymore.
Remove the NMI and safe buffers.

Although the safe buffers are removed, the NMI and safe context
tracking is still in place. In these contexts, store the message
immediately but still use irq_work to defer the console printing.

Since printk recursion tracking is in place, safe context tracking
for most of printk is not needed. Remove it. Only safe context
tracking relating to the console and console_owner locks is left
in place. This is because the console and console_owner locks are
needed for the actual printing.

Signed-off-by: John Ogness <john.ogness@linutronix.de>
---
 arch/powerpc/kernel/traps.c    |   1 -
 arch/powerpc/kernel/watchdog.c |   5 -
 include/linux/printk.h         |  10 -
 kernel/kexec_core.c            |   1 -
 kernel/panic.c                 |   3 -
 kernel/printk/internal.h       |  17 --
 kernel/printk/printk.c         | 120 +++++-------
 kernel/printk/printk_safe.c    | 335 +--------------------------------
 lib/nmi_backtrace.c            |   6 -
 9 files changed, 48 insertions(+), 450 deletions(-)

diff --git a/arch/powerpc/kernel/traps.c b/arch/powerpc/kernel/traps.c
index b4ab95c9e94a..2522800217d1 100644
--- a/arch/powerpc/kernel/traps.c
+++ b/arch/powerpc/kernel/traps.c
@@ -170,7 +170,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();
diff --git a/arch/powerpc/kernel/watchdog.c b/arch/powerpc/kernel/watchdog.c
index c9a8f4781a10..dc17d8903d4f 100644
--- a/arch/powerpc/kernel/watchdog.c
+++ b/arch/powerpc/kernel/watchdog.c
@@ -183,11 +183,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();
 
diff --git a/include/linux/printk.h b/include/linux/printk.h
index 1790a5521fd9..664612f75dac 100644
--- a/include/linux/printk.h
+++ b/include/linux/printk.h
@@ -207,8 +207,6 @@ __printf(1, 2) void dump_stack_set_arch_desc(const char *fmt, ...);
 void dump_stack_print_info(const char *log_lvl);
 void show_regs_print_info(const char *log_lvl);
 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)
@@ -272,14 +270,6 @@ static inline void show_regs_print_info(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
diff --git a/kernel/kexec_core.c b/kernel/kexec_core.c
index f099baee3578..69c6e9b7761c 100644
--- a/kernel/kexec_core.c
+++ b/kernel/kexec_core.c
@@ -978,7 +978,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);
 
 		/*
diff --git a/kernel/panic.c b/kernel/panic.c
index 332736a72a58..1f0df42f8d0c 100644
--- a/kernel/panic.c
+++ b/kernel/panic.c
@@ -247,7 +247,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);
 
 		/*
@@ -271,8 +270,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);
 
 	/*
diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
index 51615c909b2f..6cc35c5de890 100644
--- a/kernel/printk/internal.h
+++ b/kernel/printk/internal.h
@@ -22,7 +22,6 @@ __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,18 +36,6 @@ 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);
 
 #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 */
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 2f9d783373ed..9693791ab124 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -732,27 +732,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 +757,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 +791,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 +811,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 +825,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 +832,6 @@ static __poll_t devkmsg_poll(struct file *file, poll_table *wait)
 		else
 			ret = EPOLLIN|EPOLLRDNORM;
 	}
-	printk_safe_exit_irq();
 
 	return ret;
 }
@@ -874,9 +864,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 +1030,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 +1067,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 +1128,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",
@@ -1498,11 +1497,9 @@ static int syslog_print(char __user *buf, int size)
 		size_t n;
 		size_t skip;
 
-		printk_safe_enter_irq();
-		raw_spin_lock(&syslog_lock);
+		raw_spin_lock_irq(&syslog_lock);
 		if (!prb_read_valid(prb, syslog_seq, &r)) {
-			raw_spin_unlock(&syslog_lock);
-			printk_safe_exit_irq();
+			raw_spin_unlock_irq(&syslog_lock);
 			break;
 		}
 		if (r.info->seq != syslog_seq) {
@@ -1531,8 +1528,7 @@ static int syslog_print(char __user *buf, int size)
 			syslog_partial += n;
 		} else
 			n = 0;
-		raw_spin_unlock(&syslog_lock);
-		printk_safe_exit_irq();
+		raw_spin_unlock_irq(&syslog_lock);
 
 		if (!n)
 			break;
@@ -1566,7 +1562,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 +1582,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);
+		raw_spin_lock_irq(&syslog_lock);
 		latched_seq_write(&clear_seq, seq);
-		raw_spin_unlock(&syslog_lock);
+		raw_spin_unlock_irq(&syslog_lock);
 	}
-	printk_safe_exit_irq();
 
 	kfree(text);
 	return len;
@@ -1611,11 +1603,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);
+	raw_spin_lock_irq(&syslog_lock);
 	latched_seq_write(&clear_seq, prb_next_seq(prb));
-	raw_spin_unlock(&syslog_lock);
-	printk_safe_exit_irq();
+	raw_spin_unlock_irq(&syslog_lock);
 }
 
 /* Return a consistent copy of @syslog_seq. */
@@ -1703,12 +1693,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);
+		raw_spin_lock_irq(&syslog_lock);
 		if (!prb_read_valid_info(prb, syslog_seq, &info, NULL)) {
 			/* No unread messages. */
-			raw_spin_unlock(&syslog_lock);
-			printk_safe_exit_irq();
+			raw_spin_unlock_irq(&syslog_lock);
 			return 0;
 		}
 		if (info.seq != syslog_seq) {
@@ -1736,8 +1724,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();
+		raw_spin_unlock_irq(&syslog_lock);
 		break;
 	/* Size of the log buffer */
 	case SYSLOG_ACTION_SIZE_BUFFER:
@@ -2219,7 +2206,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))
@@ -2233,9 +2219,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) {
@@ -2665,9 +2649,9 @@ void console_unlock(void)
 
 	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;
@@ -2717,19 +2701,22 @@ void console_unlock(void)
 		 * 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();
@@ -2748,8 +2735,6 @@ void console_unlock(void)
 	 * flush, no worries.
 	 */
 	retry = prb_read_valid(prb, next_seq, NULL);
-	printk_safe_exit_irqrestore(flags);
-
 	if (retry && console_trylock())
 		goto again;
 }
@@ -2811,13 +2796,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();
 }
 
@@ -3469,14 +3449,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? */
@@ -3497,7 +3475,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;
@@ -3529,7 +3506,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;
@@ -3542,7 +3518,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 */
@@ -3551,10 +3526,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,
@@ -3586,7 +3559,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;
@@ -3604,12 +3576,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);
 
diff --git a/kernel/printk/printk_safe.c b/kernel/printk/printk_safe.c
index 94232186fccb..29c580dac93d 100644
--- a/kernel/printk/printk_safe.c
+++ b/kernel/printk/printk_safe.c
@@ -15,286 +15,9 @@
 
 #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);
@@ -309,9 +32,6 @@ void noinstr printk_nmi_exit(void)
  * 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)
 {
@@ -324,27 +44,8 @@ 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 +70,18 @@ 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) &
+	    (PRINTK_NMI_DIRECT_CONTEXT_MASK |
+	     PRINTK_NMI_CONTEXT_MASK |
+	     PRINTK_SAFE_CONTEXT_MASK)) {
 		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();
-}
diff --git a/lib/nmi_backtrace.c b/lib/nmi_backtrace.c
index dae233c5f597..9813a983d024 100644
--- a/lib/nmi_backtrace.c
+++ b/lib/nmi_backtrace.c
@@ -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();
 }
-- 
2.20.1


^ permalink raw reply	[flat|nested] 16+ messages in thread

* [PATCH printk v4 4/6] printk: remove NMI tracking
  2021-07-15 19:33 [PATCH printk v4 0/6] printk: remove safe buffers John Ogness
                   ` (2 preceding siblings ...)
  2021-07-15 19:33 ` [PATCH printk v4 3/6] printk: remove safe buffers John Ogness
@ 2021-07-15 19:33 ` John Ogness
  2021-07-21 12:00   ` Petr Mladek
  2021-07-15 19:33 ` [PATCH printk v4 5/6] printk: convert @syslog_lock to mutex John Ogness
                   ` (2 subsequent siblings)
  6 siblings, 1 reply; 16+ messages in thread
From: John Ogness @ 2021-07-15 19:33 UTC (permalink / raw)
  To: Petr Mladek
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner,
	linux-kernel, Russell King, Michael Ellerman,
	Benjamin Herrenschmidt, Paul Mackerras, Ingo Molnar,
	Marc Zyngier, Valentin Schneider, Geert Uytterhoeven,
	Mike Rapoport, Wolfram Sang (Renesas),
	Anshuman Khandual, Xiongwei Song, Frederic Weisbecker,
	Peter Zijlstra, Masahiro Yamada, Kees Cook, Andrew Morton,
	Nathan Chancellor, Nick Desaulniers, Nick Terrell, Vipin Sharma,
	Rasmus Villemoes, Daniel Borkmann, Vlastimil Babka,
	linux-arm-kernel, linuxppc-dev

All NMI contexts are handled the same as the safe context: store the
message and defer printing. There is no need to have special NMI
context tracking for this. Using in_nmi() is enough.

There are several parts of the kernel that are manually calling into
the printk NMI context tracking in order to cause general printk
deferred printing:

    arch/arm/kernel/smp.c
    arch/powerpc/kexec/crash.c
    kernel/trace/trace.c

For these users, provide a new function pair
printk_deferred_enter/exit that explicitly achieves the same
objective.

Signed-off-by: John Ogness <john.ogness@linutronix.de>
---
 arch/arm/kernel/smp.c       |  4 ++--
 arch/powerpc/kexec/crash.c  |  2 +-
 include/linux/hardirq.h     |  2 --
 include/linux/printk.h      | 31 +++++++++++++++++++------------
 init/Kconfig                |  5 -----
 kernel/printk/internal.h    |  8 --------
 kernel/printk/printk_safe.c | 37 +------------------------------------
 kernel/trace/trace.c        |  4 ++--
 8 files changed, 25 insertions(+), 68 deletions(-)

diff --git a/arch/arm/kernel/smp.c b/arch/arm/kernel/smp.c
index c7bb168b0d97..842427ff2b3c 100644
--- a/arch/arm/kernel/smp.c
+++ b/arch/arm/kernel/smp.c
@@ -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:
diff --git a/arch/powerpc/kexec/crash.c b/arch/powerpc/kexec/crash.c
index 0196d0c211ac..1070378c8e35 100644
--- a/arch/powerpc/kexec/crash.c
+++ b/arch/powerpc/kexec/crash.c
@@ -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
diff --git a/include/linux/hardirq.h b/include/linux/hardirq.h
index 69bc86ea382c..76878b357ffa 100644
--- a/include/linux/hardirq.h
+++ b/include/linux/hardirq.h
@@ -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)
diff --git a/include/linux/printk.h b/include/linux/printk.h
index 664612f75dac..03f7ccedaf18 100644
--- a/include/linux/printk.h
+++ b/include/linux/printk.h
@@ -149,18 +149,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
@@ -180,6 +168,16 @@ int printk(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
  * with all other unrelated printk_ratelimit() callsites.  Instead use
@@ -223,6 +221,15 @@ 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;
diff --git a/init/Kconfig b/init/Kconfig
index a61c92066c2e..9c0510693543 100644
--- a/init/Kconfig
+++ b/init/Kconfig
@@ -1506,11 +1506,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
diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
index 6cc35c5de890..b6d310c72fc9 100644
--- a/kernel/printk/internal.h
+++ b/kernel/printk/internal.h
@@ -6,12 +6,6 @@
 
 #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
-
 __printf(4, 0)
 int vprintk_store(int facility, int level,
 		  const struct dev_printk_info *dev_info,
@@ -19,8 +13,6 @@ 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);
 
 bool printk_percpu_data_ready(void);
 
diff --git a/kernel/printk/printk_safe.c b/kernel/printk/printk_safe.c
index 29c580dac93d..ef0f9a2044da 100644
--- a/kernel/printk/printk_safe.c
+++ b/kernel/printk/printk_safe.c
@@ -4,12 +4,9 @@
  */
 
 #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>
 
@@ -17,35 +14,6 @@
 
 static DEFINE_PER_CPU(int, printk_context);
 
-#ifdef CONFIG_PRINTK_NMI
-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.
- */
-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);
-}
-
-#endif /* CONFIG_PRINTK_NMI */
-
 /* Can be preempted by NMI. */
 void __printk_safe_enter(void)
 {
@@ -70,10 +38,7 @@ 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 |
-	     PRINTK_NMI_CONTEXT_MASK |
-	     PRINTK_SAFE_CONTEXT_MASK)) {
+	if (this_cpu_read(printk_context) || in_nmi()) {
 		int len;
 
 		len = vprintk_store(0, LOGLEVEL_DEFAULT, NULL, fmt, args);
diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index d23a09d3eb37..b30ad20d251f 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -9647,7 +9647,7 @@ void ftrace_dump(enum ftrace_dump_mode oops_dump_mode)
 	tracing_off();
 
 	local_irq_save(flags);
-	printk_nmi_direct_enter();
+	printk_deferred_enter();
 
 	/* Simulate the iterator */
 	trace_init_global_iter(&iter);
@@ -9729,7 +9729,7 @@ 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();
+	printk_deferred_exit();
 	local_irq_restore(flags);
 }
 EXPORT_SYMBOL_GPL(ftrace_dump);
-- 
2.20.1


^ permalink raw reply	[flat|nested] 16+ messages in thread

* [PATCH printk v4 5/6] printk: convert @syslog_lock to mutex
  2021-07-15 19:33 [PATCH printk v4 0/6] printk: remove safe buffers John Ogness
                   ` (3 preceding siblings ...)
  2021-07-15 19:33 ` [PATCH printk v4 4/6] printk: remove NMI tracking John Ogness
@ 2021-07-15 19:33 ` John Ogness
  2021-07-21 12:21   ` Petr Mladek
  2021-07-15 19:33 ` [PATCH printk v4 6/6] printk: syslog: close window between wait and read John Ogness
  2021-07-27  7:26 ` [PATCH printk v4 0/6] printk: remove safe buffers Petr Mladek
  6 siblings, 1 reply; 16+ messages in thread
From: John Ogness @ 2021-07-15 19:33 UTC (permalink / raw)
  To: Petr Mladek
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner, linux-kernel

@syslog_lock was a raw_spin_lock to simplify the transition of
removing @logbuf_lock and the safe buffers. With that transition
complete, and since all uses of @syslog_lock are within sleepable
contexts, @syslog_lock can become a mutex.

Note that until now register_console() would disable interrupts
using irqsave, which implies that it may be called with interrupts
disabled. And indeed, there is one possible call chain on parisc
where this happens:

handle_interruption(code=1) /* High-priority machine check (HPMC) */
  pdc_console_restart()
    pdc_console_init_force()
      register_console()

However, register_console() calls console_lock(), which might sleep.
So it has never been allowed to call register_console() from an
atomic context and the above call chain is a bug.

Note that the removal of read_syslog_seq_irq() is slightly changing
the behavior of SYSLOG_ACTION_READ by testing against a possibly
outdated @seq value. However, the value of @seq could have changed
after the test, so it is not a new window. A follow-up commit closes
this window.

Signed-off-by: John Ogness <john.ogness@linutronix.de>
---
 kernel/printk/printk.c | 49 +++++++++++++++++-------------------------
 1 file changed, 20 insertions(+), 29 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 9693791ab124..99160d0dafd6 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -356,7 +356,7 @@ enum log_flags {
 };
 
 /* 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);
@@ -1497,9 +1497,9 @@ static int syslog_print(char __user *buf, int size)
 		size_t n;
 		size_t skip;
 
-		raw_spin_lock_irq(&syslog_lock);
+		mutex_lock(&syslog_lock);
 		if (!prb_read_valid(prb, syslog_seq, &r)) {
-			raw_spin_unlock_irq(&syslog_lock);
+			mutex_unlock(&syslog_lock);
 			break;
 		}
 		if (r.info->seq != syslog_seq) {
@@ -1528,7 +1528,7 @@ static int syslog_print(char __user *buf, int size)
 			syslog_partial += n;
 		} else
 			n = 0;
-		raw_spin_unlock_irq(&syslog_lock);
+		mutex_unlock(&syslog_lock);
 
 		if (!n)
 			break;
@@ -1592,9 +1592,9 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
 	}
 
 	if (clear) {
-		raw_spin_lock_irq(&syslog_lock);
+		mutex_lock(&syslog_lock);
 		latched_seq_write(&clear_seq, seq);
-		raw_spin_unlock_irq(&syslog_lock);
+		mutex_unlock(&syslog_lock);
 	}
 
 	kfree(text);
@@ -1603,21 +1603,9 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
 
 static void syslog_clear(void)
 {
-	raw_spin_lock_irq(&syslog_lock);
+	mutex_lock(&syslog_lock);
 	latched_seq_write(&clear_seq, prb_next_seq(prb));
-	raw_spin_unlock_irq(&syslog_lock);
-}
-
-/* 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)
@@ -1626,6 +1614,7 @@ int do_syslog(int type, char __user *buf, int len, int source)
 	bool clear = false;
 	static int saved_console_loglevel = LOGLEVEL_DEFAULT;
 	int error;
+	u64 seq;
 
 	error = check_syslog_permissions(type, source);
 	if (error)
@@ -1644,8 +1633,12 @@ int do_syslog(int type, char __user *buf, int len, int source)
 		if (!access_ok(buf, len))
 			return -EFAULT;
 
-		error = wait_event_interruptible(log_wait,
-				prb_read_valid(prb, read_syslog_seq_irq(), NULL));
+		/* Get a consistent copy of @syslog_seq. */
+		mutex_lock(&syslog_lock);
+		seq = syslog_seq;
+		mutex_unlock(&syslog_lock);
+
+		error = wait_event_interruptible(log_wait, prb_read_valid(prb, seq, NULL));
 		if (error)
 			return error;
 		error = syslog_print(buf, len);
@@ -1693,10 +1686,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:
-		raw_spin_lock_irq(&syslog_lock);
+		mutex_lock(&syslog_lock);
 		if (!prb_read_valid_info(prb, syslog_seq, &info, NULL)) {
 			/* No unread messages. */
-			raw_spin_unlock_irq(&syslog_lock);
+			mutex_unlock(&syslog_lock);
 			return 0;
 		}
 		if (info.seq != syslog_seq) {
@@ -1714,7 +1707,6 @@ int do_syslog(int type, char __user *buf, int len, int source)
 		} else {
 			bool time = syslog_partial ? syslog_time : printk_time;
 			unsigned int line_count;
-			u64 seq;
 
 			prb_for_each_info(syslog_seq, prb, seq, &info,
 					  &line_count) {
@@ -1724,7 +1716,7 @@ int do_syslog(int type, char __user *buf, int len, int source)
 			}
 			error -= syslog_partial;
 		}
-		raw_spin_unlock_irq(&syslog_lock);
+		mutex_unlock(&syslog_lock);
 		break;
 	/* Size of the log buffer */
 	case SYSLOG_ACTION_SIZE_BUFFER:
@@ -2932,7 +2924,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;
 
@@ -3037,9 +3028,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();
-- 
2.20.1


^ permalink raw reply	[flat|nested] 16+ messages in thread

* [PATCH printk v4 6/6] printk: syslog: close window between wait and read
  2021-07-15 19:33 [PATCH printk v4 0/6] printk: remove safe buffers John Ogness
                   ` (4 preceding siblings ...)
  2021-07-15 19:33 ` [PATCH printk v4 5/6] printk: convert @syslog_lock to mutex John Ogness
@ 2021-07-15 19:33 ` John Ogness
  2021-07-21 12:43   ` Petr Mladek
  2021-07-27  7:26 ` [PATCH printk v4 0/6] printk: remove safe buffers Petr Mladek
  6 siblings, 1 reply; 16+ messages in thread
From: John Ogness @ 2021-07-15 19:33 UTC (permalink / raw)
  To: Petr Mladek
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner, linux-kernel

Syslog's SYSLOG_ACTION_READ is supposed to block until the next
syslog record can be read, and then it should read that record.
However, because @syslog_lock is not held between waking up and
reading the record, another reader could read the record first,
thus causing SYSLOG_ACTION_READ to return with a value of 0, never
having read _anything_.

By holding @syslog_lock between waking up and reading, it can be
guaranteed that SYSLOG_ACTION_READ blocks until it successfully
reads a syslog record (or a real error occurs).

Signed-off-by: John Ogness <john.ogness@linutronix.de>
---
 kernel/printk/printk.c | 55 +++++++++++++++++++++++++++---------------
 1 file changed, 36 insertions(+), 19 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 99160d0dafd6..d11612687323 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1480,12 +1480,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)
@@ -1493,15 +1495,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;
 
-		mutex_lock(&syslog_lock);
-		if (!prb_read_valid(prb, syslog_seq, &r)) {
-			mutex_unlock(&syslog_lock);
+		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;
@@ -1528,12 +1550,15 @@ static int syslog_print(char __user *buf, int size)
 			syslog_partial += n;
 		} else
 			n = 0;
-		mutex_unlock(&syslog_lock);
 
 		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;
@@ -1542,8 +1567,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;
 }
@@ -1614,7 +1640,6 @@ int do_syslog(int type, char __user *buf, int len, int source)
 	bool clear = false;
 	static int saved_console_loglevel = LOGLEVEL_DEFAULT;
 	int error;
-	u64 seq;
 
 	error = check_syslog_permissions(type, source);
 	if (error)
@@ -1632,15 +1657,6 @@ int do_syslog(int type, char __user *buf, int len, int source)
 			return 0;
 		if (!access_ok(buf, len))
 			return -EFAULT;
-
-		/* Get a consistent copy of @syslog_seq. */
-		mutex_lock(&syslog_lock);
-		seq = syslog_seq;
-		mutex_unlock(&syslog_lock);
-
-		error = wait_event_interruptible(log_wait, prb_read_valid(prb, seq, NULL));
-		if (error)
-			return error;
 		error = syslog_print(buf, len);
 		break;
 	/* Read/clear last kernel messages */
@@ -1707,6 +1723,7 @@ int do_syslog(int type, char __user *buf, int len, int source)
 		} else {
 			bool time = syslog_partial ? syslog_time : printk_time;
 			unsigned int line_count;
+			u64 seq;
 
 			prb_for_each_info(syslog_seq, prb, seq, &info,
 					  &line_count) {
-- 
2.20.1


^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: [PATCH printk v4 3/6] printk: remove safe buffers
  2021-07-15 19:33 ` [PATCH printk v4 3/6] printk: remove safe buffers John Ogness
@ 2021-07-21 11:25   ` Petr Mladek
  2021-09-02 16:48   ` Geert Uytterhoeven
  1 sibling, 0 replies; 16+ messages in thread
From: Petr Mladek @ 2021-07-21 11:25 UTC (permalink / raw)
  To: John Ogness
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner,
	linux-kernel, Michael Ellerman, Benjamin Herrenschmidt,
	Paul Mackerras, Eric Biederman, Nicholas Piggin,
	Christophe Leroy, Cédric Le Goater, Andrew Morton,
	Kees Cook, Tiezhu Yang, Alexey Kardashevskiy, Yue Hu,
	Paul E. McKenney, linuxppc-dev, kexec

On Thu 2021-07-15 21:39:56, John Ogness wrote:
> With @logbuf_lock removed, the high level printk functions for
> storing messages are lockless. Messages can be stored from any
> context, so there is no need for the NMI and safe buffers anymore.
> Remove the NMI and safe buffers.
> 
> Although the safe buffers are removed, the NMI and safe context
> tracking is still in place. In these contexts, store the message
> immediately but still use irq_work to defer the console printing.
> 
> Since printk recursion tracking is in place, safe context tracking
> for most of printk is not needed. Remove it. Only safe context
> tracking relating to the console and console_owner locks is left
> in place. This is because the console and console_owner locks are
> needed for the actual printing.
> 
> Signed-off-by: John Ogness <john.ogness@linutronix.de>

Reviewed-by: Petr Mladek <pmladek@suse.com>

Best Regards,
Petr

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: [PATCH printk v4 4/6] printk: remove NMI tracking
  2021-07-15 19:33 ` [PATCH printk v4 4/6] printk: remove NMI tracking John Ogness
@ 2021-07-21 12:00   ` Petr Mladek
  2021-07-21 12:46     ` John Ogness
  0 siblings, 1 reply; 16+ messages in thread
From: Petr Mladek @ 2021-07-21 12:00 UTC (permalink / raw)
  To: John Ogness
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner,
	linux-kernel, Russell King, Michael Ellerman,
	Benjamin Herrenschmidt, Paul Mackerras, Ingo Molnar,
	Marc Zyngier, Valentin Schneider, Geert Uytterhoeven,
	Mike Rapoport, Wolfram Sang (Renesas),
	Anshuman Khandual, Xiongwei Song, Frederic Weisbecker,
	Peter Zijlstra, Masahiro Yamada, Kees Cook, Andrew Morton,
	Nathan Chancellor, Nick Desaulniers, Nick Terrell, Vipin Sharma,
	Rasmus Villemoes, Daniel Borkmann, Vlastimil Babka,
	linux-arm-kernel, linuxppc-dev

On Thu 2021-07-15 21:39:57, John Ogness wrote:
> All NMI contexts are handled the same as the safe context: store the
> message and defer printing. There is no need to have special NMI
> context tracking for this. Using in_nmi() is enough.
> 
> There are several parts of the kernel that are manually calling into
> the printk NMI context tracking in order to cause general printk
> deferred printing:
> 
>     arch/arm/kernel/smp.c
>     arch/powerpc/kexec/crash.c
>     kernel/trace/trace.c
> 
> For these users, provide a new function pair
> printk_deferred_enter/exit that explicitly achieves the same
> objective.
> 
> Signed-off-by: John Ogness <john.ogness@linutronix.de>
> ---
>  arch/arm/kernel/smp.c       |  4 ++--
>  arch/powerpc/kexec/crash.c  |  2 +-
>  include/linux/hardirq.h     |  2 --
>  include/linux/printk.h      | 31 +++++++++++++++++++------------
>  init/Kconfig                |  5 -----
>  kernel/printk/internal.h    |  8 --------
>  kernel/printk/printk_safe.c | 37 +------------------------------------
>  kernel/trace/trace.c        |  4 ++--
>  8 files changed, 25 insertions(+), 68 deletions(-)
> 
> diff --git a/arch/arm/kernel/smp.c b/arch/arm/kernel/smp.c
> index c7bb168b0d97..842427ff2b3c 100644
> --- a/arch/arm/kernel/smp.c
> +++ b/arch/arm/kernel/smp.c
> @@ -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:
> diff --git a/arch/powerpc/kexec/crash.c b/arch/powerpc/kexec/crash.c
> index 0196d0c211ac..1070378c8e35 100644
> --- a/arch/powerpc/kexec/crash.c
> +++ b/arch/powerpc/kexec/crash.c
> @@ -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
> diff --git a/include/linux/hardirq.h b/include/linux/hardirq.h
> index 69bc86ea382c..76878b357ffa 100644
> --- a/include/linux/hardirq.h
> +++ b/include/linux/hardirq.h
> @@ -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)
> diff --git a/include/linux/printk.h b/include/linux/printk.h
> index 664612f75dac..03f7ccedaf18 100644
> --- a/include/linux/printk.h
> +++ b/include/linux/printk.h
> @@ -149,18 +149,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
> @@ -180,6 +168,16 @@ int printk(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
>   * with all other unrelated printk_ratelimit() callsites.  Instead use
> @@ -223,6 +221,15 @@ 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;
> diff --git a/init/Kconfig b/init/Kconfig
> index a61c92066c2e..9c0510693543 100644
> --- a/init/Kconfig
> +++ b/init/Kconfig
> @@ -1506,11 +1506,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
> diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
> index 6cc35c5de890..b6d310c72fc9 100644
> --- a/kernel/printk/internal.h
> +++ b/kernel/printk/internal.h
> @@ -6,12 +6,6 @@
>  
>  #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
> -
>  __printf(4, 0)
>  int vprintk_store(int facility, int level,
>  		  const struct dev_printk_info *dev_info,
> @@ -19,8 +13,6 @@ 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);
>  
>  bool printk_percpu_data_ready(void);
>  
> diff --git a/kernel/printk/printk_safe.c b/kernel/printk/printk_safe.c
> index 29c580dac93d..ef0f9a2044da 100644
> --- a/kernel/printk/printk_safe.c
> +++ b/kernel/printk/printk_safe.c
> @@ -4,12 +4,9 @@
>   */
>  
>  #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>
>  
> @@ -17,35 +14,6 @@
>  
>  static DEFINE_PER_CPU(int, printk_context);
>  
> -#ifdef CONFIG_PRINTK_NMI
> -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.
> - */
> -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);
> -}
> -
> -#endif /* CONFIG_PRINTK_NMI */
> -
>  /* Can be preempted by NMI. */
>  void __printk_safe_enter(void)
>  {
> @@ -70,10 +38,7 @@ 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 |
> -	     PRINTK_NMI_CONTEXT_MASK |
> -	     PRINTK_SAFE_CONTEXT_MASK)) {
> +	if (this_cpu_read(printk_context) || in_nmi()) {
>  		int len;
>  
>  		len = vprintk_store(0, LOGLEVEL_DEFAULT, NULL, fmt, args);
> diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
> index d23a09d3eb37..b30ad20d251f 100644
> --- a/kernel/trace/trace.c
> +++ b/kernel/trace/trace.c
> @@ -9647,7 +9647,7 @@ void ftrace_dump(enum ftrace_dump_mode oops_dump_mode)
>  	tracing_off();
>  
>  	local_irq_save(flags);
> -	printk_nmi_direct_enter();
> +	printk_deferred_enter();

I would prefer to do not manipulate the printk context here anymore,
as it was done in v3.

printk_nmi_direct_enter() was added here by the commit the commit
03fc7f9c99c1e7ae2925d4 ("printk/nmi: Prevent deadlock when
accessing the main log buffer in NMI"). It was _not_ about console
handling. The reason was to modify the default behavior under NMI
and store the messages directly into the main log buffer.

When I think about it. The original fix was not correct. We should have
modified the context only when ftrace_dump() was really called under NMI:

	if (in_nmi())
		printk_nmi_direct_enter();

By other words. We should try to show the messages on the console
when ftrace_dump()/panic() is not called from NMI. It will help
to see all messages even when the ftrace buffers are bigger
than printk() ones.

And we do not need any special handling here for NMI. vprintk()
in printk/printk_safe.c will do the right thing for us.

Best Regards,
Petr

PS: There is no need to re-send the entire patchset if this was
    the only problem. Feel free to send v4.1 version of this
    patch only.

   That said, I still have to look at 5th and 6th patch.

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: [PATCH printk v4 5/6] printk: convert @syslog_lock to mutex
  2021-07-15 19:33 ` [PATCH printk v4 5/6] printk: convert @syslog_lock to mutex John Ogness
@ 2021-07-21 12:21   ` Petr Mladek
  0 siblings, 0 replies; 16+ messages in thread
From: Petr Mladek @ 2021-07-21 12:21 UTC (permalink / raw)
  To: John Ogness
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner, linux-kernel

On Thu 2021-07-15 21:39:58, John Ogness wrote:
> @syslog_lock was a raw_spin_lock to simplify the transition of
> removing @logbuf_lock and the safe buffers. With that transition
> complete, and since all uses of @syslog_lock are within sleepable
> contexts, @syslog_lock can become a mutex.
> 
> Note that until now register_console() would disable interrupts
> using irqsave, which implies that it may be called with interrupts
> disabled. And indeed, there is one possible call chain on parisc
> where this happens:
> 
> handle_interruption(code=1) /* High-priority machine check (HPMC) */
>   pdc_console_restart()
>     pdc_console_init_force()
>       register_console()
> 
> However, register_console() calls console_lock(), which might sleep.
> So it has never been allowed to call register_console() from an
> atomic context and the above call chain is a bug.
> 
> Note that the removal of read_syslog_seq_irq() is slightly changing
> the behavior of SYSLOG_ACTION_READ by testing against a possibly
> outdated @seq value. However, the value of @seq could have changed
> after the test, so it is not a new window. A follow-up commit closes
> this window.
> 
> Signed-off-by: John Ogness <john.ogness@linutronix.de>

Reviewed-by: Petr Mladek <pmladek@suse.com>

Best Regards,
Petr

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: [PATCH printk v4 6/6] printk: syslog: close window between wait and read
  2021-07-15 19:33 ` [PATCH printk v4 6/6] printk: syslog: close window between wait and read John Ogness
@ 2021-07-21 12:43   ` Petr Mladek
  0 siblings, 0 replies; 16+ messages in thread
From: Petr Mladek @ 2021-07-21 12:43 UTC (permalink / raw)
  To: John Ogness
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner, linux-kernel

On Thu 2021-07-15 21:39:59, John Ogness wrote:
> Syslog's SYSLOG_ACTION_READ is supposed to block until the next
> syslog record can be read, and then it should read that record.
> However, because @syslog_lock is not held between waking up and
> reading the record, another reader could read the record first,
> thus causing SYSLOG_ACTION_READ to return with a value of 0, never
> having read _anything_.
> 
> By holding @syslog_lock between waking up and reading, it can be
> guaranteed that SYSLOG_ACTION_READ blocks until it successfully
> reads a syslog record (or a real error occurs).
> 
> Signed-off-by: John Ogness <john.ogness@linutronix.de>

Reviewed-by: Petr Mladek <pmladek@suse.com>

Best Regards,
Petr

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: [PATCH printk v4 4/6] printk: remove NMI tracking
  2021-07-21 12:00   ` Petr Mladek
@ 2021-07-21 12:46     ` John Ogness
  2021-07-21 13:08       ` Petr Mladek
  0 siblings, 1 reply; 16+ messages in thread
From: John Ogness @ 2021-07-21 12:46 UTC (permalink / raw)
  To: Petr Mladek
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner,
	linux-kernel, Russell King, Michael Ellerman,
	Benjamin Herrenschmidt, Paul Mackerras, Ingo Molnar,
	Marc Zyngier, Valentin Schneider, Geert Uytterhoeven,
	Mike Rapoport, Wolfram Sang (Renesas),
	Anshuman Khandual, Xiongwei Song, Frederic Weisbecker,
	Peter Zijlstra, Masahiro Yamada, Kees Cook, Andrew Morton,
	Nathan Chancellor, Nick Desaulniers, Nick Terrell, Vipin Sharma,
	Rasmus Villemoes, Daniel Borkmann, Vlastimil Babka,
	linux-arm-kernel, linuxppc-dev

On 2021-07-21, Petr Mladek <pmladek@suse.com> wrote:
>> --- a/kernel/trace/trace.c
>> +++ b/kernel/trace/trace.c
>> @@ -9647,7 +9647,7 @@ void ftrace_dump(enum ftrace_dump_mode oops_dump_mode)
>>  	tracing_off();
>>  
>>  	local_irq_save(flags);
>> -	printk_nmi_direct_enter();
>> +	printk_deferred_enter();
>
> I would prefer to do not manipulate the printk context here anymore,
> as it was done in v3.
>
> printk_nmi_direct_enter() was added here by the commit the commit
> 03fc7f9c99c1e7ae2925d4 ("printk/nmi: Prevent deadlock when
> accessing the main log buffer in NMI"). It was _not_ about console
> handling. The reason was to modify the default behavior under NMI
> and store the messages directly into the main log buffer.
>
> When I think about it. The original fix was not correct. We should have
> modified the context only when ftrace_dump() was really called under NMI:
>
> 	if (in_nmi())
> 		printk_nmi_direct_enter();
>
> By other words. We should try to show the messages on the console
> when ftrace_dump()/panic() is not called from NMI. It will help
> to see all messages even when the ftrace buffers are bigger
> than printk() ones.
>
> And we do not need any special handling here for NMI. vprintk()
> in printk/printk_safe.c will do the right thing for us.

Agreed. We need to mention this behavior change in the commit
message. Perhaps this as the commit message:

All NMI contexts are handled the same as the safe context: store the
message and defer printing. There is no need to have special NMI
context tracking for this. Using in_nmi() is enough.

There are several parts of the kernel that are manually calling into
the printk NMI context tracking in order to cause general printk
deferred printing:

    arch/arm/kernel/smp.c
    arch/powerpc/kexec/crash.c
    kernel/trace/trace.c

For arm/kernel/smp.c and powerpc/kexec/crash.c, provide a new
function pair printk_deferred_enter/exit that explicitly achieves the
same objective.

For ftrace, remove general printk deferring. This general deferrment
was added in commit 03fc7f9c99c1 ("printk/nmi: Prevent deadlock when
accessing the main log buffer in NMI"), but really should have only
been deferred when in NMI context. Since vprintk() now checks for
NMI context when deciding to defer, ftrace does not need any special
handling.

Signed-off-by: John Ogness <john.ogness@linutronix.de>

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: [PATCH printk v4 4/6] printk: remove NMI tracking
  2021-07-21 12:46     ` John Ogness
@ 2021-07-21 13:08       ` Petr Mladek
  2021-07-21 13:23         ` John Ogness
  0 siblings, 1 reply; 16+ messages in thread
From: Petr Mladek @ 2021-07-21 13:08 UTC (permalink / raw)
  To: John Ogness
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner,
	linux-kernel, Russell King, Michael Ellerman,
	Benjamin Herrenschmidt, Paul Mackerras, Ingo Molnar,
	Marc Zyngier, Valentin Schneider, Geert Uytterhoeven,
	Mike Rapoport, Wolfram Sang (Renesas),
	Anshuman Khandual, Xiongwei Song, Frederic Weisbecker,
	Peter Zijlstra, Masahiro Yamada, Kees Cook, Andrew Morton,
	Nathan Chancellor, Nick Desaulniers, Nick Terrell, Vipin Sharma,
	Rasmus Villemoes, Daniel Borkmann, Vlastimil Babka,
	linux-arm-kernel, linuxppc-dev

On Wed 2021-07-21 14:52:15, John Ogness wrote:
> On 2021-07-21, Petr Mladek <pmladek@suse.com> wrote:
> >> --- a/kernel/trace/trace.c
> >> +++ b/kernel/trace/trace.c
> >> @@ -9647,7 +9647,7 @@ void ftrace_dump(enum ftrace_dump_mode oops_dump_mode)
> >>  	tracing_off();
> >>  
> >>  	local_irq_save(flags);
> >> -	printk_nmi_direct_enter();
> >> +	printk_deferred_enter();
> >
> > I would prefer to do not manipulate the printk context here anymore,
> > as it was done in v3.
> >
> > printk_nmi_direct_enter() was added here by the commit the commit
> > 03fc7f9c99c1e7ae2925d4 ("printk/nmi: Prevent deadlock when
> > accessing the main log buffer in NMI"). It was _not_ about console
> > handling. The reason was to modify the default behavior under NMI
> > and store the messages directly into the main log buffer.
> >
> > When I think about it. The original fix was not correct. We should have
> > modified the context only when ftrace_dump() was really called under NMI:
> >
> > 	if (in_nmi())
> > 		printk_nmi_direct_enter();
> >
> > By other words. We should try to show the messages on the console
> > when ftrace_dump()/panic() is not called from NMI. It will help
> > to see all messages even when the ftrace buffers are bigger
> > than printk() ones.
> >
> > And we do not need any special handling here for NMI. vprintk()
> > in printk/printk_safe.c will do the right thing for us.
> 
> Agreed. We need to mention this behavior change in the commit
> message. Perhaps this as the commit message:
>
> All NMI contexts are handled the same as the safe context: store the
> message and defer printing. There is no need to have special NMI
> context tracking for this. Using in_nmi() is enough.
> 
> There are several parts of the kernel that are manually calling into
> the printk NMI context tracking in order to cause general printk
> deferred printing:
> 
>     arch/arm/kernel/smp.c
>     arch/powerpc/kexec/crash.c
>     kernel/trace/trace.c
> 
> For arm/kernel/smp.c and powerpc/kexec/crash.c, provide a new
> function pair printk_deferred_enter/exit that explicitly achieves the
> same objective.
> 
> For ftrace, remove general printk deferring. This general deferrment
> was added in commit 03fc7f9c99c1 ("printk/nmi: Prevent deadlock when
> accessing the main log buffer in NMI"), but really should have only
> been deferred when in NMI context. Since vprintk() now checks for
> NMI context when deciding to defer, ftrace does not need any special
> handling.

I would make it less focused on the deferring part and try to explain
the original purpose here, something like:

"For ftrace, remove the printk context manipulation completely. It was
added in commit 03fc7f9c99c1 ("printk/nmi: Prevent deadlock when
accessing the main log buffer in NMI"). The purpose was to enforce
storing messages directly into the ring buffer even in NMI context.
It really should have only modified the behavior in NMI context.
There is no need for a special behavior any longer. All messages are
always stored directly now. The console deferring is handled
transparently in vprintk()."

But I do not resist on it. And feel free to make it shorter.

Best Regards,
Petr

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: [PATCH printk v4 4/6] printk: remove NMI tracking
  2021-07-21 13:08       ` Petr Mladek
@ 2021-07-21 13:23         ` John Ogness
  0 siblings, 0 replies; 16+ messages in thread
From: John Ogness @ 2021-07-21 13:23 UTC (permalink / raw)
  To: Petr Mladek
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner,
	linux-kernel, Russell King, Michael Ellerman,
	Benjamin Herrenschmidt, Paul Mackerras, Ingo Molnar,
	Marc Zyngier, Valentin Schneider, Geert Uytterhoeven,
	Mike Rapoport, Wolfram Sang (Renesas),
	Anshuman Khandual, Xiongwei Song, Frederic Weisbecker,
	Peter Zijlstra, Masahiro Yamada, Kees Cook, Andrew Morton,
	Nathan Chancellor, Nick Desaulniers, Nick Terrell, Vipin Sharma,
	Rasmus Villemoes, Daniel Borkmann, Vlastimil Babka,
	linux-arm-kernel, linuxppc-dev

On 2021-07-21, Petr Mladek <pmladek@suse.com> wrote:
> On Wed 2021-07-21 14:52:15, John Ogness wrote:
>> On 2021-07-21, Petr Mladek <pmladek@suse.com> wrote:
>> >> --- a/kernel/trace/trace.c
>> >> +++ b/kernel/trace/trace.c
>> >> @@ -9647,7 +9647,7 @@ void ftrace_dump(enum ftrace_dump_mode oops_dump_mode)
>> >>  	tracing_off();
>> >>  
>> >>  	local_irq_save(flags);
>> >> -	printk_nmi_direct_enter();
>> >> +	printk_deferred_enter();
>> >
>> > I would prefer to do not manipulate the printk context here anymore,
>> > as it was done in v3.
>> >
>> > printk_nmi_direct_enter() was added here by the commit the commit
>> > 03fc7f9c99c1e7ae2925d4 ("printk/nmi: Prevent deadlock when
>> > accessing the main log buffer in NMI"). It was _not_ about console
>> > handling. The reason was to modify the default behavior under NMI
>> > and store the messages directly into the main log buffer.
>> >
>> > When I think about it. The original fix was not correct. We should have
>> > modified the context only when ftrace_dump() was really called under NMI:
>> >
>> > 	if (in_nmi())
>> > 		printk_nmi_direct_enter();
>> >
>> > By other words. We should try to show the messages on the console
>> > when ftrace_dump()/panic() is not called from NMI. It will help
>> > to see all messages even when the ftrace buffers are bigger
>> > than printk() ones.
>> >
>> > And we do not need any special handling here for NMI. vprintk()
>> > in printk/printk_safe.c will do the right thing for us.
>> 
>> Agreed. We need to mention this behavior change in the commit
>> message. Perhaps this as the commit message:
>>
>> All NMI contexts are handled the same as the safe context: store the
>> message and defer printing. There is no need to have special NMI
>> context tracking for this. Using in_nmi() is enough.
>> 
>> There are several parts of the kernel that are manually calling into
>> the printk NMI context tracking in order to cause general printk
>> deferred printing:
>> 
>>     arch/arm/kernel/smp.c
>>     arch/powerpc/kexec/crash.c
>>     kernel/trace/trace.c
>> 
>> For arm/kernel/smp.c and powerpc/kexec/crash.c, provide a new
>> function pair printk_deferred_enter/exit that explicitly achieves the
>> same objective.
>> 
>> For ftrace, remove general printk deferring. This general deferrment
>> was added in commit 03fc7f9c99c1 ("printk/nmi: Prevent deadlock when
>> accessing the main log buffer in NMI"), but really should have only
>> been deferred when in NMI context. Since vprintk() now checks for
>> NMI context when deciding to defer, ftrace does not need any special
>> handling.
>
> I would make it less focused on the deferring part and try to explain
> the original purpose here, something like:
>
> "For ftrace, remove the printk context manipulation completely. It was
> added in commit 03fc7f9c99c1 ("printk/nmi: Prevent deadlock when
> accessing the main log buffer in NMI"). The purpose was to enforce
> storing messages directly into the ring buffer even in NMI context.
> It really should have only modified the behavior in NMI context.
> There is no need for a special behavior any longer. All messages are
> always stored directly now. The console deferring is handled
> transparently in vprintk()."

Your wording is OK for me.

John Ogness

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: [PATCH printk v4 0/6] printk: remove safe buffers
  2021-07-15 19:33 [PATCH printk v4 0/6] printk: remove safe buffers John Ogness
                   ` (5 preceding siblings ...)
  2021-07-15 19:33 ` [PATCH printk v4 6/6] printk: syslog: close window between wait and read John Ogness
@ 2021-07-27  7:26 ` Petr Mladek
  6 siblings, 0 replies; 16+ messages in thread
From: Petr Mladek @ 2021-07-27  7:26 UTC (permalink / raw)
  To: John Ogness
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner,
	linux-kernel, Paul E. McKenney, Michael Ellerman,
	Benjamin Herrenschmidt, Paul Mackerras, Eric Biederman,
	Nicholas Piggin, Christophe Leroy, Cédric Le Goater,
	Andrew Morton, Kees Cook, Tiezhu Yang, Alexey Kardashevskiy,
	Yue Hu, linuxppc-dev, kexec, Russell King, Ingo Molnar,
	Marc Zyngier, Valentin Schneider, Geert Uytterhoeven,
	Mike Rapoport, Wolfram Sang (Renesas),
	Anshuman Khandual, Xiongwei Song, Frederic Weisbecker,
	Peter Zijlstra, Masahiro Yamada, Nathan Chancellor,
	Nick Desaulniers, Nick Terrell, Vipin Sharma, Rasmus Villemoes,
	Daniel Borkmann, Vlastimil Babka, linux-arm-kernel

On Thu 2021-07-15 21:39:53, John Ogness wrote:
> Hi,
> 
> Here is v4 of a series to remove the safe buffers. v3 can be
> found here [0]. The safe buffers are no longer needed because
> messages can be stored directly into the log buffer from any
> context.
> 
> However, the safe buffers also provided a form of recursion
> protection. For that reason, explicit recursion protection is
> implemented for this series.
> 
> The safe buffers also implicitly provided serialization
> between multiple CPUs executing in NMI context. This was
> particularly necessary for the nmi_backtrace() output. This
> serializiation is now preserved by using the printk cpulock.
> 
> With the removal of the safe buffers, there is no need for
> extra NMI enter/exit tracking. So this is also removed
> (which includes removing the config option CONFIG_PRINTK_NMI).
> 
> And finally, there are a few places in the kernel that need to
> specify code blocks where all printk calls are to be deferred
> printing. Previously the NMI tracking API was being (mis)used
> for this purpose. This series introduces an official and
> explicit interface for such cases. (Note that all deferred
> printing will be removed anyway, once printing kthreads are
> introduced.)
> 
> John Ogness (6):
>   lib/nmi_backtrace: explicitly serialize banner and regs
>   printk: track/limit recursion
>   printk: remove safe buffers
>   printk: remove NMI tracking
>   printk: convert @syslog_lock to mutex
>   printk: syslog: close window between wait and read

The entire patchset has been committed into printk/linux.git,
branch rework/printk_safe-removal.

Note that I have updated the 4th patch as discussed, see
https://lore.kernel.org/r/20210721120026.y3dqno24ahw4sazy@pathway.suse.cz
https://lore.kernel.org/r/20210721130852.zrjnti6b3fwjgdzj@pathway.suse.cz

Best Regards,
Petr

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: [PATCH printk v4 3/6] printk: remove safe buffers
  2021-07-15 19:33 ` [PATCH printk v4 3/6] printk: remove safe buffers John Ogness
  2021-07-21 11:25   ` Petr Mladek
@ 2021-09-02 16:48   ` Geert Uytterhoeven
  1 sibling, 0 replies; 16+ messages in thread
From: Geert Uytterhoeven @ 2021-09-02 16:48 UTC (permalink / raw)
  To: John Ogness
  Cc: Petr Mladek, Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner,
	Linux Kernel Mailing List, Michael Ellerman,
	Benjamin Herrenschmidt, Paul Mackerras, Eric Biederman,
	Nicholas Piggin, Christophe Leroy, Cédric Le Goater,
	Andrew Morton, Kees Cook, Tiezhu Yang, Alexey Kardashevskiy,
	Yue Hu, Paul E. McKenney, linuxppc-dev, kexec

Hi John,

On Thu, Jul 15, 2021 at 9:53 PM John Ogness <john.ogness@linutronix.de> wrote:
> With @logbuf_lock removed, the high level printk functions for
> storing messages are lockless. Messages can be stored from any
> context, so there is no need for the NMI and safe buffers anymore.
> Remove the NMI and safe buffers.
>
> Although the safe buffers are removed, the NMI and safe context
> tracking is still in place. In these contexts, store the message
> immediately but still use irq_work to defer the console printing.
>
> Since printk recursion tracking is in place, safe context tracking
> for most of printk is not needed. Remove it. Only safe context
> tracking relating to the console and console_owner locks is left
> in place. This is because the console and console_owner locks are
> needed for the actual printing.
>
> Signed-off-by: John Ogness <john.ogness@linutronix.de>

Thank you very much for reducing kernel size by ca. 8 KiB!

Gr{oetje,eeting}s,

                        Geert

-- 
Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- geert@linux-m68k.org

In personal conversations with technical people, I call myself a hacker. But
when I'm talking to journalists I just say "programmer" or something like that.
                                -- Linus Torvalds

^ permalink raw reply	[flat|nested] 16+ messages in thread

end of thread, other threads:[~2021-09-02 16:48 UTC | newest]

Thread overview: 16+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2021-07-15 19:33 [PATCH printk v4 0/6] printk: remove safe buffers John Ogness
2021-07-15 19:33 ` [PATCH printk v4 1/6] lib/nmi_backtrace: explicitly serialize banner and regs John Ogness
2021-07-15 19:33 ` [PATCH printk v4 2/6] printk: track/limit recursion John Ogness
2021-07-15 19:33 ` [PATCH printk v4 3/6] printk: remove safe buffers John Ogness
2021-07-21 11:25   ` Petr Mladek
2021-09-02 16:48   ` Geert Uytterhoeven
2021-07-15 19:33 ` [PATCH printk v4 4/6] printk: remove NMI tracking John Ogness
2021-07-21 12:00   ` Petr Mladek
2021-07-21 12:46     ` John Ogness
2021-07-21 13:08       ` Petr Mladek
2021-07-21 13:23         ` John Ogness
2021-07-15 19:33 ` [PATCH printk v4 5/6] printk: convert @syslog_lock to mutex John Ogness
2021-07-21 12:21   ` Petr Mladek
2021-07-15 19:33 ` [PATCH printk v4 6/6] printk: syslog: close window between wait and read John Ogness
2021-07-21 12:43   ` Petr Mladek
2021-07-27  7:26 ` [PATCH printk v4 0/6] printk: remove safe buffers Petr Mladek

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).