[PATCH] efi: Add newline to cper DIMM location messages

[PATCH] efi: Add newline to cper DIMM location messages

[Luck, Tony]

We forgot the newline at the end of two messages. Add it.

Signed-off-by: Tony Luck <tony.luck-ral2JQCrhuEAvxtiuMwx3w@public.gmane.org>

---

diff --git a/drivers/firmware/efi/cper.c b/drivers/firmware/efi/cper.c
index 1491dd4f08f9..9f59f6ba271a 100644
--- a/drivers/firmware/efi/cper.c
+++ b/drivers/firmware/efi/cper.c
@@ -240,9 +240,9 @@ static void cper_print_mem(const char *pfx, const struct cper_sec_mem_err *mem)
 		const char *bank = NULL, *device = NULL;
 		dmi_memdev_name(mem->mem_dev_handle, &bank, &device);
 		if (bank != NULL && device != NULL)
-			printk("%s""DIMM location: %s %s", pfx, bank, device);
+			printk("%s""DIMM location: %s %s\n", pfx, bank, device);
 		else
-			printk("%s""DIMM DMI handle: 0x%.4x",
+			printk("%s""DIMM DMI handle: 0x%.4x\n",
 			       pfx, mem->mem_dev_handle);
 	}
 }

Re: [PATCH] efi: Add newline to cper DIMM location messages

[Matt Fleming]

On Fri, 24 Jan, at 02:30:38PM, Luck, Tony wrote:
> We forgot the newline at the end of two messages. Add it.
> 
> Signed-off-by: Tony Luck <tony.luck-ral2JQCrhuEAvxtiuMwx3w@public.gmane.org>

Looks fine to me. Are you going to take this or should I?

-- 
Matt Fleming, Intel Open Source Technology Center

RE: [PATCH] efi: Add newline to cper DIMM location messages

[Luck, Tony]

>> We forgot the newline at the end of two messages. Add it.
>> 
>> Signed-off-by: Tony Luck <tony.luck-ral2JQCrhuEAvxtiuMwx3w@public.gmane.org>
>
> Looks fine to me. Are you going to take this or should I?

If that's a "Ack" - then I can send it up.

-Tony

Re: [PATCH] efi: Add newline to cper DIMM location messages

[Matt Fleming]

On Mon, 27 Jan, at 05:35:18PM, Luck, Tony wrote:
> >> We forgot the newline at the end of two messages. Add it.
> >> 
> >> Signed-off-by: Tony Luck <tony.luck-ral2JQCrhuEAvxtiuMwx3w@public.gmane.org>
> >
> > Looks fine to me. Are you going to take this or should I?
> 
> If that's a "Ack" - then I can send it up.

Yep, that's an ACK.

-- 
Matt Fleming, Intel Open Source Technology Center

[PATCH] efi: Add newline to cper DIMM location messages

[Luck, Tony]

We forgot the newline at the end of two messages. Add it.

Acked-by: Matt Fleming <matt.fleming-ral2JQCrhuEAvxtiuMwx3w@public.gmane.org>
Signed-off-by: Tony Luck <tony.luck-ral2JQCrhuEAvxtiuMwx3w@public.gmane.org>

---

diff --git a/drivers/firmware/efi/cper.c b/drivers/firmware/efi/cper.c
index 1491dd4f08f9..9f59f6ba271a 100644
--- a/drivers/firmware/efi/cper.c
+++ b/drivers/firmware/efi/cper.c
@@ -240,9 +240,9 @@ static void cper_print_mem(const char *pfx, const struct cper_sec_mem_err *mem)
 		const char *bank = NULL, *device = NULL;
 		dmi_memdev_name(mem->mem_dev_handle, &bank, &device);
 		if (bank != NULL && device != NULL)
-			printk("%s""DIMM location: %s %s", pfx, bank, device);
+			printk("%s""DIMM location: %s %s\n", pfx, bank, device);
 		else
