2012-10-08 19:25:08

by Kay Sievers

[permalink] [raw]
Subject: Re: [PATCH] printk: drop ambiguous LOG_CONT flag

On Fri, Sep 28, 2012 at 4:56 PM, Kay Sievers <[email protected]> wrote:
> On Fri, Sep 28, 2012 at 4:49 PM, "Jan H. Schönherr"

>> Given that I'm able to fix the racing case, would you be in favor of
>> this approach, or should we stick to the earlier version?
>
> I'm open to everything that makes sense. Let's see how it looks and we
> can decide when we have something that passes the tests.

Jan,
any updates, did you try something else?
Or should we merge the first version for now?

Thanks,
Kay


2012-10-08 19:55:09

by Jan H. Schönherr

[permalink] [raw]
Subject: Re: [PATCH] printk: drop ambiguous LOG_CONT flag

Am 08.10.2012 21:24, schrieb Kay Sievers:
> On Fri, Sep 28, 2012 at 4:56 PM, Kay Sievers <[email protected]> wrote:
>> On Fri, Sep 28, 2012 at 4:49 PM, "Jan H. Schönherr"
>
>>> Given that I'm able to fix the racing case, would you be in favor of
>>> this approach, or should we stick to the earlier version?
>>
>> I'm open to everything that makes sense. Let's see how it looks and we
>> can decide when we have something that passes the tests.
>
> Jan,
> any updates, did you try something else?
> Or should we merge the first version for now?

I'm working on it, though I cannot spend as much time as I want. :)

My current version does mostly well for race-printk()s, now. But
there's still one issue to resolve and some polishing to do.

If we can afford to wait a little longer, we might get a nicer
solution (and avoid a possible mostly-revert later).

Regards
Jan

2012-10-08 19:57:12

by Kay Sievers

[permalink] [raw]
Subject: Re: [PATCH] printk: drop ambiguous LOG_CONT flag

On Mon, Oct 8, 2012 at 9:54 PM, "Jan H. Schönherr"
<[email protected]> wrote:
> Am 08.10.2012 21:24, schrieb Kay Sievers:
>> On Fri, Sep 28, 2012 at 4:56 PM, Kay Sievers <[email protected]> wrote:
>>> On Fri, Sep 28, 2012 at 4:49 PM, "Jan H. Schönherr"
>>
>>>> Given that I'm able to fix the racing case, would you be in favor of
>>>> this approach, or should we stick to the earlier version?
>>>
>>> I'm open to everything that makes sense. Let's see how it looks and we
>>> can decide when we have something that passes the tests.
>>
>> Jan,
>> any updates, did you try something else?
>> Or should we merge the first version for now?
>
> I'm working on it, though I cannot spend as much time as I want. :)
>
> My current version does mostly well for race-printk()s, now. But
> there's still one issue to resolve and some polishing to do.
>
> If we can afford to wait a little longer, we might get a nicer
> solution (and avoid a possible mostly-revert later).

Sure, no hurry, I was just going through my TODO emails. :)

Thanks,
Kay

2012-10-08 23:10:40

by Joe Perches

[permalink] [raw]
Subject: Re: [PATCH] printk: drop ambiguous LOG_CONT flag

On Mon, 2012-10-08 at 21:54 +0200, "Jan H. Sch?nherr" wrote:
> Am 08.10.2012 21:24, schrieb Kay Sievers:
> > On Fri, Sep 28, 2012 at 4:56 PM, Kay Sievers <[email protected]> wrote:
> >> On Fri, Sep 28, 2012 at 4:49 PM, "Jan H. Sch?nherr"
> >>> Given that I'm able to fix the racing case, would you be in favor of
> >>> this approach, or should we stick to the earlier version?
> >>
> >> I'm open to everything that makes sense. Let's see how it looks and we
> >> can decide when we have something that passes the tests.
[]
> > any updates, did you try something else?
> > Or should we merge the first version for now?
[]
> My current version does mostly well for race-printk()s, now. But
> there's still one issue to resolve and some polishing to do.
>
> If we can afford to wait a little longer, we might get a nicer
> solution (and avoid a possible mostly-revert later).

I've also got a large refactoring patch series to printk.c
(move and declutter) I was going to submit post rc-1.

No doubt there'll be several conflicts there too.

2012-11-02 03:54:23

by Kay Sievers

[permalink] [raw]
Subject: Re: [PATCH] printk: drop ambiguous LOG_CONT flag

On Mon, Oct 8, 2012 at 9:56 PM, Kay Sievers <[email protected]> wrote:
> On Mon, Oct 8, 2012 at 9:54 PM, "Jan H. Schönherr"

