mbox series

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

Message ID 20250514173514.2117832-1-mcobb@thegoodpenguin.co.uk
Headers show
Series printk: Don't flush messages using write_atomic during console registration if kthreads have not been started yet. | expand

Message

Michael Cobb May 14, 2025, 5:35 p.m. UTC 
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(-)