-			printk("%s""DIMM DMI handle: 0x%.4x",
+			printk("%s""DIMM DMI handle: 0x%.4x\n",
 			       pfx, mem->mem_dev_handle);
 	}
 }

Re: [PATCH] efi: Add newline to cper DIMM location messages

[Linus Torvalds]

On Mon, Jan 27, 2014 at 10:43 AM, Luck, Tony <tony.luck-ral2JQCrhuEAvxtiuMwx3w@public.gmane.org> wrote:
> We forgot the newline at the end of two messages. Add it.

So I don't think the patch is necessarily wrong, but does it actually matter?

The thing is, unless the next printk is a continuation (PR_CONT), the
newline should be added at that point. And if it isn't, then that's a
bug. So I'm wondering how this issue got noticed - does it actually
cause user-visible issues, or was it just code reading?

Because I'm wondering if we eventually should start thinking of that
final '\n' as pointless noise... The fact is, printk has different
semantics from printf, and maybe we should start taking advantage of
that rather than just slavishly follow tradition?

               Linus

RE: [PATCH] efi: Add newline to cper DIMM location messages

[Luck, Tony]

> The thing is, unless the next printk is a continuation (PR_CONT), the
> newline should be added at that point. And if it isn't, then that's a
> bug. So I'm wondering how this issue got noticed - does it actually
> cause user-visible issues, or was it just code reading?

The next thing that happened was a debug printk() that didn't have
any log level specified.

	printk("CMCI on cpu%d\n", smp_processor_id());

and no newline was added.

> Because I'm wondering if we eventually should start thinking of that
> final '\n' as pointless noise... The fact is, printk has different
> semantics from printf, and maybe we should start taking advantage of
> that rather than just slavishly follow tradition?

Once the janitors have eliminated all the places without a KERN_something,
and I train my fingers to put that in even for throwaway debugging lines,
then perhaps that will work.  Output will look a bit odd if you are watching
the serial console as the newlines will be delayed.  If some user application
spits out something - then you will also see concatenated things (but jumbled
user/kernel output is hard to avoid).

-Tony

Re: [PATCH] efi: Add newline to cper DIMM location messages

[Linus Torvalds]

