[PATCH] Fix faulty logic in the case of recursive printk

[PATCH] Fix faulty logic in the case of recursive printk

[Patrick Palka]

We shouldn't set text_len in the code path that detects printk recursion
because text_len corresponds to the length of the string inside textbuf.
A few lines down from the line

    text_len = strlen(recursion_msg);

is the line

    text_len += vscnprintf(text + text_len, ...);

So if printk detects recursion, it sets text_len to 29 and logs an
error.  Then the message supplied by the caller of printk is stored
inside textbuf but offset by 29 bytes.  This means that the output of
the recursive call to printk will contain 29 bytes of garbage in front
of it.

This defect is caused by commit 458df9fd ("printk: remove separate
printk_sched buffers and use printk buf instead") which turned

    text_len = vscnprintf(text + text_len, ...);

into

    text_len += vscnprintf(text + text_len, ...);

To fix this, this patch avoids setting text_len when logging the printk
recursion error.  This patch also performs a couple of local
micro-optimizations (use unlikely() and ARRAY_SIZE()).

Signed-off-by: Patrick Palka <patrick@parcs.ath.cx>
---
 kernel/printk/printk.c | 6 +++---
 1 file changed, 3 insertions(+), 3 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index e04c455..c101ec2 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1665,15 +1665,15 @@ asmlinkage int vprintk_emit(int facility, int level,
 	raw_spin_lock(&logbuf_lock);
 	logbuf_cpu = this_cpu;
 
-	if (recursion_bug) {
+	if (unlikely(recursion_bug)) {
 		static const char recursion_msg[] =
 			"BUG: recent printk recursion!";
 
 		recursion_bug = 0;
-		text_len = strlen(recursion_msg);
 		/* emit KERN_CRIT message */
 		printed_len += log_store(0, 2, LOG_PREFIX|LOG_NEWLINE, 0,
-					 NULL, 0, recursion_msg, text_len);
+					 NULL, 0, recursion_msg,
+					 ARRAY_SIZE(recursion_msg) - 1);
 	}
 
 	/*
-- 
2.1.0

Re: [PATCH] Fix faulty logic in the case of recursive printk

[Jan Kara]

On Sun 24-08-14 12:01:36, Patrick Palka wrote:
> We shouldn't set text_len in the code path that detects printk recursion
> because text_len corresponds to the length of the string inside textbuf.
> A few lines down from the line
> 
>     text_len = strlen(recursion_msg);
> 
> is the line
> 
>     text_len += vscnprintf(text + text_len, ...);
> 
> So if printk detects recursion, it sets text_len to 29 and logs an
> error.  Then the message supplied by the caller of printk is stored
> inside textbuf but offset by 29 bytes.  This means that the output of
> the recursive call to printk will contain 29 bytes of garbage in front
> of it.
> 
> This defect is caused by commit 458df9fd ("printk: remove separate
> printk_sched buffers and use printk buf instead") which turned
> 
>     text_len = vscnprintf(text + text_len, ...);
> 
> into
> 
>     text_len += vscnprintf(text + text_len, ...);
> 
> To fix this, this patch avoids setting text_len when logging the printk
> recursion error.  This patch also performs a couple of local
> micro-optimizations (use unlikely() and ARRAY_SIZE()).
  Thanks for spotting this! Just one nit below:

> Signed-off-by: Patrick Palka <patrick@parcs.ath.cx>
> ---
>  kernel/printk/printk.c | 6 +++---
>  1 file changed, 3 insertions(+), 3 deletions(-)
> 
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index e04c455..c101ec2 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -1665,15 +1665,15 @@ asmlinkage int vprintk_emit(int facility, int level,
>  	raw_spin_lock(&logbuf_lock);
>  	logbuf_cpu = this_cpu;
>  
> -	if (recursion_bug) {
> +	if (unlikely(recursion_bug)) {
>  		static const char recursion_msg[] =
>  			"BUG: recent printk recursion!";
>  
>  		recursion_bug = 0;
> -		text_len = strlen(recursion_msg);
>  		/* emit KERN_CRIT message */
>  		printed_len += log_store(0, 2, LOG_PREFIX|LOG_NEWLINE, 0,
> -					 NULL, 0, recursion_msg, text_len);
> +					 NULL, 0, recursion_msg,
> +					 ARRAY_SIZE(recursion_msg) - 1);
  I'd prefer to keep using strlen(recursion_msg). It is more obvious what
it does and is more futureproof.

								Honza
-- 
Jan Kara <jack@suse.cz>
SUSE Labs, CR

Re: [PATCH] Fix faulty logic in the case of recursive printk

[Petr Mládek]

On Sun 24-08-14 12:01:36, Patrick Palka wrote:
> We shouldn't set text_len in the code path that detects printk recursion
> because text_len corresponds to the length of the string inside textbuf.
> A few lines down from the line
> 
>     text_len = strlen(recursion_msg);
> 
> is the line
> 
>     text_len += vscnprintf(text + text_len, ...);
> 
> So if printk detects recursion, it sets text_len to 29 and logs an
> error.  Then the message supplied by the caller of printk is stored
> inside textbuf but offset by 29 bytes.  This means that the output of
> the recursive call to printk will contain 29 bytes of garbage in front
> of it.
> 
> This defect is caused by commit 458df9fd ("printk: remove separate
> printk_sched buffers and use printk buf instead") which turned
> 
>     text_len = vscnprintf(text + text_len, ...);
> 
> into
> 
>     text_len += vscnprintf(text + text_len, ...);
> 
> To fix this, this patch avoids setting text_len when logging the printk
> recursion error.  This patch also performs a couple of local
> micro-optimizations (use unlikely() and ARRAY_SIZE()).

Great catch! And I agree with Jack about that strlen.
 
> Signed-off-by: Patrick Palka <patrick@parcs.ath.cx>
> ---
>  kernel/printk/printk.c | 6 +++---
>  1 file changed, 3 insertions(+), 3 deletions(-)
> 
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index e04c455..c101ec2 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -1665,15 +1665,15 @@ asmlinkage int vprintk_emit(int facility, int level,
>  	raw_spin_lock(&logbuf_lock);
>  	logbuf_cpu = this_cpu;
>  
> -	if (recursion_bug) {
> +	if (unlikely(recursion_bug)) {
>  		static const char recursion_msg[] =
>  			"BUG: recent printk recursion!";
>  
>  		recursion_bug = 0;
> -		text_len = strlen(recursion_msg);
>  		/* emit KERN_CRIT message */
>  		printed_len += log_store(0, 2, LOG_PREFIX|LOG_NEWLINE, 0,
> -					 NULL, 0, recursion_msg, text_len);
> +					 NULL, 0, recursion_msg,
> +					 ARRAY_SIZE(recursion_msg) - 1);
>  	}
>  
>  	/*
> -- 
> 2.1.0
> 

[PATCH] Fix faulty logic in the case of recursive printk

[Patrick Palka]

Thanks for reviewing!  I have put back the call to strlen() and adjusted
the commit message accordingly.

Patrick

-- >8 --

We shouldn't set text_len in the code path that detects printk recursion
because text_len corresponds to the length of the string inside textbuf.
A few lines down from the line

    text_len = strlen(recursion_msg);

is the line

    text_len += vscnprintf(text + text_len, ...);

So if printk detects recursion, it sets text_len to 29 (the length of
recursion_msg) and logs an error.  Then the message supplied by the
caller of printk is stored inside textbuf but offset by 29 bytes.  This
means that the output of the recursive call to printk will contain 29
bytes of garbage in front of it.

This defect is caused by commit 458df9fd ("printk: remove separate
printk_sched buffers and use printk buf instead") which turned the line

    text_len = vscnprintf(text, ...);

into

    text_len += vscnprintf(text + text_len, ...);

To fix this, this patch avoids setting text_len when logging the printk
recursion error.  This patch also marks unlikely() the branch leading
up to this code.

Signed-off-by: Patrick Palka <patrick@parcs.ath.cx>
---
 kernel/printk/printk.c | 6 +++---
 1 file changed, 3 insertions(+), 3 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index e04c455..1ce7706 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1665,15 +1665,15 @@ asmlinkage int vprintk_emit(int facility, int level,
 	raw_spin_lock(&logbuf_lock);
 	logbuf_cpu = this_cpu;
 
-	if (recursion_bug) {
+	if (unlikely(recursion_bug)) {
 		static const char recursion_msg[] =
 			"BUG: recent printk recursion!";
 
 		recursion_bug = 0;
-		text_len = strlen(recursion_msg);
 		/* emit KERN_CRIT message */
 		printed_len += log_store(0, 2, LOG_PREFIX|LOG_NEWLINE, 0,
-					 NULL, 0, recursion_msg, text_len);
+					 NULL, 0, recursion_msg,
+					 strlen(recursion_msg));
 	}
 
 	/*
-- 
2.1.0

Re: [PATCH] Fix faulty logic in the case of recursive printk

[Jan Kara]

On Tue 26-08-14 07:23:22, Patrick Palka wrote:
> Thanks for reviewing!  I have put back the call to strlen() and adjusted
> the commit message accordingly.
> 
> Patrick
> 
> -- >8 --
> 
> We shouldn't set text_len in the code path that detects printk recursion
> because text_len corresponds to the length of the string inside textbuf.
> A few lines down from the line
> 
>     text_len = strlen(recursion_msg);
> 
> is the line
> 
>     text_len += vscnprintf(text + text_len, ...);
> 
> So if printk detects recursion, it sets text_len to 29 (the length of
> recursion_msg) and logs an error.  Then the message supplied by the
> caller of printk is stored inside textbuf but offset by 29 bytes.  This
> means that the output of the recursive call to printk will contain 29
> bytes of garbage in front of it.
> 
> This defect is caused by commit 458df9fd ("printk: remove separate
> printk_sched buffers and use printk buf instead") which turned the line
> 
>     text_len = vscnprintf(text, ...);
> 
> into
> 
>     text_len += vscnprintf(text + text_len, ...);
> 
> To fix this, this patch avoids setting text_len when logging the printk
> recursion error.  This patch also marks unlikely() the branch leading
> up to this code.
> 
> Signed-off-by: Patrick Palka <patrick@parcs.ath.cx>
  The patch looks good. You can add:
Reviewed-by: Jan Kara <jack@suse.cz>

  Plus you could also add tags:
Fixes: 458df9fd4815b47809875d57f42e16401674b621
CC: stable@vger.kernel.org

								Honza
> ---
>  kernel/printk/printk.c | 6 +++---
>  1 file changed, 3 insertions(+), 3 deletions(-)
> 
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index e04c455..1ce7706 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -1665,15 +1665,15 @@ asmlinkage int vprintk_emit(int facility, int level,
>  	raw_spin_lock(&logbuf_lock);
>  	logbuf_cpu = this_cpu;
>  
> -	if (recursion_bug) {
> +	if (unlikely(recursion_bug)) {
>  		static const char recursion_msg[] =
>  			"BUG: recent printk recursion!";
>  
>  		recursion_bug = 0;
> -		text_len = strlen(recursion_msg);
>  		/* emit KERN_CRIT message */
>  		printed_len += log_store(0, 2, LOG_PREFIX|LOG_NEWLINE, 0,
> -					 NULL, 0, recursion_msg, text_len);
> +					 NULL, 0, recursion_msg,
> +					 strlen(recursion_msg));
>  	}
>  
>  	/*
> -- 
> 2.1.0
> 
-- 
Jan Kara <jack@suse.cz>
SUSE Labs, CR

Re: [PATCH] Fix faulty logic in the case of recursive printk

[Steven Rostedt]

On Tue, 26 Aug 2014 11:19:41 +0200
Petr Mládek <pmladek@suse.cz> wrote:

> On Sun 24-08-14 12:01:36, Patrick Palka wrote:
> > We shouldn't set text_len in the code path that detects printk recursion
> > because text_len corresponds to the length of the string inside textbuf.
> > A few lines down from the line
> > 
> >     text_len = strlen(recursion_msg);
> > 
> > is the line
> > 
> >     text_len += vscnprintf(text + text_len, ...);
> > 
> > So if printk detects recursion, it sets text_len to 29 and logs an
> > error.  Then the message supplied by the caller of printk is stored
> > inside textbuf but offset by 29 bytes.  This means that the output of
> > the recursive call to printk will contain 29 bytes of garbage in front
> > of it.
> > 
> > This defect is caused by commit 458df9fd ("printk: remove separate
> > printk_sched buffers and use printk buf instead") which turned
> > 
> >     text_len = vscnprintf(text + text_len, ...);
> > 
> > into
> > 
> >     text_len += vscnprintf(text + text_len, ...);
> > 
> > To fix this, this patch avoids setting text_len when logging the printk
> > recursion error.  This patch also performs a couple of local
> > micro-optimizations (use unlikely() and ARRAY_SIZE()).
> 
> Great catch! And I agree with Jack about that strlen.

Although I will say that ARRAY_SIZE() is used elsewhere in the kernel
like this.

But as this isn't a critical section, either is fine.

Acked-by: Steven Rostedt <rostedt@goodmis.org>


-- Steve

>  
> > Signed-off-by: Patrick Palka <patrick@parcs.ath.cx>
> > ---
> >  kernel/printk/printk.c | 6 +++---
> >  1 file changed, 3 insertions(+), 3 deletions(-)
> > 
> > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> > index e04c455..c101ec2 100644
> > --- a/kernel/printk/printk.c
> > +++ b/kernel/printk/printk.c
> > @@ -1665,15 +1665,15 @@ asmlinkage int vprintk_emit(int facility, int level,
> >  	raw_spin_lock(&logbuf_lock);
> >  	logbuf_cpu = this_cpu;
> >  
> > -	if (recursion_bug) {
> > +	if (unlikely(recursion_bug)) {
> >  		static const char recursion_msg[] =
> >  			"BUG: recent printk recursion!";
> >  
> >  		recursion_bug = 0;
> > -		text_len = strlen(recursion_msg);
> >  		/* emit KERN_CRIT message */
> >  		printed_len += log_store(0, 2, LOG_PREFIX|LOG_NEWLINE, 0,
> > -					 NULL, 0, recursion_msg, text_len);
> > +					 NULL, 0, recursion_msg,
> > +					 ARRAY_SIZE(recursion_msg) - 1);
> >  	}
> >  
> >  	/*
> > -- 
> > 2.1.0
> > 

Re: [PATCH] Fix faulty logic in the case of recursive printk

[Petr Mládek]

On Tue 26-08-14 07:23:22, Patrick Palka wrote:
> Thanks for reviewing!  I have put back the call to strlen() and adjusted
> the commit message accordingly.
> 
> Patrick
> 
> -- >8 --
> 
> We shouldn't set text_len in the code path that detects printk recursion
> because text_len corresponds to the length of the string inside textbuf.
> A few lines down from the line
> 
>     text_len = strlen(recursion_msg);
> 
> is the line
> 
>     text_len += vscnprintf(text + text_len, ...);
> 
> So if printk detects recursion, it sets text_len to 29 (the length of
> recursion_msg) and logs an error.  Then the message supplied by the
> caller of printk is stored inside textbuf but offset by 29 bytes.  This
> means that the output of the recursive call to printk will contain 29
> bytes of garbage in front of it.
> 
> This defect is caused by commit 458df9fd ("printk: remove separate
> printk_sched buffers and use printk buf instead") which turned the line
> 
>     text_len = vscnprintf(text, ...);
> 
> into
> 
>     text_len += vscnprintf(text + text_len, ...);
> 
> To fix this, this patch avoids setting text_len when logging the printk
> recursion error.  This patch also marks unlikely() the branch leading
> up to this code.
> 
> Signed-off-by: Patrick Palka <patrick@parcs.ath.cx>

Looks fine to me.

Reviewed-by: Petr Mladek <pmladek@suse.cz>

> ---
>  kernel/printk/printk.c | 6 +++---
>  1 file changed, 3 insertions(+), 3 deletions(-)
> 
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index e04c455..1ce7706 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -1665,15 +1665,15 @@ asmlinkage int vprintk_emit(int facility, int level,
>  	raw_spin_lock(&logbuf_lock);
>  	logbuf_cpu = this_cpu;
>  
> -	if (recursion_bug) {
> +	if (unlikely(recursion_bug)) {
>  		static const char recursion_msg[] =
>  			"BUG: recent printk recursion!";
>  
>  		recursion_bug = 0;
> -		text_len = strlen(recursion_msg);
>  		/* emit KERN_CRIT message */
>  		printed_len += log_store(0, 2, LOG_PREFIX|LOG_NEWLINE, 0,
> -					 NULL, 0, recursion_msg, text_len);
> +					 NULL, 0, recursion_msg,
> +					 strlen(recursion_msg));
>  	}
>  
>  	/*
> -- 
> 2.1.0
>