[PATCH] boot_delay should only affect output

[PATCH] boot_delay should only affect output

[Andrew Cooks]

The boot_delay parameter affects all printk(), even if the log level
 prevents visible output from the call. It results in delays greater
 than the user intended without purpose.

This patch changes the behaviour of boot_delay to only delay output.

Signed-off-by: Andrew Cooks <acooks@gmail.com>
---
 kernel/printk.c |   40 +++++++++++++++++++++-------------------
 1 files changed, 21 insertions(+), 19 deletions(-)

diff --git a/kernel/printk.c b/kernel/printk.c
index 66a2ea3..c098003 100644
--- a/kernel/printk.c
+++ b/kernel/printk.c
@@ -741,6 +741,21 @@ void __init setup_log_buf(int early)
 		free, (free * 100) / __LOG_BUF_LEN);
 }
 
+static bool __read_mostly ignore_loglevel;
+
+static int __init ignore_loglevel_setup(char *str)
+{
+	ignore_loglevel = 1;
+	printk(KERN_INFO "debug: ignoring loglevel setting.\n");
+
+	return 0;
+}
+
+early_param("ignore_loglevel", ignore_loglevel_setup);
+module_param(ignore_loglevel, bool, S_IRUGO | S_IWUSR);
+MODULE_PARM_DESC(ignore_loglevel, "ignore loglevel setting, to"
+	"print all kernel messages to the console.");
+
 #ifdef CONFIG_BOOT_PRINTK_DELAY
 
 static int boot_delay; /* msecs delay after each printk during bootup */
@@ -764,13 +779,15 @@ static int __init boot_delay_setup(char *str)
 }
 __setup("boot_delay=", boot_delay_setup);
 
-static void boot_delay_msec(void)
+static void boot_delay_msec(int level)
 {
 	unsigned long long k;
 	unsigned long timeout;
 
-	if (boot_delay == 0 || system_state != SYSTEM_BOOTING)
+	if ((boot_delay == 0 || system_state != SYSTEM_BOOTING)
+		|| (level >= console_loglevel && !ignore_loglevel)) {
 		return;
+	}
 
 	k = (unsigned long long)loops_per_msec * boot_delay;
 
@@ -789,7 +806,7 @@ static void boot_delay_msec(void)
 	}
 }
 #else
-static inline void boot_delay_msec(void)
+static inline void boot_delay_msec(int level)
 {
 }
 #endif
@@ -1232,21 +1249,6 @@ SYSCALL_DEFINE3(syslog, int, type, char __user *, buf, int, len)
 	return do_syslog(type, buf, len, SYSLOG_FROM_CALL);
 }
 
-static bool __read_mostly ignore_loglevel;
-
-static int __init ignore_loglevel_setup(char *str)
-{
-	ignore_loglevel = 1;
-	printk(KERN_INFO "debug: ignoring loglevel setting.\n");
-
-	return 0;
-}
-
-early_param("ignore_loglevel", ignore_loglevel_setup);
-module_param(ignore_loglevel, bool, S_IRUGO | S_IWUSR);
-MODULE_PARM_DESC(ignore_loglevel, "ignore loglevel setting, to"
-	"print all kernel messages to the console.");
-
 /*
  * Call the console drivers, asking them to write out
  * log_buf[start] to log_buf[end - 1].
@@ -1492,7 +1494,7 @@ asmlinkage int vprintk_emit(int facility, int level,
 	int this_cpu;
 	int printed_len = 0;
 
-	boot_delay_msec();
+	boot_delay_msec(level);
 	printk_delay();
 
 	/* This stops the holder of console_sem just where we want him */
-- 
1.7.1

Re: [PATCH] boot_delay should only affect output

[Randy Dunlap]

On 11/12/2012 10:50 PM, Andrew Cooks wrote:

> The boot_delay parameter affects all printk(), even if the log level
>  prevents visible output from the call. It results in delays greater
>  than the user intended without purpose.
> 
> This patch changes the behaviour of boot_delay to only delay output.
> 
> Signed-off-by: Andrew Cooks <acooks@gmail.com>


Acked-by: Randy Dunlap <rdunlap@infradead.org>

Thanks.