[-- Attachment #1: Type: text/plain, Size: 1341 bytes --]

On Mon, Jan 27, 2014 at 11:48 AM, Luck, Tony <tony.luck-ral2JQCrhuEAvxtiuMwx3w@public.gmane.org> wrote:
>> The thing is, unless the next printk is a continuation (PR_CONT), the
>> newline should be added at that point. And if it isn't, then that's a
>> bug. So I'm wondering how this issue got noticed - does it actually
>> cause user-visible issues, or was it just code reading?
>
> The next thing that happened was a debug printk() that didn't have
> any log level specified.
>
>         printk("CMCI on cpu%d\n", smp_processor_id());
>
> and no newline was added.

Ok, I think that's a bug. Only an explicit KERN_CONT prefix should
cause a line continuation.

The new msg code seems to be terminally confused about this, and for
example, seems to completely ignore the KERN_CONT flag, and instead
tests for just LOG_PREFIX (which is set for any prefix, not the
KERN_CONT 'c' prefix).

And then it turns LOG_CONT to be about the *current* printk missing a
newline. So the whole new msg code seems to  be really confused about
what the whole KERN_CONT thing was all about, and mixed it up with
whether the message ended in a newline or not, which is entirely
bogus.

Adding more people.  Looking at the code in vprintk_emit(), somebody
is really confused.

Anyway, attached is a *totally* untested patch. Comments?

                  Linus

[-- Attachment #2: patch.diff --]
[-- Type: text/plain, Size: 2293 bytes --]

 kernel/printk/printk.c | 43 ++++++++++++-------------------------------
 1 file changed, 12 insertions(+), 31 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index b1d255f04135..fae5c8ab607d 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1561,7 +1561,9 @@ asmlinkage int vprintk_emit(int facility, int level,
 					level = kern_level - '0';
 			case 'd':	/* KERN_DEFAULT */
 				lflags |= LOG_PREFIX;
+				break;
 			case 'c':	/* KERN_CONT */
+				lflags |= LOG_CONT;
 				break;
 			}
 			text_len -= end_of_header - text;
@@ -1575,40 +1577,19 @@ asmlinkage int vprintk_emit(int facility, int level,
 	if (dict)
 		lflags |= LOG_PREFIX|LOG_NEWLINE;
 
-	if (!(lflags & LOG_NEWLINE)) {
-		/*
-		 * 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);
-
-		/* 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,
-				  dict, dictlen, text, text_len);
-	} else {
-		bool stored = false;
-
-		/*
-		 * If an earlier newline was missing and it was the same task,
-		 * either merge it with the current buffer and flush, or if
-		 * there was a race with interrupts (prefix == true) then just
-		 * flush it out and store this line separately.
-		 * If the preceding printk was from a different task and missed
-		 * a newline, flush and append the newline.
-		 */
-		if (cont.len) {
-			if (cont.owner == current && !(lflags & LOG_PREFIX))
-				stored = cont_add(facility, level, text,
-						  text_len);
+	if (cont.len) {
+		if (cont.owner != current || !(lflags & LOG_CONT)) {
 			cont_flush(LOG_NEWLINE);
+			lflags &= ~LOG_CONT;
 		}
-
-		if (!stored)
-			log_store(facility, level, lflags, 0,
-				  dict, dictlen, text, text_len);
 	}
+
+	/*
+	 * If LOG_CONT is set, try to add the new message to any old one.
+	 * If that fails - or LOG_CONT wasmn't set - create a new record.
+	 */
+	if (!(lflags & LOG_CONT) || !cont_add(facility, level, text, text_len))
+		log_store(facility, level, lflags, 0, dict, dictlen, text, text_len);
 	printed_len += text_len;
 
 	/*

Re: [PATCH] efi: Add newline to cper DIMM location messages

[Joe Perches]

On Mon, 2014-01-27 at 14:09 -0800, Linus Torvalds wrote:
> On Mon, Jan 27, 2014 at 11:48 AM, Luck, Tony <tony.luck-ral2JQCrhuEAvxtiuMwx3w@public.gmane.org> wrote:
> >> The thing is, unless the next printk is a continuation (PR_CONT), the
> >> newline should be added at that point. And if it isn't, then that's a
> >> bug. So I'm wondering how this issue got noticed - does it actually
> >> cause user-visible issues, or was it just code reading?
> >
> > The next thing that happened was a debug printk() that didn't have
> > any log level specified.
> >
> >         printk("CMCI on cpu%d\n", smp_processor_id());
> >
> > and no newline was added.
> 
> Ok, I think that's a bug. Only an explicit KERN_CONT prefix should
> cause a line continuation.

I don't think it's a bug.
That's never been the case and isn't the case today.

In the past, if the printk buffer string prefix was
"<c>", the emitted string pointer was advanced by 3
and whatever else was emitted.

A dev_<level> though is always effectively newline
terminated even if it doesn't have end in an explicit
'\n'.  pr_cont uses after a dev_<level> are always
started on a new line.

That's sometimes unfortunate, but that is a fallout of
Kay's desire to have dev_<level> output always be a
complete message.

There was a patch proposed recently to fix some of the
scsi dev_<level> output followed by KERN_CONT that
previously would have been emitted on a single line
that is now on multiple lines.

https://lkml.org/lkml/2014/1/15/926

> The new msg code seems to be terminally confused about this, and for
> example, seems to completely ignore the KERN_CONT flag, and instead
> tests for just LOG_PREFIX (which is set for any prefix, not the
> KERN_CONT 'c' prefix).

btw: today, KERN_CONT is an empty string, not '<c>'.

include/linux/kern_levels.h:#define KERN_CONT   ""

Re: [PATCH] efi: Add newline to cper DIMM location messages

[Linus Torvalds]

On Mon, Jan 27, 2014 at 2:50 PM, Joe Perches <joe-6d6DIl74uiNBDgjK7y7TUQ@public.gmane.org> wrote:
> On Mon, 2014-01-27 at 14:09 -0800, Linus Torvalds wrote
>>
>> Ok, I think that's a bug. Only an explicit KERN_CONT prefix should
>> cause a line continuation.
>
> I don't think it's a bug.
> That's never been the case and isn't the case today.

We've certainly had different behavior over time, but we've tried to
generally go into the "do the right thing" direction.

See (for example)

    git show v3.3:kernel/printk.c | less -N

and look at lines 885-901.

Now, that code only triggers if there is *any* prefix (and I think
that we should probably make it trigger for the no-prefix case too),
but the thing is, we seem to really have broken that concept of
KERN_CONT being special.

And we seem to have broken that not so much because we've screwed up
the KERN_CONT logic itself, but because we ended up basically saying
"without any prefix, we do the old pre-linebreak default continuation
thing, so then we can make KERN_CONT empty, so now we have to do the
default continuation even if it doesn't make sense".

And _that_ in turn is a problem, because it means we missed the "oh,
we should make the non-prefix case actually be the same as
KERN_DEFAULT, not KERN_CONT.

Which I think is a bit sad. Because I think the better choice (from a
internal kernel usability standpoint) would have been to say "no
prefix means KERN_DEFAULT".

> In the past, if the printk buffer string prefix was
> "<c>", the emitted string pointer was advanced by 3
> and whatever else was emitted.

Yes, but we then also did that whole "let's break lines so that printk
is easier to use without getting ugly behavior etc". That happened

> A dev_<level> though is always effectively newline
> terminated even if it doesn't have end in an explicit
> '\n'.  pr_cont uses after a dev_<level> are always
> started on a new line.

But we're not talking about dev_xyz. We're talking about printk().

Now, printk() will inevitably behave a bit differently (if for no
other reason than the fact that it by definition *doesn't* have a
device, and *doesn't* have a specific log-level), and I think it's
somewhat reasonable that the "dev_xyz()" functions end up having the
model where they are always effectively single lines. printk() shares
much of the logic, and generally they should be *similar*, but clearly
they won't ever really be the same.

But that actually argues *more* for moving to a world where that
(common, but also often-forgotten) final '\n' at the end should be
de-emphasized. So I don't think it would be at all wrong to expect
that

    printk("Line A");
    printk("Line B");

should print two lines. We very much had that KERN_CONT to encode the
*exception* to this, for the (not very common) cases where we end up
listing multiple things on one line.

Now, I realize that we broke that at some point, and after having
broken it, we seem to have then said "KERN_CONT" doesn't do anything,
so let's make it an empty string.

But quite frankly, wouldn't it be much nicer if it was KERN_DEFAULT
that was the empty string, and KERN_CONT was the "yes, we want to
explicitly continue this line" one? So that the nide default behavior
would be that we'd not have these silly "\n" is meaningful *unless*
the next print-out happens to be a dev_xyzzy() or has an explicit
level.

> btw: today, KERN_CONT is an empty string, not '<c>'.
>
> include/linux/kern_levels.h:#define KERN_CONT   ""

Yes, I noticed that when I started looking at the history of this
thing. I just think we would be better off doing it the other way
around with KERN_DEFAULT instead, and basically move away from having
'\n' be so meaningful at the end.

Hmm?

                   Linus

RE: [PATCH] efi: Add newline to cper DIMM location messages

[Luck, Tony]

> But that actually argues *more* for moving to a world where that
> (common, but also often-forgotten) final '\n' at the end should be
> de-emphasized. So I don't think it would be at all wrong to expect
> that
>
>    printk("Line A");
>    printk("Line B");
>
> should print two lines. We very much had that KERN_CONT to encode the
> *exception* to this, for the (not very common) cases where we end up
> listing multiple things on one line.

Of course if people *really* want things on the same line, they usually end
up using sprintf() to save the individual pieces to some buffer and the dump
that out using one printk() call ... because KERN_CONT isn't much help when
some other code comes along and drops its own output in the middle of
what you were trying to pretty print.

-Tony

Re: [PATCH] efi: Add newline to cper DIMM location messages

[Joe Perches]

On Tue, 2014-01-28 at 00:26 +0000, Luck, Tony wrote:
> > But that actually argues *more* for moving to a world where that
> > (common, but also often-forgotten) final '\n' at the end should be
> > de-emphasized. So I don't think it would be at all wrong to expect
> > that
> >
> >    printk("Line A");
> >    printk("Line B");
> >
> > should print two lines. We very much had that KERN_CONT to encode the
> > *exception* to this, for the (not very common) cases where we end up
> > listing multiple things on one line.

Depends on how old the code in question is.

KERN_CONT was introduced in Oct 2007 (commit 4749252776)
and everything older than that actually did have the
intention of continuing a previous line or was a
defect.

KERN_DEFAULT was June 2009 (commit e28d7137041) and
that allowed printks to start with any KERN_<LEVEL>
but KERN_CONT and actually start on a new line too
even if the preceding printk did not end in '\n'.

There are very few uses overall of KERN_DEFAULT.

I think KERN_DEFAULT should be removed actually.
All the uses might be better with a specific level.

> Of course if people *really* want things on the same line, they usually end
> up using sprintf() to save the individual pieces to some buffer and the dump
> that out using one printk() call

No, actually, they don't.

There's probably much more code that uses KERN_CONT
or no KERN_ level where it's intended that the printks
be merged than uses of intermediate buffers.

There are many uses of %pV that effectively serve as a
mechanism to avoid using multiple printks though.

>  ... because KERN_CONT isn't much help when
> some other code comes along and drops its own output in the middle of
> what you were trying to pretty print.

Exactly true.

I've submitted quite a few patches that avoid multiple
printks by either using %pV or coalescing the separate
printks into a single printk.

There are _lots_ more that could be done.

Maybe adding a patch similar to what Linus proposes would
cause a lot more of these changes to be done quicker.

Re: [PATCH] efi: Add newline to cper DIMM location messages

[Linus Torvalds]

On Mon, Jan 27, 2014 at 4:44 PM, Joe Perches <joe-6d6DIl74uiNBDgjK7y7TUQ@public.gmane.org> wrote:
>
> There are very few uses overall of KERN_DEFAULT.
>
> I think KERN_DEFAULT should be removed actually.
> All the uses might be better with a specific level.

It's a long time ago, but I think one of the reasons for KERN_DEFAULT
was some of the precursor discussion to a different interface, where
people wanted to make the prefix a separate argument in order to
*force* it to be used. And that meant that you needed a separate value
for the default case, since you couldn't just skip it.

And that obviously never happened, and yes, KERN_DEFAULT is useless. I
agree that it could be removed, I'd just like the "no explicit level"
to behave like KERN_DEFAULT does..

>> Of course if people *really* want things on the same line, they usually end
>> up using sprintf() to save the individual pieces to some buffer and the dump
>> that out using one printk() call
>
> No, actually, they don't.
>
> There's probably much more code that uses KERN_CONT
> or no KERN_ level where it's intended that the printks
> be merged than uses of intermediate buffers.
>
> There are many uses of %pV that effectively serve as a
> mechanism to avoid using multiple printks though.

KERN_CONT is kind of hacky, but the thing is, it's very convenient.
And it's often used when it's important that things be reasonably
dense (in order to not make useless small details end up as lots of
useless separate lines), but for things that aren't really
*important*.

Sometimes people could generate single strings, but KERN_CONT is all
about convenience for those print-outs. And generating a bigger string
and then printing that all out in one go is often non-productive, when
you very much want to get incremental output (some of the really
traditional cases are for things like testing where you print the test
name and then "ok" afterwards, where you need to know that you're
testing even if the ok never happens - or _especially_ if the ok never
happens).

It's not a "good" interface, no. But it's a very simple and convenient
one for simple lists of supported features etc, and it actually does
have some cases where it would be actively *wrong* to try to do it the
"right" way with fancy preformatting.

                 Linus