>>> Jan,
>>> any updates, did you try something else?
>>> Or should we merge the first version for now?
>>
>> I'm working on it, though I cannot spend as much time as I want. :)
>>
>> My current version does mostly well for race-printk()s, now. But
>> there's still one issue to resolve and some polishing to do.
>>
>> If we can afford to wait a little longer, we might get a nicer
>> solution (and avoid a possible mostly-revert later).
>
> Sure, no hurry, I was just going through my TODO emails. :)

My TODO is nagging me again. :)

Any updates? No problems if not, but we should merge the current
version then, I think.

Thanks,
Kay

2012-11-02 22:37:26

by Jan H. Schönherr

[permalink] [raw]
Subject: Re: [PATCH] printk: drop ambiguous LOG_CONT flag

Am 02.11.2012 04:53, schrieb Kay Sievers:
> On Mon, Oct 8, 2012 at 9:56 PM, Kay Sievers <[email protected]> wrote:
>> On Mon, Oct 8, 2012 at 9:54 PM, "Jan H. Schönherr"
>
>>>> Jan,
>>>> any updates, did you try something else?
>>>> Or should we merge the first version for now?
>>>
>>> I'm working on it, though I cannot spend as much time as I want. :)
>>>
>>> My current version does mostly well for race-printk()s, now. But
>>> there's still one issue to resolve and some polishing to do.
>>>
>>> If we can afford to wait a little longer, we might get a nicer
>>> solution (and avoid a possible mostly-revert later).
>>
>> Sure, no hurry, I was just going through my TODO emails. :)
>
> My TODO is nagging me again. :)
>
> Any updates? No problems if not, but we should merge the current
> version then, I think.
>

Then let's take the first version. :)

Thanks
Jan

2012-11-02 23:36:16

by Greg Kroah-Hartman

[permalink] [raw]
Subject: Re: [PATCH] printk: drop ambiguous LOG_CONT flag

On Fri, Nov 02, 2012 at 11:37:10PM +0100, "Jan H. Sch?nherr" wrote:
> Am 02.11.2012 04:53, schrieb Kay Sievers:
> > On Mon, Oct 8, 2012 at 9:56 PM, Kay Sievers <[email protected]> wrote:
> >> On Mon, Oct 8, 2012 at 9:54 PM, "Jan H. Sch?nherr"
> >
> >>>> Jan,
> >>>> any updates, did you try something else?
> >>>> Or should we merge the first version for now?
> >>>
> >>> I'm working on it, though I cannot spend as much time as I want. :)
> >>>
> >>> My current version does mostly well for race-printk()s, now. But
> >>> there's still one issue to resolve and some polishing to do.
> >>>
> >>> If we can afford to wait a little longer, we might get a nicer
> >>> solution (and avoid a possible mostly-revert later).
> >>
> >> Sure, no hurry, I was just going through my TODO emails. :)
> >
> > My TODO is nagging me again. :)
> >
> > Any updates? No problems if not, but we should merge the current
> > version then, I think.
> >
>
> Then let's take the first version. :)

Someone needs to resend it then, as it's lost to the archives of my
inbox, sorry.

greg k-h

2012-11-03 21:13:32

by Jan H. Schönherr

[permalink] [raw]
Subject: [PATCH resend] printk: drop ambiguous LOG_CONT flag

From: Jan H. Schönherr <[email protected]>

The meaning of LOG_CONT is unclear, i. e., whether a message is a starting,
ending, or middle fragment. Unfortunately, this cannot be inferred from
the LOG_PREFIX and LOG_NEWLINE flags, as they are not always kept.
Furthermore, in some cases LOG_CONT is set, although it is unknown if
there will be a continuation. This leads to wrongly concatenated output.

Fix this by dropping LOG_CONT and rely on LOG_PREFIX and LOG_NEWLINE to
distinguish the type of fragment. That is, if LOG_PREFIX is set, this
fragment does not continue the previous fragment. And if LOG_NEWLINE is
set, this fragment is not continued by the next fragment.

(Unfortunately, we still have to look at the previous fragment to catch the
case of an unset LOG_PREFIX on this fragment, but a set LOG_NEWLINE on
the previous fragment.)

Tested-By: Kay Sievers <[email protected]>
Signed-off-by: Jan H. Schönherr <[email protected]>
---
Against linux-next from 20121102, added Kay's tested-by.
---
kernel/printk.c | 57 +++++++++++++++++++++++++++++++++------------------------
1 file changed, 33 insertions(+), 24 deletions(-)

