[3/4] printk: honor LOG_PREFIX in msg_print_text()

Message ID 1405531620-9983-4-git-send-email-elder@linaro.org
State New
Headers show

Commit Message

Alex Elder July 16, 2014, 5:26 p.m.
This patch fixes a problem similar to what was addressed in the
previous patch.

All paths that read and format log records (for consoles, and for
reading via syslog and /dev/kmsg) go through msg_print_text().  That
function starts with some logic to determine whether the given log
record when formatted should begin with a "prefix" string, and
whether it should end with a newline.  That logic has a bug.

The LOG_PREFIX flag in a log record indicates that when it's
formatted, a log record should include a prefix.  This is used to
force a record to begin a new line--even if its preceding log record
contained LOG_CONT (indicating its content should be combined with
the next record).

Like the previous patch, the problem occurs when these flags are
all set:
    prev & LOG_CONT
    msg->flags & LOG_PREFIX
    msg->flags & LOG_CONT
In that case, "prefix" should be true but it is not.

The fix involves checking LOG_PREFIX when a message has its LOG_CONT
flag set, and in that case allowing "prefix" to become false only
if LOG_PREFIX is not set.  I.e., the logic for "prefix" would become:

    if (prev & LOG_CONT && !(msg->flags & LOG_PREFIX))
        prefix = false;
    if (msg->flags & LOG_CONT)
        if (prev & LOG_CONT && !(msg->flags & LOG_PREFIX))
            prefix = false;

However, note that this makes the (msg->flags & LOG_CONT) block
redunant--it's handled by the test just above it.  The result
becomes quite a bit simpler than before.

The following table concisely defines the problem:

     prev | msg  | msg  ||
     CONT |PREFIX| CONT ||prefix
    ------+------+------++------
     clear| clear| clear|| true
     clear| clear|  set || true
     clear|  set | clear|| true
     clear|  set |  set || true
      set | clear| clear||false
      set |  set |  set ||false
      set |  set | clear|| true
      set |  set |  set ||false      <-- should be true

Signed-off-by: Alex Elder <elder@linaro.org>
---
 kernel/printk/printk.c | 7 ++-----
 1 file changed, 2 insertions(+), 5 deletions(-)

Comments

Petr Mladek July 17, 2014, 9:40 a.m. | #1
On Wed 2014-07-16 12:26:59, Alex Elder wrote:
> This patch fixes a problem similar to what was addressed in the
> previous patch.
> 
> All paths that read and format log records (for consoles, and for
> reading via syslog and /dev/kmsg) go through msg_print_text().  That
> function starts with some logic to determine whether the given log
> record when formatted should begin with a "prefix" string, and
> whether it should end with a newline.  That logic has a bug.
> 
> The LOG_PREFIX flag in a log record indicates that when it's
> formatted, a log record should include a prefix.  This is used to
> force a record to begin a new line--even if its preceding log record
> contained LOG_CONT (indicating its content should be combined with
> the next record).
> 
> Like the previous patch, the problem occurs when these flags are
> all set:
>     prev & LOG_CONT
>     msg->flags & LOG_PREFIX
>     msg->flags & LOG_CONT
> In that case, "prefix" should be true but it is not.

You are right.

