| Message ID | 20250604142045.253301-1-pmladek@suse.com |
|---|---|
| State | New |
| Headers | show |
| Series | printk: Allow to use the printk kthread immediately even for 1st nbcon | expand |
On 2025-06-04, Petr Mladek <pmladek@suse.com> wrote: > 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> Reviewed-by: John Ogness <john.ogness@linutronix.de> Thanks Petr! And thank you Michael for looking into this. I think this will be a big improvement in boot times for a lot of developers. John
On Wed, 4 Jun 2025 at 15:21, Petr Mladek <pmladek@suse.com> wrote: > > 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> Tested-by: Michael Cobb <mcobb@thegoodpenguin.co.uk> With this patch, on Raspberry Pi 3B+, I'm seeing the kernel will reach userspace in ~1.5s, which is consistent with a boot with no console output (loglevel=1) and at slower baudrates too. For reference, I was seeing ~5s to reach userspace at 115200 baud and ~15s with initcall_debug turned on. Thanks for your work on this Petr and John for your support! Kind regards, Michael Cobb
On Wed 2025-06-04 16:20:45, Petr Mladek wrote: > 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> JFYI, the patch has been committed into printk/linux.git, branch rework/optimizations. Best Regards, Petr
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..d60596777d27 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; } } @@ -1716,14 +1722,30 @@ bool nbcon_alloc(struct console *con) /** * nbcon_free - Free and cleanup the nbcon console specific data * @con: Console to free/cleanup nbcon data + * + * Important: @have_nbcon_console must be updated before calling + * this function. In particular, it can be set only when there + * is still another nbcon console registered. */ 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. + * + * Do not rely on printk_kthreads_check_locked(). It is not + * called in some code paths, see nbcon_free() callers. + */ + if (!have_nbcon_console) + printk_kthreads_running = false; + } + nbcon_state_set(con, &state); /* Boot consoles share global printk buffers. */ diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c index 1eea80d0648e..0efbcdda9aab 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,15 @@ static int unregister_console_locked(struct console *console) if (!found_nbcon_con) have_nbcon_console = found_nbcon_con; + /* @have_nbcon_console must be updated before calling nbcon_free(). */ + 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();
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> --- Hi, I am sending this patch for a proper review. I have just updated comments according to the review. Otherwise, there is no function change against the already tested patch, see https://lore.kernel.org/all/aD8JOlDVP4ufgv44@pathway.suse.cz/ Best Regards, Petr kernel/printk/internal.h | 2 ++ kernel/printk/nbcon.c | 26 ++++++++++++++++++++++++-- kernel/printk/printk.c | 20 +++++++++++--------- 3 files changed, 37 insertions(+), 11 deletions(-)