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

[Petr Mladek <pmladek@suse.com>]

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.


  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 though about moving printk_delay() into vprintk_store(). But
     we would need to temporary release IRQs disabled by
     printk_enter_irqsave(recursion_ptr, irqflags). But then the
     process might get migrated to another CPU. And the message
     generated by printk_sprint() need not fit into the reserved space.


I personally prefer the alternative solution A. But I am not sure if
it is worth it.

Best Regards,
Petr