Re: [PATCH v8 01/21] printk: Fully resolve loglevel before deciding printk delay suppression

[Petr Mladek <pmladek@suse.com>]

On Thu 2025-12-11 15:49:54, Petr Mladek wrote:
> On Tue 2025-12-09 17:40:11, Petr Mladek wrote:
> > On Fri 2025-11-28 03:43:12, Chris Down wrote:
> > > When printk_delay() is called from vprintk_emit(), the level argument
> > > may be LOGLEVEL_DEFAULT (-1) if the loglevel was not explicitly provided
> > > by the caller.
> > > 
> > > If printk_delay() relies on comparing level against the console loglevel
> > > (e.g. for suppression), receiving -1 results in incorrect behaviour
> > > because -1 is treated as a high priority (so not suppressed), causing
> > > unnecessary delays for default-level messages.
> > 
> > Great catch!
> > 
> > > Parse the format string prefix to resolve the actual loglevel before
> > > passing it to printk_delay().
> > > 
> > > --- a/kernel/printk/printk.c
> > > +++ b/kernel/printk/printk.c
> > > @@ -2179,6 +2179,32 @@ u16 printk_parse_prefix(const char *text, int *level,
> > >  	return prefix_len;
> > >  }
> > >  
> > > +/**
> > > + * printk_resolve_loglevel - Resolve the effective loglevel for a message
> > > + *
> > > + * @facility:	The log facility (0 for kernel messages)
> > > + * @level:	The initial loglevel, may be LOGLEVEL_DEFAULT
> > > + * @fmt:	The format string, potentially containing a loglevel prefix
> > > + *
> > > + * Determines the actual loglevel to use for a printk message. If the level
> > > + * is LOGLEVEL_DEFAULT and the facility indicates a kernel message, parses
> > > + * the format string prefix to extract an embedded loglevel. If no loglevel
> > > + * is found, falls back to the default_message_loglevel.
> > > + *
> > > + * Return: The resolved loglevel value
> > > + */
> > > +static inline int printk_resolve_loglevel(int facility, int level,
> > > +					  const char *fmt)
> > > +{
> > > +	if (facility == 0 && level == LOGLEVEL_DEFAULT && fmt)
> > > +		printk_parse_prefix(fmt, &level, NULL);
> > > +
> > > +	if (level == LOGLEVEL_DEFAULT)
> > > +		level = default_message_loglevel;
> > 
> > This is not ideal:
> > 
> >  1. It more or less duplicates the code from vprintk_store().
> > 
> >  2. It does not handle loglevel passed via parameter, for example, see
> >     _btrfs_printk() which calls _printk("%sBTRFS %s: %pV\n", lvl, type, &vaf).
> >     Note that vprintk_store() calls vsnprintf() before checking the loglevel.
> > 
> > > +	return level;
> > > +}
> > 
> > Alternative solutions:
> > 
> >   A. We might call vsnprintf() one more times here.
> > 
> >      It is ugly but we could do it only when anyone wants a delay.
> >      Also this is not easy because we would need to check printk_delay_msec,
> >      boot_delay, and system_state.
> > 
> >      Anyway, this solution would need some refactoring in printk_delay()
> >      and vprintk_store() to avoid code duplication.
> 
> Even more duplicated code was added by later patches.
> 
> I tried to implement this alternative solution and remove all code
> duplication. But I think that this is a wrong way after all:

The solution is not good:

  + It adds a lot of code complexity and one more vscnprintf() is needed.

  + One more vscnprintf() call is needed.

  + It still does not work properly. For example, backtraces from
    all CPUs (SysRq l) prints the entire backtrace at once because
    the console flush is delayed. The same problem will happen for
    any delayed messages, e.g. during early boot before the 1st console
    is registered.

 >   B. We could move printk_delay().
> > 
> >      It should be called before storing the message. Otherwise, we
> >      would need to call it from various console flush calls. And there
> >      are many flush paths. Also the message might get lost when
> >      consoles fall far behind.

I looked at this variant and I think that it might be much better
after all. IMHO, it should be enough to move printk_delay() from
vprintk_emit() to:

   + console_flush_one_record()
   + nbcon_emit_one()

Note that it is possible only in 6.19. It includes some refactoring
which allows to release locks between each record in both legacy
and nbcon code paths. One piece is still missing, see
https://lore.kernel.org/r/20251202135832.156559-1-pmladek@suse.com

I would suggest to solve this separately. The printk_delay() never
worked correctly. And it seems to be a more complex problem.

I mean. Let's keep this patchset only for adding per-console loglevels.
Do only the bare minimum (like in v7) and remove the rather complex
improvements added in v8.

Or we could move the printk_delay to console emit code paths first.
And rebase the per-console patchset on top of it.

Sigh, I do not want to block the per-console patchset once again.
But the printk_delay()-related changes in v8 are too hacky my taste.

Best Regards,
Petr