[PATCH v8 09/21] printk: Optimise printk_delay() to avoid walking consoles under SRCU

Chris Down posted 21 patches 2 months, 1 week ago
Only 20 patches received!
[PATCH v8 09/21] printk: Optimise printk_delay() to avoid walking consoles under SRCU
Posted by Chris Down 2 months, 1 week ago
As part of the per-console loglevel implementation, printk_delay()
introduces a call to suppress_message_printing_everywhere() within
printk_delay(). This check acquires the console SRCU lock and iterates
through all registered consoles to determine if the message implies a
delay based on per-console loglevels.

Since printk_delay() is called in the hotpath of vprintk_emit(), this
introduces measurable overhead (locking and pointer chasing) for every
printk message, even on systems where no delay is configured.

Optimise this by short-circuiting the function. If neither a boot delay
nor a runtime printk_delay_msec is configured, return immediately. This
avoids the expensive console list iteration in the common case where
delays are disabled.

Signed-off-by: Chris Down <chris@chrisdown.name>
---
 kernel/printk/printk.c | 25 ++++++++++++++++++-------
 1 file changed, 18 insertions(+), 7 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 0d7f3dac8177..13e17d892ec9 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2233,20 +2233,31 @@ int printk_delay_msec __read_mostly;
 
 static inline void printk_delay(int level)
 {
+	bool boot_delay_active = false;
+	int m;
+
+#ifdef CONFIG_BOOT_PRINTK_DELAY
+	boot_delay_active = boot_delay && system_state < SYSTEM_RUNNING;
+#endif
+
+	if (!boot_delay_active && !READ_ONCE(printk_delay_msec))
+		return;
+
 	/* If the message is forced (e.g. panic), we must delay */
 	if (!is_printk_force_console() &&
 	    suppress_message_printing_everywhere(level))
 		return;
 
-	boot_delay_msec();
+	if (boot_delay_active)
+		boot_delay_msec();
 
-	if (unlikely(printk_delay_msec)) {
-		int m = printk_delay_msec;
+	m = READ_ONCE(printk_delay_msec);
+	if (!m)
+		return;
 
-		while (m--) {
-			mdelay(1);
-			touch_nmi_watchdog();
-		}
+	while (m--) {
+		mdelay(1);
+		touch_nmi_watchdog();
 	}
 }
 
-- 
2.51.2
Re: [PATCH v8 09/21] printk: Optimise printk_delay() to avoid walking consoles under SRCU
Posted by Petr Mladek 1 month, 4 weeks ago
On Fri 2025-11-28 03:43:42, Chris Down wrote:
> As part of the per-console loglevel implementation, printk_delay()
> introduces a call to suppress_message_printing_everywhere() within
> printk_delay(). This check acquires the console SRCU lock and iterates
> through all registered consoles to determine if the message implies a
> delay based on per-console loglevels.
> 
> Since printk_delay() is called in the hotpath of vprintk_emit(), this
> introduces measurable overhead (locking and pointer chasing) for every
> printk message, even on systems where no delay is configured.
> 
> Optimise this by short-circuiting the function. If neither a boot delay
> nor a runtime printk_delay_msec is configured, return immediately. This
> avoids the expensive console list iteration in the common case where
> delays are disabled.
> 
> Signed-off-by: Chris Down <chris@chrisdown.name>
> ---
>  kernel/printk/printk.c | 25 ++++++++++++++++++-------
>  1 file changed, 18 insertions(+), 7 deletions(-)
> 
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index 0d7f3dac8177..13e17d892ec9 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -2233,20 +2233,31 @@ int printk_delay_msec __read_mostly;
>  
>  static inline void printk_delay(int level)
>  {
> +	bool boot_delay_active = false;
> +	int m;
> +
> +#ifdef CONFIG_BOOT_PRINTK_DELAY
> +	boot_delay_active = boot_delay && system_state < SYSTEM_RUNNING;
> +#endif

The same code is used also in boot_delay_msec(). It can be removed
there. But still, it would be better to create a helper function
and avoid the #ifdef in the middle of the function.

> +	if (!boot_delay_active && !READ_ONCE(printk_delay_msec))

There is another READ_ONCE(printk_delay_msec) below. It would
be better to read the value at the beginning of the function
and use it everywhere.

> +		return;
> +
>  	/* If the message is forced (e.g. panic), we must delay */
>  	if (!is_printk_force_console() &&
>  	    suppress_message_printing_everywhere(level))
>  		return;
>  
> -	boot_delay_msec();
> +	if (boot_delay_active)
> +		boot_delay_msec();
>  
> -	if (unlikely(printk_delay_msec)) {
> -		int m = printk_delay_msec;
> +	m = READ_ONCE(printk_delay_msec);
> +	if (!m)
> +		return;
>  
> -		while (m--) {
> -			mdelay(1);
> -			touch_nmi_watchdog();
> -		}
> +	while (m--) {
> +		mdelay(1);
> +		touch_nmi_watchdog();
>  	}
>  }

I played with the code. I am going to send my variant as a reply to
the 1st patch where I proposed 2 alternative solutions, see
https://lore.kernel.org/all/aThQ5mZNIijc1G94@pathway

Best Regards,
Petr