diff mbox

[1/4] printk: LOG_CONT and LOG_NEWLINE are separate

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

Commit Message

Alex Elder July 16, 2014, 5:26 p.m. UTC
Two log record flags--LOG_CONT and LOG_NEWLINE--are never both set
at the same time in a log record flags field.  What follows is a
great deal of explanation that aims to prove this assertion.

Having that knowledge allows us to simplify a bit of logic though,
and with a little more work (in follow-on patches) it allows us to
do without some flag values, considerably simplifying things.

So this patch leverages the one-or-the-other nature of these two
flags to simplify a small bit of logic.  It makes a some other small
changes to make it obvious that a few things in surrounding (and
related) code are invariant.

Log record flags are held in the "cont" continuation buffer, as well
as in "syslog_prev" and "console_prev".  Those are discussed later.
Other than that, log record flags are only set in log_store():
        msg->flags = flags & 0x1f;
There are 5 places log_store() is called:  twice from cont_flush();
and three times from vprintk_emit().

Only two single-flag values are ever passed to cont_flush():
LOG_CONT; and LOG_NEWLINE.  That passed-in value is provided by
cont_flush() to log_store() either as-is, or modified to include
LOG_NOCONS.  There are thus four possible flag combinations supplied
to log_store() by cont_flush():  LOG_CONT; LOG_NEWLINE;
LOG_CONT|LOG_NOCONS; or LOG_NEWLINE|LOG_NOCONS.

The first call vprintk_emit() makes to log_store() passes a flags
value of LOG_PREFIX|LOG_NEWLINE.  The second and third calls pass a
computed "lflags" value, possibly with LOG_CONT added.  The only
possible flag combinations held in "lflags" are:  0; LOG_NEWLINE;
LOG_PREFIX; or LOG_NEWLINE|LOG_PREFIX.  And the LOG_CONT flag is
added only when LOG_NEWLINE is not set.  So there are six possible
flag combinations supplied by cont_flush():  0; LOG_NEWLINE;
LOG_PREFIX; LOG_CONT; LOG_PREFIX|LOG_CONT; or LOG_PREFIX|LOG_NEWLINE.

Therefore log_store() is never provided (so never records) a flag
value that contains both LOG_CONT and LOG_NEWLINE.

Meanwhile, the "cont" flags field is only ever assigned value 0, or
a value passed to cont_flush().  As mentioned above, cont_flush() is
never provided more than one flag value.  The only values assigned
to "syslog_prev" and "console_prev" are 0 or the flags value from
a log record.  So none of these ever hold LOG_CONT and LOG_NEWLINE
at the same time.

This proves that at most one of LOG_CONT and LOG_NEWLINE will ever
be set in a log record flags field.  And as a result, we know that
LOG_CONT being set implies LOG_NEWLINE is not set (and vice versa).

This patch makes the following changes:
    - Changes two spots in msg_print_txt() so they no longer bother
      checking for LOG_NEWLINE once its known that LOG_CONT is set.
    - Changes two |= assignments in vprintk_emit() to be simple
      assignments instead, because the result is known to be the
      same and it makes it obvious no other flags are involved.
    - Explicitly pass NULL rather than "dict" (and 0 as its length)
      to log_store() in one spot in vprintk_emit(), because we know
      the value of dict at that point is always NULL.

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

Comments

Petr Mladek July 17, 2014, 8:39 a.m. UTC | #1
On Wed 2014-07-16 12:26:57, Alex Elder wrote:
> Two log record flags--LOG_CONT and LOG_NEWLINE--are never both set
> at the same time in a log record flags field.  What follows is a
> great deal of explanation that aims to prove this assertion.

It makes perfect sense. If you found a situation where both flags were
set together, it would mean a bug. If a record ends with new line, it
is not continuous and vice versa.

[...]