diff --git a/kernel/printk.c b/kernel/printk.c
index 22e070f..e8e4e67 100644
--- a/kernel/printk.c
+++ b/kernel/printk.c
@@ -203,7 +203,6 @@ enum log_flags {
LOG_NOCONS = 1, /* already flushed, do not print to console */
LOG_NEWLINE = 2, /* text ended with a newline */
LOG_PREFIX = 4, /* text started with a prefix */
- LOG_CONT = 8, /* text is a fragment of a continuation line */
};

struct log {
@@ -487,10 +486,9 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
* better readable output. 'c' in the record flags mark the first
* fragment of a line, '+' the following.
*/
- if (msg->flags & LOG_CONT && !(user->prev & LOG_CONT))
+ if (!(msg->flags & LOG_NEWLINE) && msg->flags & LOG_PREFIX)
cont = 'c';
- else if ((msg->flags & LOG_CONT) ||
- ((user->prev & LOG_CONT) && !(msg->flags & LOG_PREFIX)))
+ else if (!(user->prev & LOG_NEWLINE) && !(msg->flags & LOG_PREFIX))
cont = '+';

len = sprintf(user->buf, "%u,%llu,%llu,%c;",
@@ -893,15 +891,17 @@ static size_t msg_print_text(const struct log *msg, enum log_flags prev,
bool newline = true;
size_t len = 0;

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

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

- if (!(msg->flags & LOG_NEWLINE))
- newline = false;
+ if (!(prev & LOG_NEWLINE) && prefix) {
+ if (buf)
+ buf[len++] = '\n';
+ else
+ len++;
}

do {
@@ -1406,35 +1406,36 @@ static void cont_flush(enum log_flags flags)
if (cont.len == 0)
return;

+ cont.flags |= flags;
if (cont.cons) {
/*
* If a fragment of this line was directly flushed to the
* console; wait for the console to pick up the rest of the
* line. LOG_NOCONS suppresses a duplicated output.
*/
- log_store(cont.facility, cont.level, flags | LOG_NOCONS,
+ log_store(cont.facility, cont.level, cont.flags | LOG_NOCONS,
cont.ts_nsec, NULL, 0, cont.buf, cont.len);
- cont.flags = flags;
cont.flushed = true;
} else {
/*
* If no fragment of this line ever reached the console,
* just submit it to the store and free the buffer.
*/
- log_store(cont.facility, cont.level, flags, 0,
+ log_store(cont.facility, cont.level, cont.flags, 0,
NULL, 0, cont.buf, cont.len);
cont.len = 0;
}
}

-static bool cont_add(int facility, int level, const char *text, size_t len)
+static bool cont_add(int facility, int level, enum log_flags flags,
+ const char *text, size_t len)
{
if (cont.len && cont.flushed)
return false;

if (cont.len + len > sizeof(cont.buf)) {
/* the line gets too long, split it up in separate records */
- cont_flush(LOG_CONT);
+ cont_flush(0);
return false;
}

@@ -1443,7 +1444,7 @@ static bool cont_add(int facility, int level, const char *text, size_t len)
cont.level = level;
cont.owner = current;
cont.ts_nsec = local_clock();
- cont.flags = 0;
+ cont.flags = flags;
cont.cons = 0;
cont.flushed = false;
}
@@ -1452,7 +1453,7 @@ static bool cont_add(int facility, int level, const char *text, size_t len)
cont.len += len;

if (cont.len > (sizeof(cont.buf) * 80) / 100)
- cont_flush(LOG_CONT);
+ cont_flush(0);

return true;
}
@@ -1462,8 +1463,11 @@ static size_t cont_print_text(char *text, size_t size)
size_t textlen = 0;
size_t len;

- if (cont.cons == 0 && (console_prev & LOG_NEWLINE)) {
- textlen += print_time(cont.ts_nsec, text);
+ if (cont.cons == 0 && (console_prev & LOG_NEWLINE ||
+ cont.flags & LOG_PREFIX)) {
+ if (!(console_prev & LOG_NEWLINE))
+ text[textlen++] = '\n';
+ textlen += print_time(cont.ts_nsec, text + textlen);
size -= textlen;
}

@@ -1581,12 +1585,16 @@ asmlinkage int vprintk_emit(int facility, int level,
* Flush the conflicting buffer. An earlier newline was missing,
* or another task also prints continuation lines.
*/
- if (cont.len && (lflags & LOG_PREFIX || cont.owner != current))
- cont_flush(LOG_NEWLINE);
+ if (cont.len) {
+ if (cont.owner != current)
+ lflags |= LOG_PREFIX;
+ if (lflags & LOG_PREFIX)
+ cont_flush(LOG_NEWLINE);
+ }

/* buffer line if possible, otherwise store it right away */
- if (!cont_add(facility, level, text, text_len))
- log_store(facility, level, lflags | LOG_CONT, 0,
+ if (!cont_add(facility, level, lflags, text, text_len))
+ log_store(facility, level, lflags, 0,
dict, dictlen, text, text_len);
} else {
bool stored = false;
@@ -1599,7 +1607,8 @@ asmlinkage int vprintk_emit(int facility, int level,
*/
if (cont.len && cont.owner == current) {
if (!(lflags & LOG_PREFIX))
- stored = cont_add(facility, level, text, text_len);
+ stored = cont_add(facility, level, lflags,
+ text, text_len);
cont_flush(LOG_NEWLINE);
}

--
1.8.0.316.g291341c.dirty

2012-11-10 18:47:41

by Jan H. Schönherr

[permalink] [raw]
Subject: Re: [PATCH resend] printk: drop ambiguous LOG_CONT flag

Hi Greg.

This still needs a small fix, see below.

Am 03.11.2012 22:12, schrieb Jan H. Schönherr:
> From: Jan H. Schönherr <[email protected]>
>
> The meaning of LOG_CONT is unclear, i. e., whether a message is a starting,
> ending, or middle fragment. Unfortunately, this cannot be inferred from
> the LOG_PREFIX and LOG_NEWLINE flags, as they are not always kept.
> Furthermore, in some cases LOG_CONT is set, although it is unknown if
> there will be a continuation. This leads to wrongly concatenated output.
>
> Fix this by dropping LOG_CONT and rely on LOG_PREFIX and LOG_NEWLINE to
> distinguish the type of fragment. That is, if LOG_PREFIX is set, this
> fragment does not continue the previous fragment. And if LOG_NEWLINE is
> set, this fragment is not continued by the next fragment.
>
> (Unfortunately, we still have to look at the previous fragment to catch the
> case of an unset LOG_PREFIX on this fragment, but a set LOG_NEWLINE on
> the previous fragment.)
>
> Tested-By: Kay Sievers <[email protected]>
> Signed-off-by: Jan H. Schönherr <[email protected]>
> ---
> Against linux-next from 20121102, added Kay's tested-by.
> ---
> kernel/printk.c | 57 +++++++++++++++++++++++++++++++++------------------------
> 1 file changed, 33 insertions(+), 24 deletions(-)
>
> diff --git a/kernel/printk.c b/kernel/printk.c
> index 22e070f..e8e4e67 100644
> --- a/kernel/printk.c
> +++ b/kernel/printk.c

[...]

> @@ -1581,12 +1585,16 @@ asmlinkage int vprintk_emit(int facility, int level,
> * Flush the conflicting buffer. An earlier newline was missing,
> * or another task also prints continuation lines.
> */
> - if (cont.len && (lflags & LOG_PREFIX || cont.owner != current))
> - cont_flush(LOG_NEWLINE);
> + if (cont.len) {

This line should have been:
+ if (cont.len && !cont.flushed) {

The effect of this is that we now avoid to add a superfluous newline
over and over (due to setting LOG_PREFIX), when the cont buffer has been
flushed but not yet printed.

> + if (cont.owner != current)
> + lflags |= LOG_PREFIX;
> + if (lflags & LOG_PREFIX)
> + cont_flush(LOG_NEWLINE);
> + }
>
> /* buffer line if possible, otherwise store it right away */
> - if (!cont_add(facility, level, text, text_len))
> - log_store(facility, level, lflags | LOG_CONT, 0,
> + if (!cont_add(facility, level, lflags, text, text_len))
> + log_store(facility, level, lflags, 0,
> dict, dictlen, text, text_len);
> } else {
> bool stored = false;
> @@ -1599,7 +1607,8 @@ asmlinkage int vprintk_emit(int facility, int level,
> */
> if (cont.len && cont.owner == current) {

For symmetry reasons, the "if" here could use the same change. But here it
does not really matter as currently cont_add() and cont_flush() are NOPs when
cont.flushed is set.

> if (!(lflags & LOG_PREFIX))
> - stored = cont_add(facility, level, text, text_len);
> + stored = cont_add(facility, level, lflags,
> + text, text_len);
> cont_flush(LOG_NEWLINE);
> }

As I've not yet seen this patch turn up anywhere, I'm preparing a v2 of this
together with a couple of other patches that are now more or less ready.

Regards
Jan