[PATCH RFC 0/3] printk: Don't flush messages using write_atomic during console registration if kthreads have not been started yet.

[PATCH RFC 0/3] printk: Don't flush messages using write_atomic during console registration if kthreads have not been started yet.

[Michael Cobb]

Hello all,

When using a legacy console, there is a large amount of time during boot
that is spent printing boot messages to the serial port. I have spent time
looking at nbcon and the potential effects the new interface should have on
boot times. We should expect a significant reduction in boot times as this
work is now offloaded to a dedicated kthread.

With some slight tweaks to the behaviour of nbcon during console
registration, it is possible to reduce boot times significantly.

During initial console registration, we mainly rely on two flags,
`have_nbcon_console` and `printk_kthreads_running`, to handle the glboal
state of nbcon and to determine the appropriate method to handle flushing
messages.

In the case of nbcon, when calling `printk()`, messages are either flushed
by the caller using `write_atomic`, or this work is offloaded to the
console's printk kthread. As can be seen in
`printk_get_console_flush_type()`, under normal (i.e. non-emergency or
panic) priority, we check the value of `printk_kthreads_running` to
determine if nbcon consoles should be flushed via `write_atomic` or not.

When `register_console()` is called to register the first nbcon console
during boot, we know that `printk_kthreads_running` will be false as:
- before the `printk_set_kthreads_ready` initcall, no kthreads have been
  started since `printk_kthreads_ready` will be false.
- after the `printk_set_kthreads_ready` initcall, `printk_kthreads_running`
  will be false since we have not yet registered any nbcon consoles. As we
  are registering an nbcon console, `register_console()` will set
  `have_nbcon_console = true`. At this point, we are now in an intermediate
  state - we have registered an nbcon console but a kthread for it has not
  yet been started.

In effect, this means that any calls made to `printk()` after
`have_nbcon_console` has been set but before
`printk_kthreads_check_locked()` has set `printk_kthreads_running` will use
`write_atomic` on nbcon consoles. As `vprintk_emit()` calls
`nbcon_atomic_flush_pending()` in this situation, we see that the newly
registered console has all boot messages flushed in this manner.

This RFC patch introduces a new flag, `printk_kthreads_pending_start`, to
handle this intermediate state. This flag is set when an nbcon console is
registered and cleared once `printk_kthreads_running` is set to true. We
then check this flag under `printk_get_console_flush_type()`, so that
printk's are deferred in this state, relying on the fact that a kthread is
about to be started. This does not affect behaviour under panic and
emergency priorities which are flushed via `write_atomic`.

With this change applied, the flushing of printk messages on a newly
registered nbcon console is now fully handled by the console's kthread. On
my test hardware (Raspberry Pi 3B+), I have seen a reduction in the time
taken to boot into userspace when using nbcon consoles from ~9s to ~1s:

Using an nbcon console (115200 baud):

[    8.377111] probe of 3f215040.serial returned 0 after 8090191 usecs
...
[    9.316964] Run /sbin/init as init process

With this patch applied:

[    0.302173] probe of 3f215040.serial returned 0 after 7479 usecs
...
[    1.096505] Run /sbin/init as init process

This patch has been tested on master branch of the printk kernel repository
(kernel/git/printk/linux.git), Commit
af54a3a151691a969b04396cff15afe70d4da824 ("Merge tag 'printk-for-6.15-2' of
git://git.kernel.org/pub/scm/linux/kernel/git/printk/linux")

As the 8250 nbcon driver patches [0] have been applied and then reverted
upstream [1], this patch requires those driver patches to be reapplied. For
completeness, patches 2, 3 in this series reapplies them, but these patches
should not be considered as part of this RFC.

Kind regards,

Michael

[0] https://lore.kernel.org/lkml/20250107212702.169493-1-john.ogness@linutronix.de/
[1] https://lore.kernel.org/linux-serial/Z5jn5M5bdV5u21GB@kroah.com/

Signed-Off-By: Michael Cobb <mcobb@thegoodpenguin.co.uk>

Michael Cobb (3):
  printk: Don't flush messages using write_atomic during console
    registration if kthreads have not been started yet.
  Reapply "serial: 8250: Switch to nbcon console"
  Reapply "serial: 8250: Revert "drop lockdep annotation from
    serial8250_clear_IER()""

 drivers/tty/serial/8250/8250_core.c |  35 +++++-
 drivers/tty/serial/8250/8250_port.c | 183 ++++++++++++++++++++++------
 include/linux/serial_8250.h         |  13 +-
 kernel/printk/internal.h            |   4 +-
 kernel/printk/nbcon.c               |   2 +
 kernel/printk/printk.c              |   3 +
 6 files changed, 198 insertions(+), 42 deletions(-)

-- 
2.45.2

[PATCH RFC 1/3] printk: Don't flush messages using write_atomic during console registration if kthreads have not been started yet.

[Michael Cobb]

Signed-Off-By: Michael Cobb <mcobb@thegoodpenguin.co.uk>
---
 kernel/printk/internal.h | 4 +++-
 kernel/printk/nbcon.c    | 2 ++
 kernel/printk/printk.c   | 3 +++
 3 files changed, 8 insertions(+), 1 deletion(-)

diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
index 48a24e7b309d..e31ecb2fc81c 100644
--- a/kernel/printk/internal.h
+++ b/kernel/printk/internal.h
@@ -64,6 +64,7 @@ struct dev_printk_info;
 
 extern struct printk_ringbuffer *prb;
 extern bool printk_kthreads_running;
+extern bool printk_kthreads_pending_start;
 extern bool debug_non_panic_cpus;
 
 __printf(4, 0)
@@ -180,6 +181,7 @@ static inline void nbcon_kthread_wake(struct console *con)
 #define PRINTKRB_RECORD_MAX	0
 
 #define printk_kthreads_running (false)
+#define printk_kthreads_pending_start (false)
 
 /*
  * In !PRINTK builds we still export console_sem
@@ -240,7 +242,7 @@ static inline void printk_get_console_flush_type(struct console_flush_type *ft)
 	switch (nbcon_get_default_prio()) {
 	case NBCON_PRIO_NORMAL:
 		if (have_nbcon_console && !have_boot_console) {
-			if (printk_kthreads_running)
+			if (printk_kthreads_running || printk_kthreads_pending_start)
 				ft->nbcon_offload = true;
 			else
 				ft->nbcon_atomic = true;
diff --git a/kernel/printk/nbcon.c b/kernel/printk/nbcon.c
index fd12efcc4aed..adb53de5c2f2 100644
--- a/kernel/printk/nbcon.c
+++ b/kernel/printk/nbcon.c
@@ -1707,6 +1707,8 @@ bool nbcon_alloc(struct console *con)
 				con->pbufs = NULL;
 				return false;
 			}
+		} else {
+			printk_kthreads_pending_start = true;
 		}
 	}
 
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 1eea80d0648e..c71bf5c228f2 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -501,6 +501,8 @@ static bool syslog_time;
 /* True when _all_ printer threads are available for printing. */
 bool printk_kthreads_running;
 
+bool printk_kthreads_pending_start = false;
+
 struct latched_seq {
 	seqcount_latch_t	latch;
 	u64			val[2];
@@ -3758,6 +3760,7 @@ static void printk_kthreads_check_locked(void)
 			unregister_console_locked(con);
 	}
 
+	printk_kthreads_pending_start = false;
 	printk_kthreads_running = true;
 }
 