> Signed-off-by: Alex Elder <elder@linaro.org>
> ---
>  kernel/printk/printk.c | 12 +++++-------
>  1 file changed, 5 insertions(+), 7 deletions(-)
> 
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index 13e839d..301ade3 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -1006,11 +1006,9 @@ static size_t msg_print_text(const struct printk_log *msg, enum log_flags prev,
>  		prefix = false;
>  
>  	if (msg->flags & LOG_CONT) {
> -		if ((prev & LOG_CONT) && !(prev & LOG_NEWLINE))
> +		if (prev & LOG_CONT)
>  			prefix = false;
> -
> -		if (!(msg->flags & LOG_NEWLINE))
> -			newline = false;
> +		newline = false;
>  	}

Makes sense. I like it.

>  	do {
> @@ -1642,7 +1640,7 @@ asmlinkage int vprintk_emit(int facility, int level,
>  	/* mark and strip a trailing newline */
>  	if (text_len && text[text_len-1] == '\n') {
>  		text_len--;
> -		lflags |= LOG_NEWLINE;
> +		lflags = LOG_NEWLINE;
>  	}
>  
>  	/* strip kernel syslog prefix and extract log level or control flags */
> @@ -1672,7 +1670,7 @@ asmlinkage int vprintk_emit(int facility, int level,
>  		level = default_message_loglevel;
>  
>  	if (dict)
> -		lflags |= LOG_PREFIX|LOG_NEWLINE;
> +		lflags = LOG_PREFIX|LOG_NEWLINE;
>  
>  	if (!(lflags & LOG_NEWLINE)) {
>  		/*
> @@ -1688,7 +1686,7 @@ asmlinkage int vprintk_emit(int facility, int level,
>  		else
>  			printed_len += log_store(facility, level,
>  						 lflags | LOG_CONT, 0,
> -						 dict, dictlen, text, text_len);
> +						 NULL, 0, text, text_len);
>  	} else {
>  		bool stored = false;
>  

I am not sure that I like the last three changes. The logic is
correct. But I think that these micro-optimizations makes the code less
readable and prone to errors with reordering and other changes.

The original code does not harm. The new code is less obvious and will
force many people to think why it is correct. Even you might be in
doubts if you see it after few months :-)

Well, I do not have strong opinion here. Other people might see it
different. Forcing people to think is not a bad idea after all :-)

Best Regards,
Petr
--
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:11 p.m. UTC | #2
On 07/17/2014 03:39 AM, Petr Mládek wrote:
> On Wed 2014-07-16 12:26:57, Alex Elder wrote:
>> Two log record flags--LOG_CONT and LOG_NEWLINE--are never both set
>> at the same time in a log record flags field.  What follows is a
>> great deal of explanation that aims to prove this assertion.

Thank you so much for reviewing these patches.

Your confirmation of the fact that LOG_CONT and LOG_NEWLINE
should not go together is very valuable to me.  I have a set
of follow-on patches that rely on this, and I didn't want to
go ahead with proposing them until I knew this was right.

I have some responses to your feedback below.

> It makes perfect sense. If you found a situation where both flags were
> set together, it would mean a bug. If a record ends with new line, it
> is not continuous and vice versa.

At an abstract level this makes sense to me too, but the code
is written to handle many combinations of flags that simply will
never happen.  It obscures what's going on, or is supposed to be
going on.  So to the reader, this appears much more complicated than
it really is.

> [...]
> 
>> Signed-off-by: Alex Elder <elder@linaro.org>
>> ---
>>  kernel/printk/printk.c | 12 +++++-------
>>  1 file changed, 5 insertions(+), 7 deletions(-)
>>
>> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
>> index 13e839d..301ade3 100644
>> --- a/kernel/printk/printk.c
>> +++ b/kernel/printk/printk.c
>> @@ -1006,11 +1006,9 @@ static size_t msg_print_text(const struct printk_log *msg, enum log_flags prev,
>>  		prefix = false;
>>  
>>  	if (msg->flags & LOG_CONT) {
>> -		if ((prev & LOG_CONT) && !(prev & LOG_NEWLINE))
>> +		if (prev & LOG_CONT)
>>  			prefix = false;
>> -
>> -		if (!(msg->flags & LOG_NEWLINE))
>> -			newline = false;
>> +		newline = false;
>>  	}
> 
> Makes sense. I like it.
> 
>>  	do {
>> @@ -1642,7 +1640,7 @@ asmlinkage int vprintk_emit(int facility, int level,
>>  	/* mark and strip a trailing newline */
>>  	if (text_len && text[text_len-1] == '\n') {
>>  		text_len--;
>> -		lflags |= LOG_NEWLINE;
>> +		lflags = LOG_NEWLINE;
>>  	}
>>  
>>  	/* strip kernel syslog prefix and extract log level or control flags */
>> @@ -1672,7 +1670,7 @@ asmlinkage int vprintk_emit(int facility, int level,
>>  		level = default_message_loglevel;
>>  
>>  	if (dict)
>> -		lflags |= LOG_PREFIX|LOG_NEWLINE;
>> +		lflags = LOG_PREFIX|LOG_NEWLINE;
>>  
>>  	if (!(lflags & LOG_NEWLINE)) {
>>  		/*
>> @@ -1688,7 +1686,7 @@ asmlinkage int vprintk_emit(int facility, int level,
>>  		else
>>  			printed_len += log_store(facility, level,
>>  						 lflags | LOG_CONT, 0,
>> -						 dict, dictlen, text, text_len);
>> +						 NULL, 0, text, text_len);
>>  	} else {
>>  		bool stored = false;
>>  
> 
> I am not sure that I like the last three changes. The logic is
> correct. But I think that these micro-optimizations makes the code less
> readable and prone to errors with reordering and other changes.

It is not an optimization.  I don't care about that.

It is replacing a variable with a constant, because I
know by static analysis that the variable will always
have constant value.  This makes it completely obvious
that "dict" will *never* be NULL in this case, and as
above, makes it more obvious what's happening.

(You'll see in my follow-on series that I rely on the
assignment rather than |= in order to do some refactoring.)

If someone chooses to reorder the code in a way that
makes |= necessary (for example) will put that back
again, because not doing so would introduce a bug.

> The original code does not harm. The new code is less obvious and will
> force many people to think why it is correct. Even you might be in
> doubts if you see it after few months :-)

Actually I think it's the opposite.

> Well, I do not have strong opinion here. Other people might see it
> different. Forcing people to think is not a bad idea after all :-)

I may be naive, but I think it's a requirement if you're going
to change code.

Thanks again for the review.  If you're willing after reading my
explanations, please offer an ACK or Reviewed-by (or further
questions and suggestions).  I'll have responses to your others
shortly.

					-Alex

> Best Regards,
> Petr
> 

--
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:31 p.m. UTC | #3
On 07/17/2014 03:39 AM, Petr Mládek wrote:
> On Wed 2014-07-16 12:26:57, Alex Elder wrote:
>> Two log record flags--LOG_CONT and LOG_NEWLINE--are never both set
>> at the same time in a log record flags field.  What follows is a
>> great deal of explanation that aims to prove this assertion.
> 
> It makes perfect sense. If you found a situation where both flags were
> set together, it would mean a bug. If a record ends with new line, it
> is not continuous and vice versa.

. . .

My earlier response basically argued for keeping the patch
as I originally proposed it.

That is still my plan.  However there is one more thing
that I have verified since posting it--I can make the
stronger assertion that LOG_CONT and LOG_NEWLINE are
mutually exclusive.  That is, not only will they never
be both set at the time, but one of them will always
be set.

Rather than add that as a new patch I'm going to rework
the explanation, and make one more small code change
to make this a little easier to see.

					-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/
Petr Mladek July 17, 2014, 2:46 p.m. UTC | #4
On Thu 2014-07-17 07:11:39, Alex Elder wrote:
> On 07/17/2014 03:39 AM, Petr Mládek wrote:
> > On Wed 2014-07-16 12:26:57, Alex Elder wrote:
> >> Two log record flags--LOG_CONT and LOG_NEWLINE--are never both set
> >> at the same time in a log record flags field.  What follows is a
> >> great deal of explanation that aims to prove this assertion.
> 
> Thank you so much for reviewing these patches.
> 
> Your confirmation of the fact that LOG_CONT and LOG_NEWLINE
> should not go together is very valuable to me.  I have a set
> of follow-on patches that rely on this, and I didn't want to
> go ahead with proposing them until I knew this was right.

To be honest. My statement was based on a common sense. I simply
cannot imagine situatiuon when a text ends with "\n" and is continuous
at the same time. IMHO, it is against any logic.

IMHO, it would make sense to have only one flag, either LOG_NEWLINE or
LOG_CONT. Well, I am not sure if we could remove it easily. AFAIK, the
ring buffer is read also by external tools, e.g. crash.

Some more experienced kernel developer should answer this.

> I have some responses to your feedback below.
> 
> > It makes perfect sense. If you found a situation where both flags were
> > set together, it would mean a bug. If a record ends with new line, it
> > is not continuous and vice versa.
> 
> At an abstract level this makes sense to me too, but the code
> is written to handle many combinations of flags that simply will
> never happen.  It obscures what's going on, or is supposed to be
> going on.  So to the reader, this appears much more complicated than
> it really is.

Yes, the code is too complicated and deserve simplification.

> 
> > [...]
> > 
> >> Signed-off-by: Alex Elder <elder@linaro.org>
> >> ---
> >>  kernel/printk/printk.c | 12 +++++-------
> >>  1 file changed, 5 insertions(+), 7 deletions(-)
> >>
> >> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> >> index 13e839d..301ade3 100644
> >> --- a/kernel/printk/printk.c
> >> +++ b/kernel/printk/printk.c
> >> @@ -1006,11 +1006,9 @@ static size_t msg_print_text(const struct printk_log *msg, enum log_flags prev,
> >>  		prefix = false;
> >>  
> >>  	if (msg->flags & LOG_CONT) {
> >> -		if ((prev & LOG_CONT) && !(prev & LOG_NEWLINE))
> >> +		if (prev & LOG_CONT)
> >>  			prefix = false;
> >> -
> >> -		if (!(msg->flags & LOG_NEWLINE))
> >> -			newline = false;
> >> +		newline = false;
> >>  	}
> > 
> > Makes sense. I like it.
> > 
> >>  	do {
> >> @@ -1642,7 +1640,7 @@ asmlinkage int vprintk_emit(int facility, int level,
> >>  	/* mark and strip a trailing newline */
> >>  	if (text_len && text[text_len-1] == '\n') {
> >>  		text_len--;
> >> -		lflags |= LOG_NEWLINE;
> >> +		lflags = LOG_NEWLINE;
> >>  	}
> >>  
> >>  	/* strip kernel syslog prefix and extract log level or control flags */
> >> @@ -1672,7 +1670,7 @@ asmlinkage int vprintk_emit(int facility, int level,
> >>  		level = default_message_loglevel;
> >>  
> >>  	if (dict)
> >> -		lflags |= LOG_PREFIX|LOG_NEWLINE;
> >> +		lflags = LOG_PREFIX|LOG_NEWLINE;
> >>  
> >>  	if (!(lflags & LOG_NEWLINE)) {
> >>  		/*
> >> @@ -1688,7 +1686,7 @@ asmlinkage int vprintk_emit(int facility, int level,
> >>  		else
> >>  			printed_len += log_store(facility, level,
> >>  						 lflags | LOG_CONT, 0,
> >> -						 dict, dictlen, text, text_len);
> >> +						 NULL, 0, text, text_len);
> >>  	} else {
> >>  		bool stored = false;
> >>  
> > 
> > I am not sure that I like the last three changes. The logic is
> > correct. But I think that these micro-optimizations makes the code less
> > readable and prone to errors with reordering and other changes.
> 
> It is not an optimization.  I don't care about that.
> 
> It is replacing a variable with a constant, because I
> know by static analysis that the variable will always
> have constant value.  This makes it completely obvious
> that "dict" will *never* be NULL in this case, and as
> above, makes it more obvious what's happening.
> 
> (You'll see in my follow-on series that I rely on the
> assignment rather than |= in order to do some refactoring.)

As I said, I do not have strong opinion here. It might be interesting
to see the whole serie to get better picture.

> If someone chooses to reorder the code in a way that
> makes |= necessary (for example) will put that back
> again, because not doing so would introduce a bug.
> 
> > The original code does not harm. The new code is less obvious and will
> > force many people to think why it is correct. Even you might be in
> > doubts if you see it after few months :-)
> 
> Actually I think it's the opposite.
> 
> > Well, I do not have strong opinion here. Other people might see it
> > different. Forcing people to think is not a bad idea after all :-)
> 
> I may be naive, but I think it's a requirement if you're going
> to change code.

But it is easier when the code is readable and there are as few
surprises as possible. Also you never could have everything in your
head. The less dependncy is there, the easier is to work with it.

Regarding the above changes. The origial code used the typical
pattern. It set default value and then modified different flags according
to various tests. It did not need to take care much of other flags that
were not related to the given test.

If you add lated another flag and more tests, the final forced
assignent could break things.

Also the hardcoded NULL is not obvious. If you would want to modify the
code, you would need to think harder why it is there. IMHO, it does
not bring any real benefit unless you want to use it for some furher
optimization. But this is not visible from the patchset.


Please, take this as my personal opinion. I am not maintainer of this
code and the final decisions will not not be mine. Also I am still
learning good code patterns.

> Thanks again for the review.  If you're willing after reading my
> explanations, please offer an ACK or Reviewed-by (or further
> questions and suggestions).  I'll have responses to your others
> shortly.

I would like to see the bigger picture before :-)

Best Regards,
Petr
--
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, 4:19 p.m. UTC | #5
On 07/17/2014 09:46 AM, Petr Mládek wrote:
> On Thu 2014-07-17 07:11:39, Alex Elder wrote:
>> On 07/17/2014 03:39 AM, Petr Mládek wrote:
>>> On Wed 2014-07-16 12:26:57, Alex Elder wrote:
>>>> Two log record flags--LOG_CONT and LOG_NEWLINE--are never both set
>>>> at the same time in a log record flags field.  What follows is a
>>>> great deal of explanation that aims to prove this assertion.
>>
>> Thank you so much for reviewing these patches.
>>
>> Your confirmation of the fact that LOG_CONT and LOG_NEWLINE
>> should not go together is very valuable to me.  I have a set
>> of follow-on patches that rely on this, and I didn't want to
>> go ahead with proposing them until I knew this was right.
> 
> To be honest. My statement was based on a common sense. I simply
> cannot imagine situatiuon when a text ends with "\n" and is continuous
> at the same time. IMHO, it is against any logic.

Well, I thought so too, but it was hard to see that by
just looking at the code.

> IMHO, it would make sense to have only one flag, either LOG_NEWLINE or
> LOG_CONT. Well, I am not sure if we could remove it easily. AFAIK, the
> ring buffer is read also by external tools, e.g. crash.

The single flag is coming.  I have that done, but I didn't want
to send that patch (and others) until I get past this little group.

I have been concerned about the effects on other things but the
comments insist the log structure is kernel private. :)

I took a very quick look at crash-7.0.7 and see dump_log_entry(),
which seems to dump the contents of a log record but does not
interpret any of the flags.

This is a really important point, so if anybody knows of other
utilities outside the kernel that interpret the log record flags
I'd like to know about it.

> Some more experienced kernel developer should answer this.

>> I have some responses to your feedback below.
>>
>>> It makes perfect sense. If you found a situation where both flags were
>>> set together, it would mean a bug. If a record ends with new line, it
>>> is not continuous and vice versa.
>>
>> At an abstract level this makes sense to me too, but the code
>> is written to handle many combinations of flags that simply will
>> never happen.  It obscures what's going on, or is supposed to be
>> going on.  So to the reader, this appears much more complicated than
>> it really is.
> 
> Yes, the code is too complicated and deserve simplification.
> 
>>
>>> [...]
>>>
>>>> Signed-off-by: Alex Elder <elder@linaro.org>
>>>> ---
>>>>  kernel/printk/printk.c | 12 +++++-------
>>>>  1 file changed, 5 insertions(+), 7 deletions(-)
>>>>
>>>> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
>>>> index 13e839d..301ade3 100644
>>>> --- a/kernel/printk/printk.c
>>>> +++ b/kernel/printk/printk.c
>>>> @@ -1006,11 +1006,9 @@ static size_t msg_print_text(const struct printk_log *msg, enum log_flags prev,
>>>>  		prefix = false;
>>>>  
>>>>  	if (msg->flags & LOG_CONT) {
>>>> -		if ((prev & LOG_CONT) && !(prev & LOG_NEWLINE))
>>>> +		if (prev & LOG_CONT)
>>>>  			prefix = false;
>>>> -
>>>> -		if (!(msg->flags & LOG_NEWLINE))
>>>> -			newline = false;
>>>> +		newline = false;
>>>>  	}
>>>
>>> Makes sense. I like it.
>>>
>>>>  	do {
>>>> @@ -1642,7 +1640,7 @@ asmlinkage int vprintk_emit(int facility, int level,
>>>>  	/* mark and strip a trailing newline */
>>>>  	if (text_len && text[text_len-1] == '\n') {
>>>>  		text_len--;
>>>> -		lflags |= LOG_NEWLINE;
>>>> +		lflags = LOG_NEWLINE;
>>>>  	}
>>>>  
>>>>  	/* strip kernel syslog prefix and extract log level or control flags */
>>>> @@ -1672,7 +1670,7 @@ asmlinkage int vprintk_emit(int facility, int level,
>>>>  		level = default_message_loglevel;
>>>>  
>>>>  	if (dict)
>>>> -		lflags |= LOG_PREFIX|LOG_NEWLINE;
>>>> +		lflags = LOG_PREFIX|LOG_NEWLINE;
>>>>  
>>>>  	if (!(lflags & LOG_NEWLINE)) {
>>>>  		/*
>>>> @@ -1688,7 +1686,7 @@ asmlinkage int vprintk_emit(int facility, int level,
>>>>  		else
>>>>  			printed_len += log_store(facility, level,
>>>>  						 lflags | LOG_CONT, 0,
>>>> -						 dict, dictlen, text, text_len);
>>>> +						 NULL, 0, text, text_len);
>>>>  	} else {
>>>>  		bool stored = false;
>>>>  
>>>
>>> I am not sure that I like the last three changes. The logic is
>>> correct. But I think that these micro-optimizations makes the code less
>>> readable and prone to errors with reordering and other changes.
>>
>> It is not an optimization.  I don't care about that.
>>
>> It is replacing a variable with a constant, because I
>> know by static analysis that the variable will always
>> have constant value.  This makes it completely obvious
>> that "dict" will *never* be NULL in this case, and as
>> above, makes it more obvious what's happening.
>>
>> (You'll see in my follow-on series that I rely on the
>> assignment rather than |= in order to do some refactoring.)
> 
> As I said, I do not have strong opinion here. It might be interesting
> to see the whole serie to get better picture.

You'll see it.  Once I feel like this initial series is
close to acceptable (or accepted) I'll be posting the
others soon afterward.  I'd love to get it out this week.

>> If someone chooses to reorder the code in a way that
>> makes |= necessary (for example) will put that back
>> again, because not doing so would introduce a bug.
>>
>>> The original code does not harm. The new code is less obvious and will
>>> force many people to think why it is correct. Even you might be in
>>> doubts if you see it after few months :-)
>>
>> Actually I think it's the opposite.
>>
>>> Well, I do not have strong opinion here. Other people might see it
>>> different. Forcing people to think is not a bad idea after all :-)
>>
>> I may be naive, but I think it's a requirement if you're going
>> to change code.
> 
> But it is easier when the code is readable and there are as few
> surprises as possible. Also you never could have everything in your
> head. The less dependncy is there, the easier is to work with it.
> 
> Regarding the above changes. The origial code used the typical
> pattern. It set default value and then modified different flags according
> to various tests. It did not need to take care much of other flags that
> were not related to the given test.
> 
> If you add lated another flag and more tests, the final forced
> assignent could break things.
> 
> Also the hardcoded NULL is not obvious. If you would want to modify the
> code, you would need to think harder why it is there. IMHO, it does
> not bring any real benefit unless you want to use it for some furher
> optimization. But this is not visible from the patchset.

OK.  I think we disagree but I don't mind putting that "dict"
pointer back.  I find it much easier to deal with constants
than variables--constants are just that, unchanging.  Variables
can take on any value, including, possibly, unexpected ones.

> Please, take this as my personal opinion. I am not maintainer of this
> code and the final decisions will not not be mine. Also I am still
> learning good code patterns.

Given that, I will plan to keep the patch as it is posted
unless someone else weighs in to request the change you
suggest.

>> Thanks again for the review.  If you're willing after reading my
>> explanations, please offer an ACK or Reviewed-by (or further
>> questions and suggestions).  I'll have responses to your others
>> shortly.
> 
> I would like to see the bigger picture before :-)

OK, the big picture for this is that I have a set of about
5 more patches, which have the end result of eliminating
LOG_CONT and LOG_PREFIX.  The only thing that matters is
LOG_NEWLINE, which indicates the log entry completes a
sequence of one or more.  Most records will have that set;
any that do not will be "continuation" records, which should
be taken along with one or more successor records to make
up a single logical log entry.  There is no need for
LOG_PREFIX, because that is implied by the presence of
LOG_NEWLINE in the previous log entry.  We're already tracking
the previous record state where that's needed.

It's all clear how to get from here to there in the patches.

					-Alex



> Best Regards,
> Petr
> 

--
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/
Petr Mladek July 18, 2014, 8:49 a.m. UTC | #6
On Thu 2014-07-17 11:19:15, Alex Elder wrote:
> On 07/17/2014 09:46 AM, Petr Mládek wrote:
> > On Thu 2014-07-17 07:11:39, Alex Elder wrote:
> >> On 07/17/2014 03:39 AM, Petr Mládek wrote:
> >>> On Wed 2014-07-16 12:26:57, Alex Elder wrote:
> >>>> Two log record flags--LOG_CONT and LOG_NEWLINE--are never both set
> >>>> at the same time in a log record flags field.  What follows is a
> >>>> great deal of explanation that aims to prove this assertion.
> >>
> >> Thank you so much for reviewing these patches.
> >>
> >> Your confirmation of the fact that LOG_CONT and LOG_NEWLINE
> >> should not go together is very valuable to me.  I have a set
> >> of follow-on patches that rely on this, and I didn't want to
> >> go ahead with proposing them until I knew this was right.
> > 
> > To be honest. My statement was based on a common sense. I simply
> > cannot imagine situatiuon when a text ends with "\n" and is continuous
> > at the same time. IMHO, it is against any logic.
> 
> Well, I thought so too, but it was hard to see that by
> just looking at the code.
> 
> > IMHO, it would make sense to have only one flag, either LOG_NEWLINE or
> > LOG_CONT. Well, I am not sure if we could remove it easily. AFAIK, the
> > ring buffer is read also by external tools, e.g. crash.
> 
> I took a very quick look at crash-7.0.7 and see dump_log_entry(),
> which seems to dump the contents of a log record but does not
> interpret any of the flags.

Good to know.

> This is a really important point, so if anybody knows of other
> utilities outside the kernel that interpret the log record flags
> I'd like to know about it.

AFAIK, also makedumpfile tool somehow access the private data.
See the comments for log_buf_kexec_setup()

[...]
 
> >> Thanks again for the review.  If you're willing after reading my
> >> explanations, please offer an ACK or Reviewed-by (or further
> >> questions and suggestions).  I'll have responses to your others
> >> shortly.
> > 
> > I would like to see the bigger picture before :-)
> 
> OK, the big picture for this is that I have a set of about
> 5 more patches, which have the end result of eliminating
> LOG_CONT and LOG_PREFIX.  The only thing that matters is
> LOG_NEWLINE, which indicates the log entry completes a
> sequence of one or more.  Most records will have that set;
> any that do not will be "continuation" records, which should
> be taken along with one or more successor records to make
> up a single logical log entry.  There is no need for
> LOG_PREFIX, because that is implied by the presence of
> LOG_NEWLINE in the previous log entry.  We're already tracking
> the previous record state where that's needed.

I wanted to think about this over night. And Kay actually confirmed my
doubts. There are various situations when the messages could get mixed
either when writing or when reading.

We do not care much about whole lines. Users are usually able to put
the right lines together by context.

Most of the hackery seems to be done for the continuous lines. The
following problematic situations come to my mind:


1. More tasks are printing at the same time. It is solved by flushing
   the cont buffer with newline when message from another task comes.

2. Someone prints continuous lines and forgets to put '\n' at the end.
   This is solved by flushing the cont buffer with newline when
   the same tasks prints new message with prefix.

3. Task is interrupted and the handler prints something. It is not
   currently detected. It is fine because it usually looks like
   the second scenario. The handler prints the first message with
   prefix...

4. There is a flood of messages. The readers, e.g. console, syslog,
   are not able to handle everything. They copy a continuous line and
   miss the rest. This is currently solved by resetting the flags
   for the previous message. I think that it is handled as if
   the previous line was newline.


The question is how many flags we need to handle the situations
reasonable way. We are discussing the three flags:

	   LOG_CONT
	   LOG_NEWLINE
	   LOG_PREFIX

Let's start with CONT and NEWLINE. The only situation when they
have the same value is when readers miss a message and reset the flag
for the previous message. It has the meaning: "we do not know".

IMHO, we do not need both CONT and NEWLINE flags. If we do not know
what was the last message, we need to decide somehow. It seems that we
currently do nothing special and expect that the last message ended
with newline. It means that the we could omit LOG_CONT flag and
simplify the code.


What about LOG_PREFIX? IMHO, we need it because the following
situations:

a) printk() could not modify flags of the previous messages. They
might be already proceed by readers, .e.g console, syslog. We could
not add LOG_NEWLINE flag to the previous message if suddenly new
message with prefix comes and the previous was already flushed
without newline.

b) Readers might miss messages. We might want to print '\n' if
the previous message was proceed without newline and the current
one has prefix.


What are the expectations from any changes?

The code is already too complex. IMHO, nobody wants to make it worse
just to fix the few remaining corner cases.

Any simplification is great if it keeps the output reasonable.

Best Regards,
Petr
--
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/
diff mbox

Patch

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 13e839d..301ade3 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1006,11 +1006,9 @@  static size_t msg_print_text(const struct printk_log *msg, enum log_flags prev,
 		prefix = false;
 
 	if (msg->flags & LOG_CONT) {
-		if ((prev & LOG_CONT) && !(prev & LOG_NEWLINE))
+		if (prev & LOG_CONT)
 			prefix = false;
-
-		if (!(msg->flags & LOG_NEWLINE))
-			newline = false;
+		newline = false;
 	}
 
 	do {
@@ -1642,7 +1640,7 @@  asmlinkage int vprintk_emit(int facility, int level,
 	/* mark and strip a trailing newline */
 	if (text_len && text[text_len-1] == '\n') {
 		text_len--;
-		lflags |= LOG_NEWLINE;
+		lflags = LOG_NEWLINE;
 	}
 
 	/* strip kernel syslog prefix and extract log level or control flags */
@@ -1672,7 +1670,7 @@  asmlinkage int vprintk_emit(int facility, int level,
 		level = default_message_loglevel;
 
 	if (dict)
-		lflags |= LOG_PREFIX|LOG_NEWLINE;
+		lflags = LOG_PREFIX|LOG_NEWLINE;
 
 	if (!(lflags & LOG_NEWLINE)) {
 		/*
@@ -1688,7 +1686,7 @@  asmlinkage int vprintk_emit(int facility, int level,
 		else
 			printed_len += log_store(facility, level,
 						 lflags | LOG_CONT, 0,
-						 dict, dictlen, text, text_len);
+						 NULL, 0, text, text_len);
 	} else {
 		bool stored = false;