[PATCH RFC 3/4] printk: nbcon: move printk_delay to console emiting code
Andrew Murray
amurray at thegoodpenguin.co.uk
Sun Jun 14 12:17:10 PDT 2026
On Mon, 8 Jun 2026 at 16:25, Petr Mladek <pmladek at suse.com> wrote:
>
> On Mon 2026-06-01 00:17:39, Andrew Murray wrote:
> > The printk_delay and boot_delay features are helpful for debugging
> > as kernel output can be slowed down during boot allowing messages to
> > be seen before scrolling off the screen, or to correlate timing between
> > some physical event and console output.
> >
> > However, since the introduction of nbcon and the legacy printer thread
> > for PREEMPT_RT kernels, printk records are now emited to the console
> > asynchronously to the caller of printk. Thus, any printk delay added by
> > boot_delay/printk_delay continues to slow down the calling process but
> > may not have any impact to the rate in which records are emited to the
> > console.
> >
> > Let's address this by moving the printk delay from the calling code
> > to the console emiting code instead. Whilst this ensures that delays
> > are still observed (especially for slower consoles), it doesn't improve
> > the use-case of using boot_delay/printk_delay to correlate timings
> > between physical events and console output.
> >
> > --- a/include/linux/printk.h
> > +++ b/include/linux/printk.h
>
> The declaration is needed just inside kernel/printk/ directory.
> It should better be done via kernel/printk/internal.h
>
> > @@ -209,6 +209,7 @@ extern bool nbcon_device_try_acquire(struct console *con);
> > extern void nbcon_device_release(struct console *con);
> > void nbcon_atomic_flush_unsafe(void);
> > bool pr_flush(int timeout_ms, bool reset_on_progress);
> > +void printk_delay(bool use_atomic);
> > #else
> > static inline __printf(1, 0)
> > int vprintk(const char *s, va_list args)
> > @@ -326,6 +327,9 @@ static inline bool pr_flush(int timeout_ms, bool reset_on_progress)
> > {
> > return true;
> > }
> > +static inline void printk_delay(bool use_atomic)
> > +{
> > +}
> >
> > #endif
> >
> > diff --git a/kernel/printk/nbcon.c b/kernel/printk/nbcon.c
> > index d7044a7a214bdd4537a5e20d876d99bc3ffe8b3a..a507a2fed5bf4366e24330f763b842a698ecf6f7 100644
> > --- a/kernel/printk/nbcon.c
> > +++ b/kernel/printk/nbcon.c
> > @@ -1267,11 +1267,16 @@ static int nbcon_kthread_func(void *__console)
> >
> > con_flags = console_srcu_read_flags(con);
> >
> > + wctxt.len = 0;
> > +
> > if (console_is_usable(con, con_flags, false))
> > backlog = nbcon_emit_one(&wctxt, false);
> >
> > console_srcu_read_unlock(cookie);
> >
> > + if (backlog && wctxt.len > 0)
>
> Heh, this is tricky. It might probably work but it is not guarantted
> by design.
>
> The "backlog" name is a bit misleading. The value is basically
> wctxt.ctxt.backlog. The real meaning is that printk_get_next_message()
> was able to read a message. It means that there _was_ a backlog.
> But it is not clear whether there are still pending messages or not.
>
> Also it is not clear that whether the message was pushed to the
> console or not. It might have been supressed in which case
> (wctxt.len == 0). But it might also be emitted only partially
> when a higher priority context took over the console context
> ownership.
>
> I would prefer to explicitely set some flag when
> nbcon_emit_next_record() really called con->write*().
> See below.
>
> > + printk_delay(false);
> > +
> > cond_resched();
> >
> > } while (backlog);
> > @@ -1525,6 +1530,8 @@ bool nbcon_legacy_emit_next_record(struct console *con, bool *handover,
> > }
> >
> > progress = nbcon_emit_one(&wctxt, use_atomic);
> > + if (progress && wctxt.len > 0)
>
> Same here.
>
> > + printk_delay(use_atomic);
> >
> > if (use_atomic) {
> > start_critical_timings();
> > @@ -1584,6 +1591,8 @@ static int __nbcon_atomic_flush_pending_con(struct console *con, u64 stop_seq)
> > if (!nbcon_context_try_acquire(ctxt, false))
> > return -EPERM;
> >
> > + wctxt.len = 0;
> > +
> > /*
> > * nbcon_emit_next_record() returns false when
> > * the console was handed over or taken over.
> > @@ -1595,7 +1604,9 @@ static int __nbcon_atomic_flush_pending_con(struct console *con, u64 stop_seq)
> > nbcon_context_release(ctxt);
> > }
> >
> > - if (!ctxt->backlog) {
> > + if (ctxt->backlog && wctxt.len > 0) {
> > + printk_delay(true);
> > + } else {
>
> This changes the semantic. The original code call this when
> no message was read. The new code would call this path also
> when the output was suppressed. It would probably work.
> But still.
>
> > /* Are there reserved but not yet finalized records? */
> > if (nbcon_seq_read(con) < stop_seq)
> > err = -ENOENT;
>
>
> As mentioned above, I would add a flag which would be set when
> con->write*() was called.
>
> It modifies the type of unsafe_takeover in struct nbcon_write_context.
> But it actually makes it more compatible with struct nbcon_state.
>
> My proposal (on top of this patch):
>
> diff --git a/include/linux/console.h b/include/linux/console.h
> index 5520e4477ad7..5a86942e55ef 100644
> --- a/include/linux/console.h
> +++ b/include/linux/console.h
> @@ -290,6 +290,7 @@ struct nbcon_context {
> * @outbuf: Pointer to the text buffer for output
> * @len: Length to write
> * @unsafe_takeover: If a hostile takeover in an unsafe state has occurred
> + * @emitted: The write context tried to emit the message. Might be incomplete.
> * @cpu: CPU on which the message was generated
> * @pid: PID of the task that generated the message
> * @comm: Name of the task that generated the message
> @@ -298,7 +299,8 @@ struct nbcon_write_context {
> struct nbcon_context __private ctxt;
> char *outbuf;
> unsigned int len;
> - bool unsafe_takeover;
> + unsigned char unsafe_takeover : 1;
> + unsigned char emitted : 1
> #ifdef CONFIG_PRINTK_EXECUTION_CTX
> int cpu;
> pid_t pid;
> diff --git a/kernel/printk/nbcon.c b/kernel/printk/nbcon.c
> index a507a2fed5bf..060534becefc 100644
> --- a/kernel/printk/nbcon.c
> +++ b/kernel/printk/nbcon.c
> @@ -1069,6 +1069,9 @@ static bool nbcon_emit_next_record(struct nbcon_write_context *wctxt, bool use_a
> else
> con->write_thread(con, wctxt);
>
> + /* Tried to emit something. Might be incomplete. */
> + wctxt.emitted = 1;
> +
> if (!wctxt->outbuf) {
> /*
> * Ownership was lost and reacquired by the driver. Handle it
> @@ -1267,14 +1270,14 @@ static int nbcon_kthread_func(void *__console)
>
> con_flags = console_srcu_read_flags(con);
>
> - wctxt.len = 0;
> + wctxt.emitted = 0;
>
> if (console_is_usable(con, con_flags, false))
> backlog = nbcon_emit_one(&wctxt, false);
>
> console_srcu_read_unlock(cookie);
>
> - if (backlog && wctxt.len > 0)
> + if (wctxt.emitted)
I think this (and the others) should be:
if (backlog && wctxt.emitted)
Otherwise you may delay in instances where con->write_* was called but
ownership is lost, for example if write_thread calls
nbcon_enter_unsafe which returns false and doesn't write anything. I
assume that when ownership is lost, the record will be reattempted in
the future, thus it would presumably make sense to delay upon
successful emit, rather than each/any partial attempt? Is that
understanding correct?
Thanks,
Andrew Murray
>
> printk_delay(false);
>
> cond_resched();
> @@ -1530,7 +1533,7 @@ bool nbcon_legacy_emit_next_record(struct console *con, bool *handover,
> }
>
> progress = nbcon_emit_one(&wctxt, use_atomic);
> - if (progress && wctxt.len > 0)
> + if (wctxt.emitted)
> printk_delay(use_atomic);
>
> if (use_atomic) {
> @@ -1591,7 +1594,7 @@ static int __nbcon_atomic_flush_pending_con(struct console *con, u64 stop_seq)
> if (!nbcon_context_try_acquire(ctxt, false))
> return -EPERM;
>
> - wctxt.len = 0;
> + wctxt.emitted = 0;
>
> /*
> * nbcon_emit_next_record() returns false when
> @@ -1604,9 +1607,10 @@ static int __nbcon_atomic_flush_pending_con(struct console *con, u64 stop_seq)
> nbcon_context_release(ctxt);
> }
>
> - if (ctxt->backlog && wctxt.len > 0) {
> + if (wctxt.emitted)
> printk_delay(true);
> - } else {
> +
> + if (!ctxt->backlog) {
> /* Are there reserved but not yet finalized records? */
> if (nbcon_seq_read(con) < stop_seq)
> err = -ENOENT;
More information about the linux-arm-kernel
mailing list