-- 
2.45.2

[PATCH RFC 2/3] Reapply "serial: 8250: Switch to nbcon console"

[Michael Cobb]

This reverts commit f79b163c42314a1f46f4bcc40a19c8a75cf1e7a3.
---
 drivers/tty/serial/8250/8250_core.c |  35 +++++-
 drivers/tty/serial/8250/8250_port.c | 180 ++++++++++++++++++++++------
 include/linux/serial_8250.h         |  13 +-
 3 files changed, 187 insertions(+), 41 deletions(-)

diff --git a/drivers/tty/serial/8250/8250_core.c b/drivers/tty/serial/8250/8250_core.c
index 6f676bb37ac3..3ab372b28cf3 100644
--- a/drivers/tty/serial/8250/8250_core.c
+++ b/drivers/tty/serial/8250/8250_core.c
@@ -388,12 +388,34 @@ void __init serial8250_register_ports(struct uart_driver *drv, struct device *de
 
 #ifdef CONFIG_SERIAL_8250_CONSOLE
 
-static void univ8250_console_write(struct console *co, const char *s,
-				   unsigned int count)
+static void univ8250_console_write_atomic(struct console *co,
+					  struct nbcon_write_context *wctxt)
 {
 	struct uart_8250_port *up = &serial8250_ports[co->index];
 
-	serial8250_console_write(up, s, count);
+	serial8250_console_write(up, wctxt, true);
+}
+
+static void univ8250_console_write_thread(struct console *co,
+					  struct nbcon_write_context *wctxt)
+{
+	struct uart_8250_port *up = &serial8250_ports[co->index];
+
+	serial8250_console_write(up, wctxt, false);
+}
+
+static void univ8250_console_device_lock(struct console *co, unsigned long *flags)
+{
+	struct uart_port *up = &serial8250_ports[co->index].port;
+
+	__uart_port_lock_irqsave(up, flags);
+}
+
+static void univ8250_console_device_unlock(struct console *co, unsigned long flags)
+{
+	struct uart_port *up = &serial8250_ports[co->index].port;
+
+	__uart_port_unlock_irqrestore(up, flags);
 }
 
 static int univ8250_console_setup(struct console *co, char *options)
@@ -494,12 +516,15 @@ static int univ8250_console_match(struct console *co, char *name, int idx,
 
 static struct console univ8250_console = {
 	.name		= "ttyS",
-	.write		= univ8250_console_write,
+	.write_atomic	= univ8250_console_write_atomic,
+	.write_thread	= univ8250_console_write_thread,
+	.device_lock	= univ8250_console_device_lock,
+	.device_unlock	= univ8250_console_device_unlock,
 	.device		= uart_console_device,
 	.setup		= univ8250_console_setup,
 	.exit		= univ8250_console_exit,
 	.match		= univ8250_console_match,
-	.flags		= CON_PRINTBUFFER | CON_ANYTIME,
+	.flags		= CON_PRINTBUFFER | CON_ANYTIME | CON_NBCON,
 	.index		= -1,
 	.data		= &serial8250_reg,
 };
diff --git a/drivers/tty/serial/8250/8250_port.c b/drivers/tty/serial/8250/8250_port.c
index c57f44882abb..ef7dfab908d8 100644
--- a/drivers/tty/serial/8250/8250_port.c
+++ b/drivers/tty/serial/8250/8250_port.c
@@ -709,7 +709,12 @@ static void serial8250_set_sleep(struct uart_8250_port *p, int sleep)
 	serial8250_rpm_put(p);
 }
 
-static void serial8250_clear_IER(struct uart_8250_port *up)
+/*
+ * Only to be used directly by the callback helper serial8250_console_write(),
+ * which may not require the port lock. Use serial8250_clear_IER() instead for
+ * all other cases.
+ */
+static void __serial8250_clear_IER(struct uart_8250_port *up)
 {
 	if (up->capabilities & UART_CAP_UUE)
 		serial_out(up, UART_IER, UART_IER_UUE);
@@ -717,6 +722,11 @@ static void serial8250_clear_IER(struct uart_8250_port *up)
 		serial_out(up, UART_IER, 0);
 }
 
+static inline void serial8250_clear_IER(struct uart_8250_port *up)
+{
+	__serial8250_clear_IER(up);
+}
+
 #ifdef CONFIG_SERIAL_8250_RSA
 /*
  * Attempts to turn on the RSA FIFO.  Returns zero on failure.
@@ -1404,9 +1414,6 @@ void serial8250_em485_stop_tx(struct uart_8250_port *p, bool toggle_ier)
 {
 	unsigned char mcr = serial8250_in_MCR(p);
 
-	/* Port locked to synchronize UART_IER access against the console. */
-	lockdep_assert_held_once(&p->port.lock);
-
 	if (p->port.rs485.flags & SER_RS485_RTS_AFTER_SEND)
 		mcr |= UART_MCR_RTS;
 	else
@@ -1422,6 +1429,16 @@ void serial8250_em485_stop_tx(struct uart_8250_port *p, bool toggle_ier)
 		serial8250_clear_and_reinit_fifos(p);
 
 		if (toggle_ier) {
+			/*
+			 * Port locked to synchronize UART_IER access against
+			 * the console. The lockdep_assert must be restricted
+			 * to this condition because only here is it
+			 * guaranteed that the port lock is held. The other
+			 * hardware access in this function is synchronized
+			 * by console ownership.
+			 */
+			lockdep_assert_held_once(&p->port.lock);
+
 			p->ier |= UART_IER_RLSI | UART_IER_RDI;
 			serial_port_out(&p->port, UART_IER, p->ier);
 		}
@@ -3310,7 +3327,11 @@ EXPORT_SYMBOL_GPL(serial8250_set_defaults);
 
 static void serial8250_console_putchar(struct uart_port *port, unsigned char ch)
 {
+	struct uart_8250_port *up = up_to_u8250p(port);
+
 	serial_port_out(port, UART_TX, ch);
+
+	up->console_line_ended = (ch == '\n');
 }
 
 static void serial8250_console_wait_putchar(struct uart_port *port, unsigned char ch)
@@ -3347,11 +3368,22 @@ static void serial8250_console_restore(struct uart_8250_port *up)
 	serial8250_out_MCR(up, up->mcr | UART_MCR_DTR | UART_MCR_RTS);
 }
 