> ---
>  kernel/printk.c |   40 +++++++++++++++++++++-------------------
>  1 files changed, 21 insertions(+), 19 deletions(-)
> 
> diff --git a/kernel/printk.c b/kernel/printk.c
> index 66a2ea3..c098003 100644
> --- a/kernel/printk.c
> +++ b/kernel/printk.c
> @@ -741,6 +741,21 @@ void __init setup_log_buf(int early)
>  		free, (free * 100) / __LOG_BUF_LEN);
>  }
>  
> +static bool __read_mostly ignore_loglevel;
> +
> +static int __init ignore_loglevel_setup(char *str)
> +{
> +	ignore_loglevel = 1;
> +	printk(KERN_INFO "debug: ignoring loglevel setting.\n");
> +
> +	return 0;
> +}
> +
> +early_param("ignore_loglevel", ignore_loglevel_setup);
> +module_param(ignore_loglevel, bool, S_IRUGO | S_IWUSR);
> +MODULE_PARM_DESC(ignore_loglevel, "ignore loglevel setting, to"
> +	"print all kernel messages to the console.");
> +
>  #ifdef CONFIG_BOOT_PRINTK_DELAY
>  
>  static int boot_delay; /* msecs delay after each printk during bootup */
> @@ -764,13 +779,15 @@ static int __init boot_delay_setup(char *str)
>  }
>  __setup("boot_delay=", boot_delay_setup);
>  
> -static void boot_delay_msec(void)
> +static void boot_delay_msec(int level)
>  {
>  	unsigned long long k;
>  	unsigned long timeout;
>  
> -	if (boot_delay == 0 || system_state != SYSTEM_BOOTING)
> +	if ((boot_delay == 0 || system_state != SYSTEM_BOOTING)
> +		|| (level >= console_loglevel && !ignore_loglevel)) {
>  		return;
> +	}
>  
>  	k = (unsigned long long)loops_per_msec * boot_delay;
>  
> @@ -789,7 +806,7 @@ static void boot_delay_msec(void)
>  	}
>  }
>  #else
> -static inline void boot_delay_msec(void)
> +static inline void boot_delay_msec(int level)
>  {
>  }
>  #endif
> @@ -1232,21 +1249,6 @@ SYSCALL_DEFINE3(syslog, int, type, char __user *, buf, int, len)
>  	return do_syslog(type, buf, len, SYSLOG_FROM_CALL);
>  }
>  
> -static bool __read_mostly ignore_loglevel;
> -
> -static int __init ignore_loglevel_setup(char *str)
> -{
> -	ignore_loglevel = 1;
> -	printk(KERN_INFO "debug: ignoring loglevel setting.\n");
> -
> -	return 0;
> -}
> -
> -early_param("ignore_loglevel", ignore_loglevel_setup);
> -module_param(ignore_loglevel, bool, S_IRUGO | S_IWUSR);
> -MODULE_PARM_DESC(ignore_loglevel, "ignore loglevel setting, to"
> -	"print all kernel messages to the console.");
> -
>  /*
>   * Call the console drivers, asking them to write out
>   * log_buf[start] to log_buf[end - 1].
> @@ -1492,7 +1494,7 @@ asmlinkage int vprintk_emit(int facility, int level,
>  	int this_cpu;
>  	int printed_len = 0;
>  
> -	boot_delay_msec();
> +	boot_delay_msec(level);
>  	printk_delay();
>  
>  	/* This stops the holder of console_sem just where we want him */



-- 
~Randy

Re: [PATCH] boot_delay should only affect output

[Andrew Cooks]

Hi Joe

On Wed, Nov 14, 2012 at 4:31 PM, Joe Perches <joe@perches.com> wrote:
> On Tue, 2012-11-13 at 14:50 +0800, Andrew Cooks wrote:
>> The boot_delay parameter affects all printk(), even if the log level
>>  prevents visible output from the call. It results in delays greater
>>  than the user intended without purpose.
>>
>> This patch changes the behaviour of boot_delay to only delay output.
>
> Seems sensible.
>
> Couldn't that be done for printk_delay too?
>

This was only my second submitted patch, so I tried to keep things as
simple as possible to get the process right.

When printk_delay is called, the log message is written into a buffer
regardless of log level. The log level may change before the logs are
flushed to console/syslog, so delaying based on log level at the
buffer input side is not ideal.

I thought about moving the delay to the point where the buffer is
cleared, but that seems like it would drastically increase the
likelihood of dropping messages under load.

Dropping the message in vprintk_emit, before any delay or buffer
management might also be an option, though I'm not sure if it's
acceptable for printk to return 0.

a.