> The fix involves checking LOG_PREFIX when a message has its LOG_CONT
> flag set, and in that case allowing "prefix" to become false only
> if LOG_PREFIX is not set.  I.e., the logic for "prefix" would become:
> 
>     if (prev & LOG_CONT && !(msg->flags & LOG_PREFIX))
>         prefix = false;
>     if (msg->flags & LOG_CONT)
>         if (prev & LOG_CONT && !(msg->flags & LOG_PREFIX))
>             prefix = false;
> 
> However, note that this makes the (msg->flags & LOG_CONT) block
> redunant--it's handled by the test just above it.  The result
> becomes quite a bit simpler than before.
> 
> The following table concisely defines the problem:
> 
>      prev | msg  | msg  ||
>      CONT |PREFIX| CONT ||prefix
>     ------+------+------++------
>      clear| clear| clear|| true
>      clear| clear|  set || true
>      clear|  set | clear|| true
>      clear|  set |  set || true
>       set | clear| clear||false
>       set |  set |  set ||false
>       set |  set | clear|| true
>       set |  set |  set ||false      <-- should be true
> 
> Signed-off-by: Alex Elder <elder@linaro.org>
> ---
>  kernel/printk/printk.c | 7 ++-----
>  1 file changed, 2 insertions(+), 5 deletions(-)
> 
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index 9e9cf93..3f15d95 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -1003,14 +1003,11 @@ static size_t msg_print_text(const struct printk_log *msg, enum log_flags prev,
>  	bool newline = true;
>  	size_t len = 0;
>  
> -	if ((prev & LOG_CONT) && !(msg->flags & LOG_PREFIX))
> +	if (prev & LOG_CONT && !(msg->flags & LOG_PREFIX))
>  		prefix = false;

I would personaly keep the brackets there. For me.

  ( & ) && !( & )

is easier to parse than

  & && !( & )

> -	if (msg->flags & LOG_CONT) {
> -		if (prev & LOG_CONT)
> -			prefix = false;
> +	if (msg->flags & LOG_CONT)
>  		newline = false;
> -	}

You are right. The check before "prefix = false" did not make much
sense. We should not remove prefix just because the previous line was
continuous. Also it does not make sense to do this only when the new line
is continuous.

But I think that the fix is not complete. IMHO, we should finish the
previous continuous line with '\n' before we print the prefix. I mean something
like:

if ((prev & LOG_CONT) && (msg->flags & LOG_PREFIX) && (len < size)) {
	/* finish the incomplete continuous line */
	if (buf) {
		buf[len++] = '\n';
	} else {
		len++;
	}
}

Best Regards,
Petr


>  
>  	do {
>  		const char *next = memchr(text, '\n', text_size);
> -- 
> 1.9.1
> 
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/
Alex Elder July 17, 2014, 12:18 p.m. | #2
On 07/17/2014 04:40 AM, Petr Mládek wrote:
> On Wed 2014-07-16 12:26:59, Alex Elder wrote:
>> This patch fixes a problem similar to what was addressed in the
>> previous patch.
>>
>> All paths that read and format log records (for consoles, and for
>> reading via syslog and /dev/kmsg) go through msg_print_text().  That
>> function starts with some logic to determine whether the given log
>> record when formatted should begin with a "prefix" string, and
>> whether it should end with a newline.  That logic has a bug.
>>
>> The LOG_PREFIX flag in a log record indicates that when it's
>> formatted, a log record should include a prefix.  This is used to
>> force a record to begin a new line--even if its preceding log record
>> contained LOG_CONT (indicating its content should be combined with
>> the next record).
>>
>> Like the previous patch, the problem occurs when these flags are
>> all set:
>>     prev & LOG_CONT
>>     msg->flags & LOG_PREFIX
>>     msg->flags & LOG_CONT
>> In that case, "prefix" should be true but it is not.
> 
> You are right.

That's great news.

>> The fix involves checking LOG_PREFIX when a message has its LOG_CONT
>> flag set, and in that case allowing "prefix" to become false only
>> if LOG_PREFIX is not set.  I.e., the logic for "prefix" would become:
>>
>>     if (prev & LOG_CONT && !(msg->flags & LOG_PREFIX))
>>         prefix = false;
>>     if (msg->flags & LOG_CONT)
>>         if (prev & LOG_CONT && !(msg->flags & LOG_PREFIX))
>>             prefix = false;
>>
>> However, note that this makes the (msg->flags & LOG_CONT) block
>> redunant--it's handled by the test just above it.  The result
>> becomes quite a bit simpler than before.
>>
>> The following table concisely defines the problem:
>>
>>      prev | msg  | msg  ||
>>      CONT |PREFIX| CONT ||prefix
>>     ------+------+------++------
>>      clear| clear| clear|| true
>>      clear| clear|  set || true
>>      clear|  set | clear|| true
>>      clear|  set |  set || true
>>       set | clear| clear||false
>>       set |  set |  set ||false
               clear

(Same problem you pointed out in the next patch.)

>>       set |  set | clear|| true
>>       set |  set |  set ||false      <-- should be true
>>
>> Signed-off-by: Alex Elder <elder@linaro.org>
>> ---
>>  kernel/printk/printk.c | 7 ++-----
>>  1 file changed, 2 insertions(+), 5 deletions(-)
>>
>> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
>> index 9e9cf93..3f15d95 100644
>> --- a/kernel/printk/printk.c
>> +++ b/kernel/printk/printk.c
>> @@ -1003,14 +1003,11 @@ static size_t msg_print_text(const struct printk_log *msg, enum log_flags prev,
>>  	bool newline = true;
>>  	size_t len = 0;
>>  
>> -	if ((prev & LOG_CONT) && !(msg->flags & LOG_PREFIX))
>> +	if (prev & LOG_CONT && !(msg->flags & LOG_PREFIX))
>>  		prefix = false;
> 
> I would personaly keep the brackets there. For me.
> 
>   ( & ) && !( & )

That's fine.  I tend to be minimalist unless the compiler suggests
otherwise, but I'll keep the parentheses.

> is easier to parse than
> 
>   & && !( & )
> 
>> -	if (msg->flags & LOG_CONT) {
>> -		if (prev & LOG_CONT)
>> -			prefix = false;
>> +	if (msg->flags & LOG_CONT)
>>  		newline = false;
>> -	}
> 
> You are right. The check before "prefix = false" did not make much
> sense. We should not remove prefix just because the previous line was
> continuous. Also it does not make sense to do this only when the new line
> is continuous.

I came at this trying to understand what was intended by
reading the code.  And it is not easy.  These patches and
the set that I'll post soon simplify things enormously.

> But I think that the fix is not complete. IMHO, we should finish the
> previous continuous line with '\n' before we print the prefix. I mean something
> like:

I will re-post a new version of this patch.  When I do so
I will look at this and--unless I find I disagree--will
implement your suggestion.

Thanks.

					-Alex

> 
> if ((prev & LOG_CONT) && (msg->flags & LOG_PREFIX) && (len < size)) {
> 	/* finish the incomplete continuous line */
> 	if (buf) {
> 		buf[len++] = '\n';
> 	} else {
> 		len++;
> 	}
> }
> 
> Best Regards,
> Petr
> 
> 
>>  
>>  	do {
>>  		const char *next = memchr(text, '\n', text_size);
>> -- 
>> 1.9.1
>>

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/
Alex Elder July 17, 2014, 1:42 p.m. | #3
On 07/17/2014 07:18 AM, Alex Elder wrote:
>> But I think that the fix is not complete. IMHO, we should finish the
>> > previous continuous line with '\n' before we print the prefix. I mean something
>> > like:
> I will re-post a new version of this patch.  When I do so
> I will look at this and--unless I find I disagree--will
> implement your suggestion.

I concur with this, but it's a different bug that changes
externally-visible behavior, so I'm going to add this as
a separate patch.

					-Alex
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

Patch hide | download patch | download mbox

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 9e9cf93..3f15d95 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1003,14 +1003,11 @@  static size_t msg_print_text(const struct printk_log *msg, enum log_flags prev,
 	bool newline = true;
 	size_t len = 0;
 
-	if ((prev & LOG_CONT) && !(msg->flags & LOG_PREFIX))
+	if (prev & LOG_CONT && !(msg->flags & LOG_PREFIX))
 		prefix = false;
 
-	if (msg->flags & LOG_CONT) {
-		if (prev & LOG_CONT)
-			prefix = false;
+	if (msg->flags & LOG_CONT)
 		newline = false;
-	}
 
 	do {
 		const char *next = memchr(text, '\n', text_size);