-static void fifo_wait_for_lsr(struct uart_8250_port *up, unsigned int count)
+static void fifo_wait_for_lsr(struct uart_8250_port *up,
+			      struct nbcon_write_context *wctxt,
+			      unsigned int count)
 {
 	unsigned int i;
 
 	for (i = 0; i < count; i++) {
+		/*
+		 * Pass the ownership as quickly as possible to a higher
+		 * priority context. Otherwise, its attempt to take over
+		 * the ownership might timeout. The new owner will wait
+		 * for UART_LSR_THRE before reusing the fifo.
+		 */
+		if (!nbcon_can_proceed(wctxt))
+			return;
+
 		if (wait_for_lsr(up, UART_LSR_THRE))
 			return;
 	}
@@ -3364,20 +3396,29 @@ static void fifo_wait_for_lsr(struct uart_8250_port *up, unsigned int count)
  * to get empty.
  */
 static void serial8250_console_fifo_write(struct uart_8250_port *up,
-					  const char *s, unsigned int count)
+					  struct nbcon_write_context *wctxt)
 {
-	const char *end = s + count;
 	unsigned int fifosize = up->tx_loadsz;
 	struct uart_port *port = &up->port;
+	const char *s = wctxt->outbuf;
+	const char *end = s + wctxt->len;
 	unsigned int tx_count = 0;
 	bool cr_sent = false;
 	unsigned int i;
 
 	while (s != end) {
 		/* Allow timeout for each byte of a possibly full FIFO */
-		fifo_wait_for_lsr(up, fifosize);
+		fifo_wait_for_lsr(up, wctxt, fifosize);
 
+		/*
+		 * Fill the FIFO. If a handover or takeover occurs, writing
+		 * must be aborted since wctxt->outbuf and wctxt->len are no
+		 * longer valid.
+		 */
 		for (i = 0; i < fifosize && s != end; ++i) {
+			if (!nbcon_enter_unsafe(wctxt))
+				return;
+
 			if (*s == '\n' && !cr_sent) {
 				serial8250_console_putchar(port, '\r');
 				cr_sent = true;
@@ -3385,6 +3426,8 @@ static void serial8250_console_fifo_write(struct uart_8250_port *up,
 				serial8250_console_putchar(port, *s++);
 				cr_sent = false;
 			}
+
+			nbcon_exit_unsafe(wctxt);
 		}
 		tx_count = i;
 	}
@@ -3393,39 +3436,57 @@ static void serial8250_console_fifo_write(struct uart_8250_port *up,
 	 * Allow timeout for each byte written since the caller will only wait
 	 * for UART_LSR_BOTH_EMPTY using the timeout of a single character
 	 */
-	fifo_wait_for_lsr(up, tx_count);
+	fifo_wait_for_lsr(up, wctxt, tx_count);
+}
+
+static void serial8250_console_byte_write(struct uart_8250_port *up,
+					  struct nbcon_write_context *wctxt)
+{
+	struct uart_port *port = &up->port;
+	const char *s = wctxt->outbuf;
+	const char *end = s + wctxt->len;
+
+	/*
+	 * Write out the message. If a handover or takeover occurs, writing
+	 * must be aborted since wctxt->outbuf and wctxt->len are no longer
+	 * valid.
+	 */
+	while (s != end) {
+		if (!nbcon_enter_unsafe(wctxt))
+			return;
+
+		uart_console_write(port, s++, 1, serial8250_console_wait_putchar);
+
+		nbcon_exit_unsafe(wctxt);
+	}
 }
 
 /*
- *	Print a string to the serial port trying not to disturb
- *	any possible real use of the port...
- *
- *	The console_lock must be held when we get here.
+ * Print a string to the serial port trying not to disturb
+ * any possible real use of the port...
  *
- *	Doing runtime PM is really a bad idea for the kernel console.
- *	Thus, we assume the function is called when device is powered up.
+ * Doing runtime PM is really a bad idea for the kernel console.
+ * Thus, assume it is called when device is powered up.
  */
-void serial8250_console_write(struct uart_8250_port *up, const char *s,
-			      unsigned int count)
+void serial8250_console_write(struct uart_8250_port *up,
+			      struct nbcon_write_context *wctxt,
+			      bool is_atomic)
 {
 	struct uart_8250_em485 *em485 = up->em485;
 	struct uart_port *port = &up->port;
-	unsigned long flags;
-	unsigned int ier, use_fifo;
-	int locked = 1;
-
-	touch_nmi_watchdog();
+	unsigned int ier;
+	bool use_fifo;
 
-	if (oops_in_progress)
-		locked = uart_port_trylock_irqsave(port, &flags);
-	else
-		uart_port_lock_irqsave(port, &flags);
+	if (!nbcon_enter_unsafe(wctxt))
+		return;
 
 	/*
-	 *	First save the IER then disable the interrupts
+	 * First, save the IER, then disable the interrupts. The special
+	 * variant to clear the IER is used because console printing may
+	 * occur without holding the port lock.
 	 */
 	ier = serial_port_in(port, UART_IER);
-	serial8250_clear_IER(up);
+	__serial8250_clear_IER(up);
 
 	/* check scratch reg to see if port powered off during system sleep */
 	if (up->canary && (up->canary != serial_port_in(port, UART_SCR))) {
@@ -3439,6 +3500,18 @@ void serial8250_console_write(struct uart_8250_port *up, const char *s,
 		mdelay(port->rs485.delay_rts_before_send);
 	}
 
+	/* If ownership was lost, no writing is allowed */
+	if (!nbcon_can_proceed(wctxt))
+		goto skip_write;
+
+	/*
+	 * If console printer did not fully output the previous line, it must
+	 * have been handed or taken over. Insert a newline in order to
+	 * maintain clean output.
+	 */
+	if (!up->console_line_ended)
+		uart_console_write(port, "\n", 1, serial8250_console_wait_putchar);
+
 	use_fifo = (up->capabilities & UART_CAP_FIFO) &&
 		/*
 		 * BCM283x requires to check the fifo
@@ -3459,10 +3532,23 @@ void serial8250_console_write(struct uart_8250_port *up, const char *s,
 		 */
 		!(up->port.flags & UPF_CONS_FLOW);
 
+	nbcon_exit_unsafe(wctxt);
+
 	if (likely(use_fifo))
-		serial8250_console_fifo_write(up, s, count);
+		serial8250_console_fifo_write(up, wctxt);
 	else
-		uart_console_write(port, s, count, serial8250_console_wait_putchar);
+		serial8250_console_byte_write(up, wctxt);
+skip_write:
+	/*
+	 * If ownership was lost, this context must reacquire ownership and
+	 * re-enter the unsafe section in order to perform final actions
+	 * (such as re-enabling interrupts).
+	 */
+	if (!nbcon_can_proceed(wctxt)) {
+		do {
+			nbcon_reacquire_nobuf(wctxt);
+		} while (!nbcon_enter_unsafe(wctxt));
+	}
 
 	/*
 	 *	Finally, wait for transmitter to become empty
@@ -3485,11 +3571,18 @@ void serial8250_console_write(struct uart_8250_port *up, const char *s,
 	 *	call it if we have saved something in the saved flags
 	 *	while processing with interrupts off.
 	 */
-	if (up->msr_saved_flags)
-		serial8250_modem_status(up);
+	if (up->msr_saved_flags) {
+		/*
+		 * For atomic, it must be deferred to irq_work because this
+		 * may be a context that does not permit waking up tasks.
+		 */
+		if (is_atomic)
+			irq_work_queue(&up->modem_status_work);
+		else
+			serial8250_modem_status(up);
+	}
 
-	if (locked)
-		uart_port_unlock_irqrestore(port, flags);
+	nbcon_exit_unsafe(wctxt);
 }
 
 static unsigned int probe_baud(struct uart_port *port)
@@ -3507,8 +3600,24 @@ static unsigned int probe_baud(struct uart_port *port)
 	return (port->uartclk / 16) / quot;
 }
 
+/*
+ * irq_work handler to perform modem control. Only triggered via
+ * ->write_atomic() callback because it may be in a scheduler or
+ * NMI context, unable to wake tasks.
+ */
+static void modem_status_handler(struct irq_work *iwp)
+{
+	struct uart_8250_port *up = container_of(iwp, struct uart_8250_port, modem_status_work);
+	struct uart_port *port = &up->port;
+
+	uart_port_lock(port);
+	serial8250_modem_status(up);
+	uart_port_unlock(port);
+}
+
 int serial8250_console_setup(struct uart_port *port, char *options, bool probe)
 {
+	struct uart_8250_port *up = up_to_u8250p(port);
 	int baud = 9600;
 	int bits = 8;
 	int parity = 'n';
@@ -3518,6 +3627,9 @@ int serial8250_console_setup(struct uart_port *port, char *options, bool probe)
 	if (!port->iobase && !port->membase)
 		return -ENODEV;
 
+	up->console_line_ended = true;
+	init_irq_work(&up->modem_status_work, modem_status_handler);
+
 	if (options)
 		uart_parse_options(options, &baud, &parity, &bits, &flow);
 	else if (probe)
diff --git a/include/linux/serial_8250.h b/include/linux/serial_8250.h
index 144de7a7948d..57875c37023a 100644
--- a/include/linux/serial_8250.h
+++ b/include/linux/serial_8250.h
@@ -150,8 +150,17 @@ struct uart_8250_port {
 #define LSR_SAVE_FLAGS UART_LSR_BRK_ERROR_BITS
 	u16			lsr_saved_flags;
 	u16			lsr_save_mask;
+
+	/*
+	 * Track when a console line has been fully written to the
+	 * hardware, i.e. true when the most recent byte written to
+	 * UART_TX by the console was '\n'.
+	 */
+	bool			console_line_ended;
+
 #define MSR_SAVE_FLAGS UART_MSR_ANY_DELTA
 	unsigned char		msr_saved_flags;
+	struct irq_work		modem_status_work;
 
 	struct uart_8250_dma	*dma;
 	const struct uart_8250_ops *ops;
@@ -202,8 +211,8 @@ void serial8250_tx_chars(struct uart_8250_port *up);
 unsigned int serial8250_modem_status(struct uart_8250_port *up);
 void serial8250_init_port(struct uart_8250_port *up);
 void serial8250_set_defaults(struct uart_8250_port *up);
-void serial8250_console_write(struct uart_8250_port *up, const char *s,
-			      unsigned int count);
+void serial8250_console_write(struct uart_8250_port *up,
+			      struct nbcon_write_context *wctxt, bool in_atomic);
 int serial8250_console_setup(struct uart_port *port, char *options, bool probe);
 int serial8250_console_exit(struct uart_port *port);
 
-- 
2.45.2

[PATCH RFC 3/3] Reapply "serial: 8250: Revert "drop lockdep annotation from serial8250_clear_IER()""

[Michael Cobb]

This reverts commit 244eb5c6ec62ccab59ecac1f4815bb33130c423a.
---
 drivers/tty/serial/8250/8250_port.c | 3 +++
 1 file changed, 3 insertions(+)

diff --git a/drivers/tty/serial/8250/8250_port.c b/drivers/tty/serial/8250/8250_port.c
index ef7dfab908d8..af77fd966d6c 100644
--- a/drivers/tty/serial/8250/8250_port.c
+++ b/drivers/tty/serial/8250/8250_port.c
@@ -724,6 +724,9 @@ static void __serial8250_clear_IER(struct uart_8250_port *up)
 
 static inline void serial8250_clear_IER(struct uart_8250_port *up)
 {
+	/* Port locked to synchronize UART_IER access against the console */
+	lockdep_assert_held_once(&up->port.lock);
+
 	__serial8250_clear_IER(up);
 }
 
-- 
2.45.2

Re: [PATCH RFC 0/3] printk: Don't flush messages using write_atomic during console registration if kthreads have not been started yet.

[John Ogness]

Hi Michael,

On 2025-05-14, Michael Cobb <mcobb@thegoodpenguin.co.uk> wrote:
> Hello all,
>
> When using a legacy console, there is a large amount of time during boot
> that is spent printing boot messages to the serial port. I have spent time
> looking at nbcon and the potential effects the new interface should have on
> boot times. We should expect a significant reduction in boot times as this
> work is now offloaded to a dedicated kthread.
>
> With some slight tweaks to the behaviour of nbcon during console
> registration, it is possible to reduce boot times significantly.
>
> During initial console registration, we mainly rely on two flags,
> `have_nbcon_console` and `printk_kthreads_running`, to handle the glboal
> state of nbcon and to determine the appropriate method to handle flushing
> messages.
>
> In the case of nbcon, when calling `printk()`, messages are either flushed
> by the caller using `write_atomic`, or this work is offloaded to the
> console's printk kthread. As can be seen in
> `printk_get_console_flush_type()`, under normal (i.e. non-emergency or
> panic) priority, we check the value of `printk_kthreads_running` to
> determine if nbcon consoles should be flushed via `write_atomic` or not.
>
> When `register_console()` is called to register the first nbcon console
> during boot, we know that `printk_kthreads_running` will be false as:
> - before the `printk_set_kthreads_ready` initcall, no kthreads have been
>   started since `printk_kthreads_ready` will be false.
> - after the `printk_set_kthreads_ready` initcall, `printk_kthreads_running`
>   will be false since we have not yet registered any nbcon consoles. As we
>   are registering an nbcon console, `register_console()` will set
>   `have_nbcon_console = true`. At this point, we are now in an intermediate
>   state - we have registered an nbcon console but a kthread for it has not
>   yet been started.
>
> In effect, this means that any calls made to `printk()` after
> `have_nbcon_console` has been set but before
> `printk_kthreads_check_locked()` has set `printk_kthreads_running` will use
> `write_atomic` on nbcon consoles. As `vprintk_emit()` calls
> `nbcon_atomic_flush_pending()` in this situation, we see that the newly
> registered console has all boot messages flushed in this manner.
>
> This RFC patch introduces a new flag, `printk_kthreads_pending_start`, to
> handle this intermediate state. This flag is set when an nbcon console is
> registered and cleared once `printk_kthreads_running` is set to true. We
> then check this flag under `printk_get_console_flush_type()`, so that
> printk's are deferred in this state, relying on the fact that a kthread is
> about to be started. This does not affect behaviour under panic and
> emergency priorities which are flushed via `write_atomic`.
>
> With this change applied, the flushing of printk messages on a newly
> registered nbcon console is now fully handled by the console's kthread. On
> my test hardware (Raspberry Pi 3B+), I have seen a reduction in the time
> taken to boot into userspace when using nbcon consoles from ~9s to ~1s:

If I understand the problem correctly, it is really due to the "console
enabled" message that is printed upon registration. For the first
console, it would perform a full atomic flush, even though it is about
to create the kthread printer.

What if we create the kthread _before_ printing the message. Something
like the below (untested) changes. Does this also address the issue?

John Ogness

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 1eea80d0648ed..ecc0f393cacf0 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -4122,7 +4122,6 @@ void register_console(struct console *newcon)
 	 * users know there might be something in the kernel's log buffer that
 	 * went to the bootconsole (that they do not see on the real console)
 	 */
-	con_printk(KERN_INFO, newcon, "enabled\n");
 	if (bootcon_registered &&
 	    ((newcon->flags & (CON_CONSDEV | CON_BOOT)) == CON_CONSDEV) &&
 	    !keep_bootcon) {
@@ -4136,6 +4135,7 @@ void register_console(struct console *newcon)
 
 	/* Changed console list, may require printer threads to start/stop. */
 	printk_kthreads_check_locked();
+	con_printk(KERN_INFO, newcon, "enabled\n");
 unlock:
 	console_list_unlock();
 }

Re: [PATCH RFC 0/3] printk: Don't flush messages using write_atomic during console registration if kthreads have not been started yet.

[Michael Cobb]

On Fri, 16 May 2025 at 10:44, John Ogness <john.ogness@linutronix.de> wrote:
> If I understand the problem correctly, it is really due to the "console
> enabled" message that is printed upon registration. For the first
> console, it would perform a full atomic flush, even though it is about
> to create the kthread printer.

Hi John,

Yes, you're correct, when the first nbcon console is registered, any
calls to printk() (made after have_nbcon_console is set and before
printk_kthreads_check_locked() sets printk_kthreads_running) will
trigger an atomic flush.

This can also happen if we attempt to register the console before
printk_set_kthreads_ready() has been called, as
printk_kthreads_check_locked() cannot start printer kthreads yet. In
this case printk() will also flush atomically until kthreads are
ready.

> What if we create the kthread _before_ printing the message. Something
> like the below (untested) changes. Does this also address the issue?

Yes, that works and avoids the atomic flush, however we then lose the
"console [ttyS0] enabled" message on any boot consoles that we are
about to unregister. See the comment above the con_printk() call:

    /*
     * By unregistering the bootconsoles after we enable the real console
     * we get the "console xxx enabled" message on all the consoles -
     * boot consoles, real consoles, etc - this is to ensure that end
     * users know there might be something in the kernel's log buffer that
     * went to the bootconsole (that they do not see on the real console)
     */
    con_printk(KERN_INFO, newcon, "enabled\n");

We would then also need to ensure that nowhere in this code path calls
printk(). I can see some places where printk() might be called (mainly
for error reporting). For example, unregister_console_locked(), prints
a "console disabled" message, also in the call to
console_sysfs_notify() (linux/kernel/printk/printk.c:4116),
kernfs_put() calls WARN_ONCE() (linux/fs/kernfs/dir.c:579).

I am worried that by avoiding calling printk() to not trigger a flush,
this might not be robust enough?
Any future changes, even those made outside printk.c if made inside
this code path, can reintroduce an atomic flush just by calling
printk().

Kind regards,

Michael

Re: [PATCH RFC 0/3] printk: Don't flush messages using write_atomic during console registration if kthreads have not been started yet.

[John Ogness]

On 2025-05-30, Michael Cobb <mcobb@thegoodpenguin.co.uk> wrote:
> On Fri, 16 May 2025 at 10:44, John Ogness <john.ogness@linutronix.de> wrote:
>> What if we create the kthread _before_ printing the message. Something
>> like the below (untested) changes. Does this also address the issue?
>
> Yes, that works and avoids the atomic flush, however we then lose the
> "console [ttyS0] enabled" message on any boot consoles that we are
> about to unregister.

Right. I was going about it wrong. Really we should start the threads as
soon as the console is fully registered. Waiting until after the boot
consoles are unregistered is wrong. So how about this change instead?

Note that printk_kthreads_check_locked() is only needed for the newly
added console. If any boot console is unregistered,
printk_kthreads_check_locked() is called again in
unregister_console_locked().

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 1eea80d0648ed..b142d69330de2 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -4115,6 +4115,9 @@ void register_console(struct console *newcon)
 
 	console_sysfs_notify();
 
+	/* Changed console list, may require printer threads to start/stop. */
+	printk_kthreads_check_locked();
+
 	/*
 	 * By unregistering the bootconsoles after we enable the real console
 	 * we get the "console xxx enabled" message on all the consoles -
@@ -4133,9 +4136,6 @@ void register_console(struct console *newcon)
 				unregister_console_locked(con);
 		}
 	}
-
-	/* Changed console list, may require printer threads to start/stop. */
-	printk_kthreads_check_locked();
 unlock:
 	console_list_unlock();
 }


> I am worried that by avoiding calling printk() to not trigger a flush,
> this might not be robust enough?

The problem is that we cannot trust that the kthreads will start.

I think my above change is correct because it starts the kthreads before
unregistering the boot console, so if there are any problems, the boot
consoles are still around to report them.

In your case you have no boot consoles, so you really just want to avoid
all atomic printing until the kthread has had a chance. Something like
this change might be more appropriate:

diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
index 48a24e7b309db..7462a6d179850 100644
--- a/kernel/printk/internal.h
+++ b/kernel/printk/internal.h
@@ -240,7 +240,7 @@ static inline void printk_get_console_flush_type(struct console_flush_type *ft)
 	switch (nbcon_get_default_prio()) {
 	case NBCON_PRIO_NORMAL:
 		if (have_nbcon_console && !have_boot_console) {
-			if (printk_kthreads_running)
+			if (printk_kthreads_running || printk_kthreads_pending_start)
 				ft->nbcon_offload = true;
 			else
 				ft->nbcon_atomic = true;
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 1eea80d0648ed..9c0378dc88c4c 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -4072,6 +4072,14 @@ void register_console(struct console *newcon)
 	if (newcon->flags & CON_BOOT)
 		have_boot_console = true;
 
+	/*
+	 * If this is the first console, avoid flushing the backlog
+	 * until the printing kthread has had a chance to start via
+	 * printk_kthreads_check_locked() below.
+	 */
+	if (hlist_empty(&console_list) && (newcon->flags & CON_NBCON))
+		printk_kthread_pending_start = true;
+
 	/*
 	 * If another context is actively using the hardware of this new
 	 * console, it will not be aware of the nbcon synchronization. This
@@ -4115,6 +4123,10 @@ void register_console(struct console *newcon)
 
 	console_sysfs_notify();
 
+	/* Changed console list, may require printer threads to start/stop. */
+	printk_kthreads_check_locked();
+	printk_kthread_pending_start = false;
+
 	/*
 	 * By unregistering the bootconsoles after we enable the real console
 	 * we get the "console xxx enabled" message on all the consoles -
@@ -4133,9 +4145,6 @@ void register_console(struct console *newcon)
 				unregister_console_locked(con);
 		}
 	}
-
-	/* Changed console list, may require printer threads to start/stop. */
-	printk_kthreads_check_locked();
 unlock:
 	console_list_unlock();
 }

Notice that I kept the control of the new flag inside the register
function.

I do not really like this because printk_get_console_flush_type() is now
checking an extra flag every time for something that is a special case
and only at boot. Although, theoretically, it can happen anytime that
all consoles are removed during runtime and then later added.

Thoughts?

John

Re: [PATCH RFC 0/3] printk: Don't flush messages using write_atomic during console registration if kthreads have not been started yet.

[John Ogness]

On 2025-05-31, John Ogness <john.ogness@linutronix.de> wrote:
> diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
> index 48a24e7b309db..7462a6d179850 100644
> --- a/kernel/printk/internal.h
> +++ b/kernel/printk/internal.h
> @@ -240,7 +240,7 @@ static inline void printk_get_console_flush_type(struct console_flush_type *ft)
>  	switch (nbcon_get_default_prio()) {
>  	case NBCON_PRIO_NORMAL:
>  		if (have_nbcon_console && !have_boot_console) {
> -			if (printk_kthreads_running)
> +			if (printk_kthreads_running || printk_kthreads_pending_start)
>  				ft->nbcon_offload = true;
>  			else
>  				ft->nbcon_atomic = true;
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index 1eea80d0648ed..9c0378dc88c4c 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -4072,6 +4072,14 @@ void register_console(struct console *newcon)
>  	if (newcon->flags & CON_BOOT)
>  		have_boot_console = true;
>  
> +	/*
> +	 * If this is the first console, avoid flushing the backlog
> +	 * until the printing kthread has had a chance to start via
> +	 * printk_kthreads_check_locked() below.
> +	 */
> +	if (hlist_empty(&console_list) && (newcon->flags & CON_NBCON))
> +		printk_kthread_pending_start = true;
> +
>  	/*
>  	 * If another context is actively using the hardware of this new
>  	 * console, it will not be aware of the nbcon synchronization. This
> @@ -4115,6 +4123,10 @@ void register_console(struct console *newcon)
>  
>  	console_sysfs_notify();
>  
> +	/* Changed console list, may require printer threads to start/stop. */
> +	printk_kthreads_check_locked();
> +	printk_kthread_pending_start = false;
> +
>  	/*
>  	 * By unregistering the bootconsoles after we enable the real console
>  	 * we get the "console xxx enabled" message on all the consoles -
> @@ -4133,9 +4145,6 @@ void register_console(struct console *newcon)
>  				unregister_console_locked(con);
>  		}
>  	}
> -
> -	/* Changed console list, may require printer threads to start/stop. */
> -	printk_kthreads_check_locked();

This won't work. printk_kthreads_check_locked() must come after the
boot-console unregister-loop. The kthreads do not start if boot consoles
are registered.

I spent some time thinking about how to get a clean implementation of
this optimization. It is tricky because:

- If the console is registered before printk_kthreads_ready=true, then
  the optimization cannot be used (i.e. the console must do the atomic
  flushing).

- If the console fails to start its kthread, then it must do the atomic
  flush when unregistering.

Perhaps something like this:

diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
index 48a24e7b309db..7462a6d179850 100644
--- a/kernel/printk/internal.h
+++ b/kernel/printk/internal.h
@@ -240,7 +240,7 @@ static inline void printk_get_console_flush_type(struct console_flush_type *ft)
 	switch (nbcon_get_default_prio()) {
 	case NBCON_PRIO_NORMAL:
 		if (have_nbcon_console && !have_boot_console) {
-			if (printk_kthreads_running)
+			if (printk_kthreads_running || printk_kthreads_pending_start)
 				ft->nbcon_offload = true;
 			else
 				ft->nbcon_atomic = true;
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 1eea80d0648ed..d47e8076152e7 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -3754,8 +3754,18 @@ static void printk_kthreads_check_locked(void)
 		if (!(con->flags & CON_NBCON))
 			continue;
 
-		if (!nbcon_kthread_create(con))
+		if (!nbcon_kthread_create(con)) {
+			/*
+			 * The kthread failed to start so it is no longer
+			 * allowed to use the boot optimization and expect
+			 * offloading to take over. The backlog will be
+			 * flushed using atomic printing during unregister.
+			 */
+			if (printk_kthread_pending_start)
+				printk_kthread_pending_start = false;
+
 			unregister_console_locked(con);
+		}
 	}
 
 	printk_kthreads_running = true;
@@ -4072,6 +4082,18 @@ void register_console(struct console *newcon)
 	if (newcon->flags & CON_BOOT)
 		have_boot_console = true;
 
+	/*
+	 * Begin boot optimization.
+	 * If this is the first console and kthreads are available, avoid
+	 * flushing the backlog until the printing kthread has had a chance
+	 * to start via printk_kthreads_check_locked() below.
+	 */
+	if (hlist_empty(&console_list) &&
+	    (newcon->flags & CON_NBCON) &&
+	    printk_kthreads_ready) {
+		printk_kthread_pending_start = true;
+	}
+
 	/*
 	 * If another context is actively using the hardware of this new
 	 * console, it will not be aware of the nbcon synchronization. This
@@ -4136,6 +4158,13 @@ void register_console(struct console *newcon)
 
 	/* Changed console list, may require printer threads to start/stop. */
 	printk_kthreads_check_locked();
+
+	/*
+	 * End boot optimization.
+	 * The printing kthread had a chance to start.
+	 */
+	if (printk_kthread_pending_start)
+		printk_kthread_pending_start = false;
 unlock:
 	console_list_unlock();
 }

John

Re: [PATCH RFC 0/3] printk: Don't flush messages using write_atomic during console registration if kthreads have not been started yet.

[Petr Mladek]

Hi,

I am sorry for the late reply. I have hard times to catch up after
a conference...

On Mon 2025-06-02 17:46:57, John Ogness wrote:
> On 2025-05-31, John Ogness <john.ogness@linutronix.de> wrote:
> This won't work. printk_kthreads_check_locked() must come after the
> boot-console unregister-loop. The kthreads do not start if boot consoles
> are registered.
> 
> I spent some time thinking about how to get a clean implementation of
> this optimization. It is tricky because:
> 
> - If the console is registered before printk_kthreads_ready=true, then
>   the optimization cannot be used (i.e. the console must do the atomic
>   flushing).
> 
> - If the console fails to start its kthread, then it must do the atomic
>   flush when unregistering.
> 
> Perhaps something like this:
> 
> @@ -4072,6 +4082,18 @@ void register_console(struct console *newcon)
>  	if (newcon->flags & CON_BOOT)
>  		have_boot_console = true;
>  
> +	/*
> +	 * Begin boot optimization.
> +	 * If this is the first console and kthreads are available, avoid
> +	 * flushing the backlog until the printing kthread has had a chance
> +	 * to start via printk_kthreads_check_locked() below.
> +	 */
> +	if (hlist_empty(&console_list) &&

I am not sure if the check of empty_list is correct. There could be
legacy consoles...

> +	    (newcon->flags & CON_NBCON) &&
> +	    printk_kthreads_ready) {
> +		printk_kthread_pending_start = true;
> +	}
> +
>  	/*
>  	 * If another context is actively using the hardware of this new
>  	 * console, it will not be aware of the nbcon synchronization. This

Anyway, the console registration code is tricky like hell. There are
so many variables, twists, ...

I thought whether we could avoid introducing yet another variable
and still keep the code sane. And I came with the following.
The commit messages describes the idea.

I hope that I have covered all the cases. Note that I haven't tested
it with nbcon console though.

What do you think, please?

From 5768ff7e9d944bb904344341a2a447d2f101e6ba Mon Sep 17 00:00:00 2001
From: Petr Mladek <pmladek@suse.com>
Date: Tue, 3 Jun 2025 14:19:00 +0200
Subject: [PATCH] printk: Allow to use the printk kthread immediately even for
 1st nbcon

The kthreads for nbcon consoles are created by nbcon_alloc() at the beginning
of the console registration. But it currently works only for the 2nd or
later nbcon console because the code checks @printk_kthreads_running.

The kthread for the 1st registered nbcon console is created at the very
end of register_console() by printk_kthreads_check_locked(). As a result,
the entire log is replayed synchronously when the "enabled" message
gets printed. It might block the boot for a long time with a slow serial
console.

Prevent the synchronous flush by creating the kthread even for the 1st
nbcon console when it is safe (kthreads ready and no boot consoles).

Also inform printk() to use the kthread by setting @printk_kthreads_running.
Note that the kthreads already must be running when it is safe and this
is not the 1st nbcon console.

Symmetrically, clear @printk_kthreads_running when the last nbcon
console was unregistered by nbcon_free(). This requires updating
@have_nbcon_console before nbcon_free() gets called.

Note that there is _no_ problem when the 1st nbcon console replaces boot
consoles. In this case, the kthread will be started at the end
of registration after the boot consoles are removed. But the console
does not reply the entire log buffer in this case. Note that
the flag CON_PRINTBUFFER is always cleared when the boot consoles are
removed and vice versa.

Closes: https://lore.kernel.org/r/20250514173514.2117832-1-mcobb@thegoodpenguin.co.uk
Signed-off-by: Petr Mladek <pmladek@suse.com>
---
 kernel/printk/internal.h |  2 ++
 kernel/printk/nbcon.c    | 17 +++++++++++++++--
 kernel/printk/printk.c   | 19 ++++++++++---------
 3 files changed, 27 insertions(+), 11 deletions(-)

diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
index 48a24e7b309d..567c9e100d47 100644
--- a/kernel/printk/internal.h
+++ b/kernel/printk/internal.h
@@ -64,6 +64,7 @@ struct dev_printk_info;
 
 extern struct printk_ringbuffer *prb;
 extern bool printk_kthreads_running;
+extern bool printk_kthreads_ready;
 extern bool debug_non_panic_cpus;
 
 __printf(4, 0)
@@ -180,6 +181,7 @@ static inline void nbcon_kthread_wake(struct console *con)
 #define PRINTKRB_RECORD_MAX	0
 
 #define printk_kthreads_running (false)
+#define printk_kthreads_ready (false)
 
 /*
  * In !PRINTK builds we still export console_sem
diff --git a/kernel/printk/nbcon.c b/kernel/printk/nbcon.c
index fd12efcc4aed..7519d09c20e7 100644
--- a/kernel/printk/nbcon.c
+++ b/kernel/printk/nbcon.c
@@ -1671,6 +1671,9 @@ bool nbcon_alloc(struct console *con)
 {
 	struct nbcon_state state = { };
 
+	/* Synchronize the kthread start. */
+	lockdep_assert_console_list_lock_held();
+
 	/* The write_thread() callback is mandatory. */
 	if (WARN_ON(!con->write_thread))
 		return false;
@@ -1701,12 +1704,15 @@ bool nbcon_alloc(struct console *con)
 			return false;
 		}
 
-		if (printk_kthreads_running) {
+		if (printk_kthreads_ready && !have_boot_console) {
 			if (!nbcon_kthread_create(con)) {
 				kfree(con->pbufs);
 				con->pbufs = NULL;
 				return false;
 			}
+
+			/* Might be the first kthread. */
+			printk_kthreads_running = true;
 		}
 	}
 
@@ -1721,8 +1727,15 @@ void nbcon_free(struct console *con)
 {
 	struct nbcon_state state = { };
 
-	if (printk_kthreads_running)
+	/* Synchronize the kthread stop. */
+	lockdep_assert_console_list_lock_held();
+
+	if (printk_kthreads_running) {
 		nbcon_kthread_stop(con);
+		/* Might be the last nbcon console */
+		if (!have_nbcon_console)
+			printk_kthreads_running = false;
+	}
 
 	nbcon_state_set(con, &state);
 
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 1eea80d0648e..af6e4f0e8e22 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -3574,7 +3574,7 @@ EXPORT_SYMBOL(console_resume);
 static int unregister_console_locked(struct console *console);
 
 /* True when system boot is far enough to create printer threads. */
-static bool printk_kthreads_ready __ro_after_init;
+bool printk_kthreads_ready __ro_after_init;
 
 static struct task_struct *printk_legacy_kthread;
 
@@ -3713,6 +3713,7 @@ static void printk_kthreads_check_locked(void)
 	if (!printk_kthreads_ready)
 		return;
 
+	/* Start or stop the legacy kthread when needed. */
 	if (have_legacy_console || have_boot_console) {
 		if (!printk_legacy_kthread &&
 		    force_legacy_kthread() &&
@@ -4204,14 +4205,6 @@ static int unregister_console_locked(struct console *console)
 	 */
 	synchronize_srcu(&console_srcu);
 
-	if (console->flags & CON_NBCON)
-		nbcon_free(console);
-
-	console_sysfs_notify();
-
-	if (console->exit)
-		res = console->exit(console);
-
 	/*
 	 * With this console gone, the global flags tracking registered
 	 * console types may have changed. Update them.
@@ -4232,6 +4225,14 @@ static int unregister_console_locked(struct console *console)
 	if (!found_nbcon_con)
 		have_nbcon_console = found_nbcon_con;
 
+	if (console->flags & CON_NBCON)
+		nbcon_free(console);
+
+	console_sysfs_notify();
+
+	if (console->exit)
+		res = console->exit(console);
+
 	/* Changed console list, may require printer threads to start/stop. */
 	printk_kthreads_check_locked();
 
-- 
2.49.0

Re: [PATCH RFC 0/3] printk: Don't flush messages using write_atomic during console registration if kthreads have not been started yet.

[John Ogness]

On 2025-06-03, Petr Mladek <pmladek@suse.com> wrote:
> I thought whether we could avoid introducing yet another variable
> and still keep the code sane. And I came with the following.
> The commit messages describes the idea.
>
> I hope that I have covered all the cases. Note that I haven't tested
> it with nbcon console though.
>
> What do you think, please?
>
> From 5768ff7e9d944bb904344341a2a447d2f101e6ba Mon Sep 17 00:00:00 2001
> From: Petr Mladek <pmladek@suse.com>
> Date: Tue, 3 Jun 2025 14:19:00 +0200
> Subject: [PATCH] printk: Allow to use the printk kthread immediately even for
>  1st nbcon
>
> The kthreads for nbcon consoles are created by nbcon_alloc() at the beginning
> of the console registration. But it currently works only for the 2nd or
> later nbcon console because the code checks @printk_kthreads_running.
>
> The kthread for the 1st registered nbcon console is created at the very
> end of register_console() by printk_kthreads_check_locked(). As a result,
> the entire log is replayed synchronously when the "enabled" message
> gets printed. It might block the boot for a long time with a slow serial
> console.
>
> Prevent the synchronous flush by creating the kthread even for the 1st
> nbcon console when it is safe (kthreads ready and no boot consoles).
>
> Also inform printk() to use the kthread by setting @printk_kthreads_running.
> Note that the kthreads already must be running when it is safe and this
> is not the 1st nbcon console.
>
> Symmetrically, clear @printk_kthreads_running when the last nbcon
> console was unregistered by nbcon_free(). This requires updating
> @have_nbcon_console before nbcon_free() gets called.
>
> Note that there is _no_ problem when the 1st nbcon console replaces boot
> consoles. In this case, the kthread will be started at the end
> of registration after the boot consoles are removed. But the console
> does not reply the entire log buffer in this case. Note that
> the flag CON_PRINTBUFFER is always cleared when the boot consoles are
> removed and vice versa.
>
> Closes: https://lore.kernel.org/r/20250514173514.2117832-1-mcobb@thegoodpenguin.co.uk
> Signed-off-by: Petr Mladek <pmladek@suse.com>
> ---
>  kernel/printk/internal.h |  2 ++
>  kernel/printk/nbcon.c    | 17 +++++++++++++++--
>  kernel/printk/printk.c   | 19 ++++++++++---------
>  3 files changed, 27 insertions(+), 11 deletions(-)
>
> diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
> index 48a24e7b309d..567c9e100d47 100644
> --- a/kernel/printk/internal.h
> +++ b/kernel/printk/internal.h
> @@ -64,6 +64,7 @@ struct dev_printk_info;
>  
>  extern struct printk_ringbuffer *prb;
>  extern bool printk_kthreads_running;
> +extern bool printk_kthreads_ready;
>  extern bool debug_non_panic_cpus;
>  
>  __printf(4, 0)
> @@ -180,6 +181,7 @@ static inline void nbcon_kthread_wake(struct console *con)
>  #define PRINTKRB_RECORD_MAX	0
>  
>  #define printk_kthreads_running (false)
> +#define printk_kthreads_ready (false)
>  
>  /*
>   * In !PRINTK builds we still export console_sem
> diff --git a/kernel/printk/nbcon.c b/kernel/printk/nbcon.c
> index fd12efcc4aed..7519d09c20e7 100644
> --- a/kernel/printk/nbcon.c
> +++ b/kernel/printk/nbcon.c
> @@ -1671,6 +1671,9 @@ bool nbcon_alloc(struct console *con)
>  {
>  	struct nbcon_state state = { };
>  
> +	/* Synchronize the kthread start. */
> +	lockdep_assert_console_list_lock_held();
> +
>  	/* The write_thread() callback is mandatory. */
>  	if (WARN_ON(!con->write_thread))
>  		return false;
> @@ -1701,12 +1704,15 @@ bool nbcon_alloc(struct console *con)
>  			return false;
>  		}
>  
> -		if (printk_kthreads_running) {
> +		if (printk_kthreads_ready && !have_boot_console) {
>  			if (!nbcon_kthread_create(con)) {
>  				kfree(con->pbufs);
>  				con->pbufs = NULL;
>  				return false;
>  			}
> +
> +			/* Might be the first kthread. */
> +			printk_kthreads_running = true;
>  		}
>  	}
>  
> @@ -1721,8 +1727,15 @@ void nbcon_free(struct console *con)
>  {
>  	struct nbcon_state state = { };
>  
> -	if (printk_kthreads_running)
> +	/* Synchronize the kthread stop. */
> +	lockdep_assert_console_list_lock_held();
> +
> +	if (printk_kthreads_running) {
>  		nbcon_kthread_stop(con);
> +		/* Might be the last nbcon console */

Super small nit... add a period at the end of the comment to be
consistent with the one one-liners.

> +		if (!have_nbcon_console)
> +			printk_kthreads_running = false;
> +	}

This is pretty tricky. We should have a comment here (and possibly in
the function description of nbcon_free()) mentioning that nbcon_free()
must be called _after_ @have_nbcon_console has been updated for the
removal of this console. Generally it would not matter because
printk_kthreads_check_locked() is called at the end of
unregister. However, if in register CON_BRL is set, then nbcon_free() is
called without ever calling printk_kthreads_check_locked(). So this new
code in nbcon_free() is necessary to correctly reset
@printk_kthreads_running in that case.

> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index 1eea80d0648e..af6e4f0e8e22 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -3574,7 +3574,7 @@ EXPORT_SYMBOL(console_resume);
>  static int unregister_console_locked(struct console *console);
>  
>  /* True when system boot is far enough to create printer threads. */
> -static bool printk_kthreads_ready __ro_after_init;
> +bool printk_kthreads_ready __ro_after_init;
>  
>  static struct task_struct *printk_legacy_kthread;
>  
> @@ -3713,6 +3713,7 @@ static void printk_kthreads_check_locked(void)
>  	if (!printk_kthreads_ready)
>  		return;
>  
> +	/* Start or stop the legacy kthread when needed. */
>  	if (have_legacy_console || have_boot_console) {
>  		if (!printk_legacy_kthread &&
>  		    force_legacy_kthread() &&
> @@ -4204,14 +4205,6 @@ static int unregister_console_locked(struct console *console)
>  	 */
>  	synchronize_srcu(&console_srcu);
>  
> -	if (console->flags & CON_NBCON)
> -		nbcon_free(console);
> -
> -	console_sysfs_notify();
> -
> -	if (console->exit)
> -		res = console->exit(console);
> -
>  	/*
>  	 * With this console gone, the global flags tracking registered
>  	 * console types may have changed. Update them.
> @@ -4232,6 +4225,14 @@ static int unregister_console_locked(struct console *console)
>  	if (!found_nbcon_con)
>  		have_nbcon_console = found_nbcon_con;
>

Maybe also a small comment here that it can be freed because
@have_nbcon_console has been updated. Just to leave a little hint for
future developers that its location is important.

> +	if (console->flags & CON_NBCON)
> +		nbcon_free(console);
> +
> +	console_sysfs_notify();
> +
> +	if (console->exit)
> +		res = console->exit(console);
> +
>  	/* Changed console list, may require printer threads to start/stop. */
>  	printk_kthreads_check_locked();

Aside from documenting these new subtle relationships, I think this is
a good solution.

Note that LKML is not CC. I can offer my reviewed-by when the patch is
posted on LKML.

John Ogness

Re: [PATCH RFC 0/3] printk: Don't flush messages using write_atomic during console registration if kthreads have not been started yet.

[Michael Cobb]

Hi John, Petr,

Thanks for your time on this. I've had a look at John's suggestions
and I had a go at trying to remove the need for adding an additional
flag. Though I think Petr's solution is better than what I had come up
with.

On Tue, 3 Jun 2025 at 15:40, Petr Mladek <pmladek@suse.com> wrote:
>
> I hope that I have covered all the cases. Note that I haven't tested
> it with nbcon console though.
>
> What do you think, please?

Applied and tested this patch with an nbcon console, and I can see
that it's not causing an atomic flush. (Tested both with and without a
boot console/earlycon).

On Tue, 3 Jun 2025 at 17:09, John Ogness <john.ogness@linutronix.de> wrote:
>
> Note that LKML is not CC. I can offer my reviewed-by when the patch is
> posted on LKML.

I can also offer my Tested-by for this patch.

Kind regards,

Michael Cobb