2010-11-23 10:39:52

by Uwe Kleine-König

[permalink] [raw]
Subject: Re: About multi-line printk and the need (not) to repeat loglevel markers [Was: Re: [PATCH] ARM: mx3/pcm037: properly allocate memory for mx3-camera]

Hello,

[extended the audience to lkml and a few more]

On Tue, Nov 23, 2010 at 10:12:11AM +0000, Russell King - ARM Linux wrote:
> On Tue, Nov 23, 2010 at 10:43:02AM +0100, Uwe Kleine-K?nig wrote:
> > There is no need to memzero the buffer because dma_alloc_coherent zeros
> > the memory for us.
> >
> > This fixes:
> >
> > BUG: Your driver calls ioremap() on system memory. This leads
> > <4>to architecturally unpredictable behaviour on ARMv6+, and ioremap()
> > <4>will fail in the next kernel release. Please fix your driver.
> >
> > Tested-by: Michael Grzeschik <[email protected]>
> > Signed-off-by: Uwe Kleine-K?nig <[email protected]>
> > ---
> [...]
> > I assume sending a patch to remove the <4> is just a waste of time,
> > isn't it?
(this message is generated by:

printk(KERN_WARNING "BUG: Your driver calls ioremap() on system memory. This leads\n"
KERN_WARNING "to architecturally unpredictable behaviour on ARMv6+, and ioremap()\n"
KERN_WARNING "will fail in the next kernel release. Please fix your driver.\n");

in arch/arm/mm/ioremap.c.)

> Hmm, someone changed the behaviour of printk - it used to require the
> tag after each newline. It seems that it only requires it as the first
> few characters now, which is a pain in the backside if you split
> printk's.
>
> IOW:
>
> printk(KERN_ERR "foo bar baz ");
> printk("buz\n" KERN_WARNING "fiz\n");
>
> used to result in "foo bar baz buz" being printed at error level, and
> "fiz" at warning level. Today, you'll get "foo bar baz buz" at error
> level, and "<4>fiz" at the default level.
>
> Note that it's not as simple as deleting the KERN_WARNING, because:
> printk(KERN_ERR "foo bar baz ");
> printk("buz\nfiz\n");
>
> will result in the same as above except for the missing <4> - which means
> "fiz" still ends up at the wrong severity level.
>
> Confusingly:
>
> printk(KERN_ERR "foo bar baz");
> printk(KERN_WARNING "buz\nfiz\n");
>
> will do as per the original, but is silly. Wonder how many other places
> are broken by this change.
I wonder if this was intended. It was introduced in v2.6.31-rc1~324
(printk: clean up handling of log-levels and newlines) by Linus.

Thinking about it I consider the current behaviour more sane, because
I cannot imagine a valid usecase to change the loglevel in a single
printk and having to repeat the same loglevel marker for each newline
isn't very effective, too. This for example fixes the usage of
pr_warning et al for multiline strings.

Is it worth to add some logic to vprint that handles repeating (or even
changing) markers after a newline?

Best regards
Uwe

--
Pengutronix e.K. | Uwe Kleine-K?nig |
Industrial Linux Solutions | http://www.pengutronix.de/ |


2010-11-23 10:58:48

by Uwe Kleine-König

[permalink] [raw]
Subject: Re: About multi-line printk and the need (not) to repeat loglevel markers [Was: Re: [PATCH] ARM: mx3/pcm037: properly allocate memory for mx3-camera]

On Tue, Nov 23, 2010 at 11:39:40AM +0100, Uwe Kleine-K?nig wrote:
> Hello,
>
> [extended the audience to lkml and a few more]
>
> On Tue, Nov 23, 2010 at 10:12:11AM +0000, Russell King - ARM Linux wrote:
> > On Tue, Nov 23, 2010 at 10:43:02AM +0100, Uwe Kleine-K?nig wrote:
> > > There is no need to memzero the buffer because dma_alloc_coherent zeros
> > > the memory for us.
> > >
> > > This fixes:
> > >
> > > BUG: Your driver calls ioremap() on system memory. This leads
> > > <4>to architecturally unpredictable behaviour on ARMv6+, and ioremap()
> > > <4>will fail in the next kernel release. Please fix your driver.
> > >
> > > Tested-by: Michael Grzeschik <[email protected]>
> > > Signed-off-by: Uwe Kleine-K?nig <[email protected]>
> > > ---
> > [...]
> > > I assume sending a patch to remove the <4> is just a waste of time,
> > > isn't it?
> (this message is generated by:
>
> printk(KERN_WARNING "BUG: Your driver calls ioremap() on system memory. This leads\n"
> KERN_WARNING "to architecturally unpredictable behaviour on ARMv6+, and ioremap()\n"
> KERN_WARNING "will fail in the next kernel release. Please fix your driver.\n");
>
> in arch/arm/mm/ioremap.c.)
>
> > Hmm, someone changed the behaviour of printk - it used to require the
> > tag after each newline. It seems that it only requires it as the first
> > few characters now, which is a pain in the backside if you split
> > printk's.
> >
> > IOW:
> >
> > printk(KERN_ERR "foo bar baz ");
> > printk("buz\n" KERN_WARNING "fiz\n");
> >
> > used to result in "foo bar baz buz" being printed at error level, and
> > "fiz" at warning level. Today, you'll get "foo bar baz buz" at error
> > level, and "<4>fiz" at the default level.
BTW, I just noticed that Linus wrote:

Additionally, if no newline existed, one is added (unless the
log-level is the explicit KERN_CONT marker, to explicitly show
that it's a continuation of a previous line).

This seems to be unimplemented, otherwise the output of

printk(KERN_ERR "foo bar baz ");
printk("buz\n" KERN_WARNING "fiz\n");

should be

"foo bar baz \n" at error level
"buz\n<4>fiz\n" at default level

useless_mail_counter++;

Uwe

--
Pengutronix e.K. | Uwe Kleine-K?nig |
Industrial Linux Solutions | http://www.pengutronix.de/ |

2010-11-23 22:16:59

by Linus Torvalds

[permalink] [raw]
Subject: Re: About multi-line printk and the need (not) to repeat loglevel markers [Was: Re: [PATCH] ARM: mx3/pcm037: properly allocate memory for mx3-camera]

10/11/23 Uwe Kleine-K?nig <[email protected]>:
>
> BTW, I just noticed that Linus wrote:
>
> ? ? ? ?Additionally, if no newline existed, one is added (unless the
> ? ? ? ?log-level is the explicit KERN_CONT marker, to explicitly show
> ? ? ? ?that it's a continuation of a previous line).
>
> This seems to be unimplemented, otherwise the output of
>
> ? ? ? ?printk(KERN_ERR "foo bar baz ");
> ? ? ? ?printk("buz\n" KERN_WARNING "fiz\n");
>
> should be
>
> ? ? ? ?"foo bar baz \n" at error level
> ? ? ? ?"buz\n<4>fiz\n" at default level

No. The KERN_WARNING in the middle of a string is always totally
bogus. There is no "should be". It's just wrong.

The "\n" is added automatically iff there is a log-level marker at the
beginning of the string (with LOG_CONT being the exception). So

printk("foo bar baz ");
printk(KERN_WARNING "fiz\n");

should output two lines ("foo bar baz" with the default loglevel, and
"fiz" with KERN_WARNING). Even though there is no explicit "\n" there
for the first one.

But KERN_XYZ anywhere but in the beginning of the string do not
matter. Adding newlines changes none of that. It doesn't make the
marker beginning of the string, it just makes it beginning of the
line.

Linus

2010-11-23 22:34:44

by Russell King - ARM Linux

[permalink] [raw]
Subject: Re: About multi-line printk and the need (not) to repeat loglevel markers [Was: Re: [PATCH] ARM: mx3/pcm037: properly allocate memory for mx3-camera]

On Wed, Nov 24, 2010 at 07:16:06AM +0900, Linus Torvalds wrote:
> No. The KERN_WARNING in the middle of a string is always totally
> bogus. There is no "should be". It's just wrong.
>
> The "\n" is added automatically iff there is a log-level marker at the
> beginning of the string (with LOG_CONT being the exception). So
>
> printk("foo bar baz ");
> printk(KERN_WARNING "fiz\n");
>
> should output two lines ("foo bar baz" with the default loglevel, and
> "fiz" with KERN_WARNING). Even though there is no explicit "\n" there
> for the first one.
>
> But KERN_XYZ anywhere but in the beginning of the string do not
> matter. Adding newlines changes none of that. It doesn't make the
> marker beginning of the string, it just makes it beginning of the
> line.

Oh dear.

Note that KERN_foo in the middle of strings, even after a newline are
preserved in the output. So:

printk(KERN_WARNING "BUG: Your driver calls ioremap() on system memory. This leads\n"
KERN_WARNING "to architecturally unpredictable behaviour on ARMv6+, and ioremap()\n"
KERN_WARNING "will fail in the next kernel release. Please fix your driver.\n");

results in <4>'s appearing on the console. I've always written code
over the last 15 years assuming that after any newline in printk output,
the log level gets reset and so needs a new log level specifier.

Sounds like this is something which needs auditing as a result of your
change, and sounds like its something that kernelnewbies people could
do. My own greps haven't revealed any cases though.

2010-11-23 23:23:32

by Joe Perches

[permalink] [raw]
Subject: Re: About multi-line printk and the need (not) to repeat loglevel markers [Was: Re: [PATCH] ARM: mx3/pcm037: properly allocate memory for mx3-camera]

On Tue, 23 Nov 2010, Russell King - ARM Linux wrote:

> On Wed, Nov 24, 2010 at 07:16:06AM +0900, Linus Torvalds wrote:
> > No. The KERN_WARNING in the middle of a string is always totally
> > bogus. There is no "should be". It's just wrong.
> Oh dear.
> Sounds like this is something which needs auditing as a result of your
> change, and sounds like its something that kernelnewbies people could
> do. My own greps haven't revealed any cases though.

They used to. I tried to fix all of the ones I could find
about a year ago.

commit ad361c9884e809340f6daca80d56a9e9c871690a
Author: Joe Perches <[email protected]>
Date: Mon Jul 6 13:05:40 2009 -0700

Remove multiple KERN_ prefixes from printk formats

Commit 5fd29d6ccbc98884569d6f3105aeca70858b3e0f ("printk: clean up
handling of log-levels and newlines") changed printk semantics. printk
lines with multiple KERN_<level> prefixes are no longer emitted as
before the patch.

<level> is now included in the output on each additional use.

Remove all uses of multiple KERN_<level>s in formats.

Signed-off-by: Joe Perches <[email protected]>
Signed-off-by: Linus Torvalds <[email protected]>

2010-11-24 00:57:43

by Joe Perches

[permalink] [raw]
Subject: [PATCH] md: Fix single printks with multiple KERN_<level>s

Noticed-by: Russell King <[email protected]>
Signed-off-by: Joe Perches <[email protected]>
---
> Note that KERN_foo in the middle of strings, even after a newline are
> preserved in the output. So:
>
> printk(KERN_WARNING "BUG: Your driver calls ioremap() on system memory. This leads\n"
> KERN_WARNING "to architecturally unpredictable behaviour on ARMv6+, and ioremap()\n"
> KERN_WARNING "will fail in the next kernel release. Please fix your driver.\n");
>
> results in <4>'s appearing on the console. I've always written code
> over the last 15 years assuming that after any newline in printk output,
> the log level gets reset and so needs a new log level specifier.
>
> Sounds like this is something which needs auditing as a result of your
> change, and sounds like its something that kernelnewbies people could
> do. My own greps haven't revealed any cases though.

drivers/md/raid1.c | 5 +++--
drivers/md/raid10.c | 5 +++--
drivers/md/raid5.c | 1 -
3 files changed, 6 insertions(+), 5 deletions(-)

diff --git a/drivers/md/raid1.c b/drivers/md/raid1.c
index 45f8324..e05381b 100644
--- a/drivers/md/raid1.c
+++ b/drivers/md/raid1.c
@@ -1027,8 +1027,9 @@ static void error(mddev_t *mddev, mdk_rdev_t *rdev)
} else
set_bit(Faulty, &rdev->flags);
set_bit(MD_CHANGE_DEVS, &mddev->flags);
- printk(KERN_ALERT "md/raid1:%s: Disk failure on %s, disabling device.\n"
- KERN_ALERT "md/raid1:%s: Operation continuing on %d devices.\n",
+ printk(KERN_ALERT
+ "md/raid1:%s: Disk failure on %s, disabling device.\n"
+ "md/raid1:%s: Operation continuing on %d devices.\n",
mdname(mddev), bdevname(rdev->bdev, b),
mdname(mddev), conf->raid_disks - mddev->degraded);
}
diff --git a/drivers/md/raid10.c b/drivers/md/raid10.c
index c67aa54..686543d 100644
--- a/drivers/md/raid10.c
+++ b/drivers/md/raid10.c
@@ -1051,8 +1051,9 @@ static void error(mddev_t *mddev, mdk_rdev_t *rdev)
}
set_bit(Faulty, &rdev->flags);
set_bit(MD_CHANGE_DEVS, &mddev->flags);
- printk(KERN_ALERT "md/raid10:%s: Disk failure on %s, disabling device.\n"
- KERN_ALERT "md/raid10:%s: Operation continuing on %d devices.\n",
+ printk(KERN_ALERT
+ "md/raid10:%s: Disk failure on %s, disabling device.\n"
+ "md/raid10:%s: Operation continuing on %d devices.\n",
mdname(mddev), bdevname(rdev->bdev, b),
mdname(mddev), conf->raid_disks - mddev->degraded);
}
diff --git a/drivers/md/raid5.c b/drivers/md/raid5.c
index dc574f3..316fbe7 100644
--- a/drivers/md/raid5.c
+++ b/drivers/md/raid5.c
@@ -1721,7 +1721,6 @@ static void error(mddev_t *mddev, mdk_rdev_t *rdev)
set_bit(Faulty, &rdev->flags);
printk(KERN_ALERT
"md/raid:%s: Disk failure on %s, disabling device.\n"
- KERN_ALERT
"md/raid:%s: Operation continuing on %d devices.\n",
mdname(mddev),
bdevname(rdev->bdev, b),

2010-11-24 05:16:44

by NeilBrown

[permalink] [raw]
Subject: Re: [PATCH] md: Fix single printks with multiple KERN_<level>s

On Tue, 23 Nov 2010 16:57:40 -0800
Joe Perches <[email protected]> wrote:

> Noticed-by: Russell King <[email protected]>
> Signed-off-by: Joe Perches <[email protected]>

Applied by: NeilBrown

Thanks a lot!

NeilBrown


> ---
> > Note that KERN_foo in the middle of strings, even after a newline are
> > preserved in the output. So:
> >
> > printk(KERN_WARNING "BUG: Your driver calls ioremap() on system memory. This leads\n"
> > KERN_WARNING "to architecturally unpredictable behaviour on ARMv6+, and ioremap()\n"
> > KERN_WARNING "will fail in the next kernel release. Please fix your driver.\n");
> >
> > results in <4>'s appearing on the console. I've always written code
> > over the last 15 years assuming that after any newline in printk output,
> > the log level gets reset and so needs a new log level specifier.
> >
> > Sounds like this is something which needs auditing as a result of your
> > change, and sounds like its something that kernelnewbies people could
> > do. My own greps haven't revealed any cases though.
>
> drivers/md/raid1.c | 5 +++--
> drivers/md/raid10.c | 5 +++--
> drivers/md/raid5.c | 1 -
> 3 files changed, 6 insertions(+), 5 deletions(-)
>
> diff --git a/drivers/md/raid1.c b/drivers/md/raid1.c
> index 45f8324..e05381b 100644
> --- a/drivers/md/raid1.c
> +++ b/drivers/md/raid1.c
> @@ -1027,8 +1027,9 @@ static void error(mddev_t *mddev, mdk_rdev_t *rdev)
> } else
> set_bit(Faulty, &rdev->flags);
> set_bit(MD_CHANGE_DEVS, &mddev->flags);
> - printk(KERN_ALERT "md/raid1:%s: Disk failure on %s, disabling device.\n"
> - KERN_ALERT "md/raid1:%s: Operation continuing on %d devices.\n",
> + printk(KERN_ALERT
> + "md/raid1:%s: Disk failure on %s, disabling device.\n"
> + "md/raid1:%s: Operation continuing on %d devices.\n",
> mdname(mddev), bdevname(rdev->bdev, b),
> mdname(mddev), conf->raid_disks - mddev->degraded);
> }
> diff --git a/drivers/md/raid10.c b/drivers/md/raid10.c
> index c67aa54..686543d 100644
> --- a/drivers/md/raid10.c
> +++ b/drivers/md/raid10.c
> @@ -1051,8 +1051,9 @@ static void error(mddev_t *mddev, mdk_rdev_t *rdev)
> }
> set_bit(Faulty, &rdev->flags);
> set_bit(MD_CHANGE_DEVS, &mddev->flags);
> - printk(KERN_ALERT "md/raid10:%s: Disk failure on %s, disabling device.\n"
> - KERN_ALERT "md/raid10:%s: Operation continuing on %d devices.\n",
> + printk(KERN_ALERT
> + "md/raid10:%s: Disk failure on %s, disabling device.\n"
> + "md/raid10:%s: Operation continuing on %d devices.\n",
> mdname(mddev), bdevname(rdev->bdev, b),
> mdname(mddev), conf->raid_disks - mddev->degraded);
> }
> diff --git a/drivers/md/raid5.c b/drivers/md/raid5.c
> index dc574f3..316fbe7 100644
> --- a/drivers/md/raid5.c
> +++ b/drivers/md/raid5.c
> @@ -1721,7 +1721,6 @@ static void error(mddev_t *mddev, mdk_rdev_t *rdev)
> set_bit(Faulty, &rdev->flags);
> printk(KERN_ALERT
> "md/raid:%s: Disk failure on %s, disabling device.\n"
> - KERN_ALERT
> "md/raid:%s: Operation continuing on %d devices.\n",
> mdname(mddev),
> bdevname(rdev->bdev, b),
>
>
> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at http://www.tux.org/lkml/

2010-11-24 08:18:04

by Uwe Kleine-König

[permalink] [raw]
Subject: Re: About multi-line printk and the need (not) to repeat loglevel markers [Was: Re: [PATCH] ARM: mx3/pcm037: properly allocate memory for mx3-camera]

Hello Linus,

On Wed, Nov 24, 2010 at 07:16:06AM +0900, Linus Torvalds wrote:
> 10/11/23 Uwe Kleine-K?nig <[email protected]>:
> >
> > BTW, I just noticed that Linus wrote:
> >
> > ? ? ? ?Additionally, if no newline existed, one is added (unless the
> > ? ? ? ?log-level is the explicit KERN_CONT marker, to explicitly show
> > ? ? ? ?that it's a continuation of a previous line).
> >
> > This seems to be unimplemented, otherwise the output of
> >
> > ? ? ? ?printk(KERN_ERR "foo bar baz ");
> > ? ? ? ?printk("buz\n" KERN_WARNING "fiz\n");
> >
> > should be
> >
> > ? ? ? ?"foo bar baz \n" at error level
> > ? ? ? ?"buz\n<4>fiz\n" at default level
>
> No. The KERN_WARNING in the middle of a string is always totally
> bogus. There is no "should be". It's just wrong.
>
> The "\n" is added automatically iff there is a log-level marker at the
> beginning of the string (with LOG_CONT being the exception).
So

printk("anything that doesn't look like a loglevel marker");

always behaves like

printk(KERN_CONT "anything that doesn't look like a loglevel marker");

so unless someone wants to print a literal kernel marker we can just do

-#define KERN_CONT "<c>"
+#define KERN_CONT ""

without any harm.

I wonder why you implemented "iff there is a log-level marker at the
beginning ot the string (with KERN_CONT being the exception)." and not
"unless there is a KERN_CONT marker".

> So
>
> printk("foo bar baz ");
> printk(KERN_WARNING "fiz\n");
>
> should output two lines ("foo bar baz" with the default loglevel, and
> "fiz" with KERN_WARNING). Even though there is no explicit "\n" there
> for the first one.
>
> But KERN_XYZ anywhere but in the beginning of the string do not
> matter. Adding newlines changes none of that. It doesn't make the
> marker beginning of the string, it just makes it beginning of the
> line.
I see one reason to interpret markers after a newline. In case
recursion_bug is true, printk_buf is initialized with recursion_bug_msg
and my message gets appended. So currently the marker I pass with my
message is ignored.
Maybe wanting to fix that is just my addiction to overengineering :-)

Best regards
Uwe

--
Pengutronix e.K. | Uwe Kleine-K?nig |
Industrial Linux Solutions | http://www.pengutronix.de/ |

2010-11-24 08:56:51

by Uwe Kleine-König

[permalink] [raw]
Subject: [PATCH 0/6] add some KERN_CONT markers to continuation lines

Hello,

> I wonder why you implemented "iff there is a log-level marker at the
> beginning ot the string (with KERN_CONT being the exception)." and not
> "unless there is a KERN_CONT marker".
While playing around with the latter variant some outputs broke (as
expected).

I don't know if we ever switch to do that, still make the continuation
lines explicit by adding the KERN_CONT marker. These appeared when
booting am ARM/imx machine, there are probably more ...

Best regards
Uwe

--
Pengutronix e.K. | Uwe Kleine-K?nig |
Industrial Linux Solutions | http://www.pengutronix.de/ |

2010-11-24 08:58:01

by Uwe Kleine-König

[permalink] [raw]
Subject: [PATCH 1/6] ARM: add some KERN_CONT markers to continuation lines

Cc: [email protected]
Signed-off-by: Uwe Kleine-König <[email protected]>
---
arch/arm/mm/fault-armv.c | 4 ++--
arch/arm/mm/init.c | 4 ++--
2 files changed, 4 insertions(+), 4 deletions(-)

diff --git a/arch/arm/mm/fault-armv.c b/arch/arm/mm/fault-armv.c
index 83e59f8..c8fb352 100644
--- a/arch/arm/mm/fault-armv.c
+++ b/arch/arm/mm/fault-armv.c
@@ -258,9 +258,9 @@ void __init check_writebuffer_bugs(void)
}

if (v) {
- printk("failed, %s\n", reason);
+ printk(KERN_CONT "failed, %s\n", reason);
shared_pte_mask = L_PTE_MT_UNCACHED;
} else {
- printk("ok\n");
+ printk(KERN_CONT "ok\n");
}
}
diff --git a/arch/arm/mm/init.c b/arch/arm/mm/init.c
index 5164069..947663a 100644
--- a/arch/arm/mm/init.c
+++ b/arch/arm/mm/init.c
@@ -549,9 +549,9 @@ void __init mem_init(void)
unsigned long pages = memblock_region_memory_end_pfn(reg) -
memblock_region_memory_base_pfn(reg);
num_physpages += pages;
- printk(" %ldMB", pages >> (20 - PAGE_SHIFT));
+ printk(KERN_CONT " %ldMB", pages >> (20 - PAGE_SHIFT));
}
- printk(" = %luMB total\n", num_physpages >> (20 - PAGE_SHIFT));
+ printk(KERN_CONT " = %luMB total\n", num_physpages >> (20 - PAGE_SHIFT));

printk(KERN_NOTICE "Memory: %luk/%luk available, %luk reserved, %luK highmem\n",
nr_free_pages() << (PAGE_SHIFT-10),
--
1.7.2.3

2010-11-24 08:58:11

by Uwe Kleine-König

[permalink] [raw]
Subject: [PATCH 6/6] tty/vt: add some KERN_CONT markers to continuation lines

Signed-off-by: Uwe Kleine-König <[email protected]>
---
drivers/tty/vt/vt.c | 10 +++++-----
1 files changed, 5 insertions(+), 5 deletions(-)

diff --git a/drivers/tty/vt/vt.c b/drivers/tty/vt/vt.c
index a8ec48e..e4b05ad 100644
--- a/drivers/tty/vt/vt.c
+++ b/drivers/tty/vt/vt.c
@@ -2930,11 +2930,11 @@ static int __init con_init(void)
gotoxy(vc, vc->vc_x, vc->vc_y);
csi_J(vc, 0);
update_screen(vc);
- printk("Console: %s %s %dx%d",
+ printk(KERN_DEFAULT "Console: %s %s %dx%d",
vc->vc_can_do_color ? "colour" : "mono",
display_desc, vc->vc_cols, vc->vc_rows);
printable = 1;
- printk("\n");
+ printk(KERN_CONT "\n");

release_console_sem();

@@ -3084,11 +3084,11 @@ static int bind_con_driver(const struct consw *csw, int first, int last,

printk("Console: switching ");
if (!deflt)
- printk("consoles %d-%d ", first+1, last+1);
+ printk(KERN_CONT "consoles %d-%d ", first+1, last+1);
if (j >= 0) {
struct vc_data *vc = vc_cons[j].d;

- printk("to %s %s %dx%d\n",
+ printk(KERN_CONT "to %s %s %dx%d\n",
vc->vc_can_do_color ? "colour" : "mono",
desc, vc->vc_cols, vc->vc_rows);

@@ -3097,7 +3097,7 @@ static int bind_con_driver(const struct consw *csw, int first, int last,
update_screen(vc);
}
} else
- printk("to %s\n", desc);
+ printk(KERN_CONT "to %s\n", desc);

retval = 0;
err:
--
1.7.2.3

2010-11-24 08:58:08

by Uwe Kleine-König

[permalink] [raw]
Subject: [PATCH 5/6] mm: add some KERN_CONT markers to continuation lines

Cc: [email protected]
Signed-off-by: Uwe Kleine-König <[email protected]>
---
mm/percpu.c | 12 ++++++------
1 files changed, 6 insertions(+), 6 deletions(-)

diff --git a/mm/percpu.c b/mm/percpu.c
index efe8168..3356646 100644
--- a/mm/percpu.c
+++ b/mm/percpu.c
@@ -1117,20 +1117,20 @@ static void pcpu_dump_alloc_info(const char *lvl,
for (alloc_end += gi->nr_units / upa;
alloc < alloc_end; alloc++) {
if (!(alloc % apl)) {
- printk("\n");
- printk("%spcpu-alloc: ", lvl);
+ printk(KERN_CONT "\n");
+ printk("%spcpu-alloc:", lvl);
}
- printk("[%0*d] ", group_width, group);
+ printk(KERN_CONT " [%0*d]", group_width, group);

for (unit_end += upa; unit < unit_end; unit++)
if (gi->cpu_map[unit] != NR_CPUS)
- printk("%0*d ", cpu_width,
+ printk(KERN_CONT " %0*d", cpu_width,
gi->cpu_map[unit]);
else
- printk("%s ", empty_str);
+ printk(KERN_CONT " %s", empty_str);
}
}
- printk("\n");
+ printk(KERN_CONT "\n");
}

/**
--
1.7.2.3

2010-11-24 08:58:38

by Uwe Kleine-König

[permalink] [raw]
Subject: [PATCH 4/6] init: add some KERN_CONT markers to continuation lines

Signed-off-by: Uwe Kleine-König <[email protected]>
---
init/do_mounts.c | 4 ++--
1 files changed, 2 insertions(+), 2 deletions(-)

diff --git a/init/do_mounts.c b/init/do_mounts.c
index 830aaec..5d2afd4 100644
--- a/init/do_mounts.c
+++ b/init/do_mounts.c
@@ -348,8 +348,8 @@ retry:
printk_all_partitions();
printk("No filesystem could mount root, tried: ");
for (p = fs_names; *p; p += strlen(p)+1)
- printk(" %s", p);
- printk("\n");
+ printk(KERN_CONT " %s", p);
+ printk(KERN_CONT "\n");
#ifdef CONFIG_BLOCK
__bdevname(ROOT_DEV, b);
#endif
--
1.7.2.3

2010-11-24 08:58:20

by Uwe Kleine-König

[permalink] [raw]
Subject: [PATCH 3/6] net: add some KERN_CONT markers to continuation lines

Cc: [email protected]
Signed-off-by: Uwe Kleine-König <[email protected]>
---
drivers/net/phy/phy.c | 4 ++--
net/ipv4/ipconfig.c | 32 ++++++++++++++++----------------
2 files changed, 18 insertions(+), 18 deletions(-)

diff --git a/drivers/net/phy/phy.c b/drivers/net/phy/phy.c
index 7670aac..a8445c7 100644
--- a/drivers/net/phy/phy.c
+++ b/drivers/net/phy/phy.c
@@ -47,11 +47,11 @@ void phy_print_status(struct phy_device *phydev)
pr_info("PHY: %s - Link is %s", dev_name(&phydev->dev),
phydev->link ? "Up" : "Down");
if (phydev->link)
- printk(" - %d/%s", phydev->speed,
+ printk(KERN_CONT " - %d/%s", phydev->speed,
DUPLEX_FULL == phydev->duplex ?
"Full" : "Half");

- printk("\n");
+ printk(KERN_CONT "\n");
}
EXPORT_SYMBOL(phy_print_status);

diff --git a/net/ipv4/ipconfig.c b/net/ipv4/ipconfig.c
index 3a6e1ec..2b09775 100644
--- a/net/ipv4/ipconfig.c
+++ b/net/ipv4/ipconfig.c
@@ -1191,13 +1191,13 @@ static int __init ic_dynamic(void)
(ic_proto_enabled & IC_USE_DHCP) &&
ic_dhcp_msgtype != DHCPACK) {
ic_got_reply = 0;
- printk(",");
+ printk(KERN_CONT ",");
continue;
}
#endif /* IPCONFIG_DHCP */

if (ic_got_reply) {
- printk(" OK\n");
+ printk(KERN_CONT " OK\n");
break;
}

@@ -1205,7 +1205,7 @@ static int __init ic_dynamic(void)
continue;

if (! --retries) {
- printk(" timed out!\n");
+ printk(KERN_CONT " timed out!\n");
break;
}

@@ -1215,7 +1215,7 @@ static int __init ic_dynamic(void)
if (timeout > CONF_TIMEOUT_MAX)
timeout = CONF_TIMEOUT_MAX;

- printk(".");
+ printk(KERN_CONT ".");
}

#ifdef IPCONFIG_BOOTP
@@ -1236,7 +1236,7 @@ static int __init ic_dynamic(void)
((ic_got_reply & IC_RARP) ? "RARP"
: (ic_proto_enabled & IC_USE_DHCP) ? "DHCP" : "BOOTP"),
&ic_servaddr);
- printk("my address is %pI4\n", &ic_myaddr);
+ printk(KERN_CONT "my address is %pI4\n", &ic_myaddr);

return 0;
}
@@ -1468,19 +1468,19 @@ static int __init ip_auto_config(void)
/*
* Clue in the operator.
*/
- printk("IP-Config: Complete:");
- printk("\n device=%s", ic_dev->name);
- printk(", addr=%pI4", &ic_myaddr);
- printk(", mask=%pI4", &ic_netmask);
- printk(", gw=%pI4", &ic_gateway);
- printk(",\n host=%s, domain=%s, nis-domain=%s",
+ printk("IP-Config: Complete:\n");
+ printk(" device=%s", ic_dev->name);
+ printk(KERN_CONT ", addr=%pI4", &ic_myaddr);
+ printk(KERN_CONT ", mask=%pI4", &ic_netmask);
+ printk(KERN_CONT ", gw=%pI4", &ic_gateway);
+ printk(KERN_CONT ",\n host=%s, domain=%s, nis-domain=%s",
utsname()->nodename, ic_domain, utsname()->domainname);
- printk(",\n bootserver=%pI4", &ic_servaddr);
- printk(", rootserver=%pI4", &root_server_addr);
- printk(", rootpath=%s", root_server_path);
+ printk(KERN_CONT ",\n bootserver=%pI4", &ic_servaddr);
+ printk(KERN_CONT ", rootserver=%pI4", &root_server_addr);
+ printk(KERN_CONT ", rootpath=%s", root_server_path);
if (ic_dev_mtu)
- printk(", mtu=%d", ic_dev_mtu);
- printk("\n");
+ printk(KERN_CONT ", mtu=%d", ic_dev_mtu);
+ printk(KERN_CONT "\n");
#endif /* !SILENT */

return 0;
--
1.7.2.3

2010-11-24 08:58:06

by Uwe Kleine-König

[permalink] [raw]
Subject: [PATCH 2/6] block: add some KERN_CONT markers to continuation lines

Cc: Jens Axboe <[email protected]>
Signed-off-by: Uwe Kleine-König <[email protected]>
---
block/genhd.c | 8 ++++----
1 files changed, 4 insertions(+), 4 deletions(-)

diff --git a/block/genhd.c b/block/genhd.c
index 5fa2b44..9437048 100644
--- a/block/genhd.c
+++ b/block/genhd.c
@@ -665,19 +665,19 @@ void __init printk_all_partitions(void)
if (part->info)
part_unpack_uuid(part->info->uuid, uuid);

- printk("%s%s %10llu %s %s", is_part0 ? "" : " ",
+ printk(KERN_CONT "%s%s %10llu %s %s", is_part0 ? "" : " ",
bdevt_str(part_devt(part), devt_buf),
(unsigned long long)part->nr_sects >> 1,
disk_name(disk, part->partno, name_buf), uuid);
if (is_part0) {
if (disk->driverfs_dev != NULL &&
disk->driverfs_dev->driver != NULL)
- printk(" driver: %s\n",
+ printk(KERN_CONT " driver: %s\n",
disk->driverfs_dev->driver->name);
else
- printk(" (driver?)\n");
+ printk(KERN_CONT " (driver?)\n");
} else
- printk("\n");
+ printk(KERN_CONT "\n");
}
disk_part_iter_exit(&piter);
}
--
1.7.2.3

2010-11-24 09:09:38

by Michał Mirosław

[permalink] [raw]
Subject: Re: About multi-line printk and the need (not) to repeat loglevel markers [Was: Re: [PATCH] ARM: mx3/pcm037: properly allocate memory for mx3-camera]

2010/11/24 Uwe Kleine-K?nig <[email protected]>:
> Hello Linus,
>
> On Wed, Nov 24, 2010 at 07:16:06AM +0900, Linus Torvalds wrote:
>> 10/11/23 Uwe Kleine-K?nig <[email protected]>:
>> >
>> > BTW, I just noticed that Linus wrote:
>> >
>> > ? ? ? ?Additionally, if no newline existed, one is added (unless the
>> > ? ? ? ?log-level is the explicit KERN_CONT marker, to explicitly show
>> > ? ? ? ?that it's a continuation of a previous line).
>> >
>> > This seems to be unimplemented, otherwise the output of
>> >
>> > ? ? ? ?printk(KERN_ERR "foo bar baz ");
>> > ? ? ? ?printk("buz\n" KERN_WARNING "fiz\n");
>> >
>> > should be
>> >
>> > ? ? ? ?"foo bar baz \n" at error level
>> > ? ? ? ?"buz\n<4>fiz\n" at default level
>>
>> No. The KERN_WARNING in the middle of a string is always totally
>> bogus. There is no "should be". It's just wrong.
>>
>> The "\n" is added automatically iff there is a log-level marker at the
>> beginning of the string (with LOG_CONT being the exception).
> So
>
> ? ? ? ?printk("anything that doesn't look like a loglevel marker");
>
> always behaves like
>
> ? ? ? ?printk(KERN_CONT "anything that doesn't look like a loglevel marker");
>
> so unless someone wants to print a literal kernel marker we can just do
>
> -#define ? ? ? ?KERN_CONT ? ? ? "<c>"
> +#define ? ? ? ?KERN_CONT ? ? ? ""
>
> without any harm.
>
> I wonder why you implemented "iff there is a log-level marker at the
> beginning ot the string (with KERN_CONT being the exception)." and not
> "unless there is a KERN_CONT marker".
>
>> ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ?So
>>
>> ? ?printk("foo bar baz ");
>> ? ?printk(KERN_WARNING "fiz\n");
>>
>> should output two lines ("foo bar baz" with the default loglevel, and
>> "fiz" with KERN_WARNING). Even though there is no explicit "\n" there
>> for the first one.
>>
>> But KERN_XYZ anywhere but in the beginning of the string do not
>> matter. Adding newlines changes none of that. It doesn't make the
>> marker beginning of the string, it just makes it beginning of the
>> line.
> I see one reason to interpret markers after a newline. ?In case
> recursion_bug is true, printk_buf is initialized with recursion_bug_msg
> and my message gets appended. ?So currently the marker I pass with my
> message is ignored.
> Maybe wanting to fix that is just my addiction to overengineering :-)

Hello, Kernel Hackers!

I think that KERN_CONT and any other form of continuation printks() is
just source of trouble.

This is usually used in code like this:

int init_dev(...)
{
...
printk("Initializing dev %s ... ", dev->name);
/* do initialize, sleeping/scheduling is allowed */
printk("%s.\n", ok ? "done" : "error");
...
}

When parallel initialization is done you might expect output like this:

Initializing dev A ...
Initializing dev B ... error.
done.

And now guess which one failed.

Second case against printk() continuations is netconsole. Every
printk() output is sent as separate packet with no ordering or
delivery guarantees, and usually logged as separate lines by remote
logging daemon. From the example code above, you might get this in
remote log:

Initializing dev A ...
done.
Initializing dev B ...
error.

When in reality A failed and B initialized properly. (Yes, I know this
is highly unlikely, but still - possible.)

Best Regards,
Micha? Miros?aw

2010-11-28 18:48:30

by David Miller

[permalink] [raw]
Subject: Re: [PATCH 3/6] net: add some KERN_CONT markers to continuation lines

From: Uwe Kleine-K?nig <[email protected]>
Date: Wed, 24 Nov 2010 09:57:47 +0100

> Cc: [email protected]
> Signed-off-by: Uwe Kleine-K?nig <[email protected]>

Applied.

2011-02-28 15:16:45

by Uwe Kleine-König

[permalink] [raw]
Subject: Re: [PATCH 6/6] tty/vt: add some KERN_CONT markers to continuation lines

Hello Greg,

should this patch go via your tree?

Thanks
Uwe

On Wed, Nov 24, 2010 at 09:57:50AM +0100, Uwe Kleine-K?nig wrote:
> Signed-off-by: Uwe Kleine-K?nig <[email protected]>
> ---
> drivers/tty/vt/vt.c | 10 +++++-----
> 1 files changed, 5 insertions(+), 5 deletions(-)
>
> diff --git a/drivers/tty/vt/vt.c b/drivers/tty/vt/vt.c
> index a8ec48e..e4b05ad 100644
> --- a/drivers/tty/vt/vt.c
> +++ b/drivers/tty/vt/vt.c
> @@ -2930,11 +2930,11 @@ static int __init con_init(void)
> gotoxy(vc, vc->vc_x, vc->vc_y);
> csi_J(vc, 0);
> update_screen(vc);
> - printk("Console: %s %s %dx%d",
> + printk(KERN_DEFAULT "Console: %s %s %dx%d",
> vc->vc_can_do_color ? "colour" : "mono",
> display_desc, vc->vc_cols, vc->vc_rows);
> printable = 1;
> - printk("\n");
> + printk(KERN_CONT "\n");
>
> release_console_sem();
>
> @@ -3084,11 +3084,11 @@ static int bind_con_driver(const struct consw *csw, int first, int last,
>
> printk("Console: switching ");
> if (!deflt)
> - printk("consoles %d-%d ", first+1, last+1);
> + printk(KERN_CONT "consoles %d-%d ", first+1, last+1);
> if (j >= 0) {
> struct vc_data *vc = vc_cons[j].d;
>
> - printk("to %s %s %dx%d\n",
> + printk(KERN_CONT "to %s %s %dx%d\n",
> vc->vc_can_do_color ? "colour" : "mono",
> desc, vc->vc_cols, vc->vc_rows);
>
> @@ -3097,7 +3097,7 @@ static int bind_con_driver(const struct consw *csw, int first, int last,
> update_screen(vc);
> }
> } else
> - printk("to %s\n", desc);
> + printk(KERN_CONT "to %s\n", desc);
>
> retval = 0;
> err:
> --
> 1.7.2.3
>
>

--
Pengutronix e.K. | Uwe Kleine-K?nig |
Industrial Linux Solutions | http://www.pengutronix.de/ |

2011-02-28 15:17:40

by Uwe Kleine-König

[permalink] [raw]
Subject: Re: [PATCH 5/6] mm: add some KERN_CONT markers to continuation lines

Hello,


On Wed, Nov 24, 2010 at 09:57:49AM +0100, Uwe Kleine-K?nig wrote:
> Cc: [email protected]
> Signed-off-by: Uwe Kleine-K?nig <[email protected]>
> ---
> mm/percpu.c | 12 ++++++------
> 1 files changed, 6 insertions(+), 6 deletions(-)
>
> diff --git a/mm/percpu.c b/mm/percpu.c
> index efe8168..3356646 100644
> --- a/mm/percpu.c
> +++ b/mm/percpu.c
> @@ -1117,20 +1117,20 @@ static void pcpu_dump_alloc_info(const char *lvl,
> for (alloc_end += gi->nr_units / upa;
> alloc < alloc_end; alloc++) {
> if (!(alloc % apl)) {
> - printk("\n");
> - printk("%spcpu-alloc: ", lvl);
> + printk(KERN_CONT "\n");
> + printk("%spcpu-alloc:", lvl);
> }
> - printk("[%0*d] ", group_width, group);
> + printk(KERN_CONT " [%0*d]", group_width, group);
>
> for (unit_end += upa; unit < unit_end; unit++)
> if (gi->cpu_map[unit] != NR_CPUS)
> - printk("%0*d ", cpu_width,
> + printk(KERN_CONT " %0*d", cpu_width,
> gi->cpu_map[unit]);
> else
> - printk("%s ", empty_str);
> + printk(KERN_CONT " %s", empty_str);
> }
> }
> - printk("\n");
> + printk(KERN_CONT "\n");
> }
>
> /**
ping

Best regards
Uwe

--
Pengutronix e.K. | Uwe Kleine-K?nig |
Industrial Linux Solutions | http://www.pengutronix.de/ |

2011-02-28 15:40:39

by Greg KH

[permalink] [raw]
Subject: Re: [PATCH 6/6] tty/vt: add some KERN_CONT markers to continuation lines

On Mon, Feb 28, 2011 at 04:16:41PM +0100, Uwe Kleine-K?nig wrote:
> Hello Greg,
>
> should this patch go via your tree?

Yes, care to resend it in a format I can apply it in?

thanks,

greg k-h

2011-02-28 15:50:16

by Uwe Kleine-König

[permalink] [raw]
Subject: Re: [PATCH 6/6] tty/vt: add some KERN_CONT markers to continuation lines

Hello Greg,

On Mon, Feb 28, 2011 at 07:39:46AM -0800, Greg KH wrote:
> On Mon, Feb 28, 2011 at 04:16:41PM +0100, Uwe Kleine-K?nig wrote:
> > Hello Greg,
> >
> > should this patch go via your tree?
>
> Yes, care to resend it in a format I can apply it in?
I bounced you the original mail assuming this is enough.

Best regards
Uwe

--
Pengutronix e.K. | Uwe Kleine-K?nig |
Industrial Linux Solutions | http://www.pengutronix.de/ |

2011-02-28 16:04:16

by Greg KH

[permalink] [raw]
Subject: Re: [PATCH 6/6] tty/vt: add some KERN_CONT markers to continuation lines

On Mon, Feb 28, 2011 at 04:50:08PM +0100, Uwe Kleine-K?nig wrote:
> Hello Greg,
>
> On Mon, Feb 28, 2011 at 07:39:46AM -0800, Greg KH wrote:
> > On Mon, Feb 28, 2011 at 04:16:41PM +0100, Uwe Kleine-K?nig wrote:
> > > Hello Greg,
> > >
> > > should this patch go via your tree?
> >
> > Yes, care to resend it in a format I can apply it in?
> I bounced you the original mail assuming this is enough.

Yup, I'll queue it up in a few days, thanks.

greg k-h

2011-03-01 05:48:24

by Greg KH

[permalink] [raw]
Subject: Re: [PATCH 6/6] tty/vt: add some KERN_CONT markers to continuation lines

On Wed, Nov 24, 2010 at 09:57:50AM +0100, Uwe Kleine-K?nig wrote:
> Signed-off-by: Uwe Kleine-K?nig <[email protected]>
> ---
> drivers/tty/vt/vt.c | 10 +++++-----

This doesn't apply on the linux-next tree, care to refresh it and
resend so I can apply it?

thanks,

greg k-h

2011-03-01 21:47:15

by Linus Torvalds

[permalink] [raw]
Subject: Re: [PATCH 5/6] mm: add some KERN_CONT markers to continuation lines

2011/2/28 Uwe Kleine-K?nig <[email protected]>:
> Hello,
>
>
> On Wed, Nov 24, 2010 at 09:57:49AM +0100, Uwe Kleine-K?nig wrote:
>> - ? ? ? ? ? ? ? ? ? ? ? ? ? ? printk("\n");
>> - ? ? ? ? ? ? ? ? ? ? ? ? ? ? printk("%spcpu-alloc: ", lvl);
>> + ? ? ? ? ? ? ? ? ? ? ? ? ? ? printk(KERN_CONT "\n");
>> + ? ? ? ? ? ? ? ? ? ? ? ? ? ? printk("%spcpu-alloc:", lvl);

So I hate this kind of "mindless search-and-replace" patch.

The whole point is that with the modern printk semantics, the above
kind of crazy cdoe shouldn't be needed. You should be able to just
write

printk("%spcpu-alloc:", lvl);

without that "\n" at all, because printk() will insert the \n if
necessary. So the concept of

printk(KERN_CONT "\n")

is just crazy: you're saying "I want to continue the line, in order to
print a newline". Whaa?

>> - ? ? ? ? ? ? ? ? ? ? printk("[%0*d] ", group_width, group);
>> + ? ? ? ? ? ? ? ? ? ? printk(KERN_CONT " [%0*d]", group_width, group);
>> - ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? printk("%0*d ", cpu_width,
>> + ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? printk(KERN_CONT " %0*d", cpu_width,
>> - ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? printk("%s ", empty_str);
>> + ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? printk(KERN_CONT " %s", empty_str);

These look ok, but:

>> - ? ? printk("\n");
>> + ? ? printk(KERN_CONT "\n");

Same deal. Why do KERN_CONT + "\n"?

Yes, yes, it does have semantic meaning ("do newline _now_"), and can
matter if you are going to use KERN_CONT exclusively around it. But it
still smells like just being silly to me. The point of the printk
changes was to make things simpler. I really would suggest just
removing those KERN_CONT "\n" lines. Doesn't it end up looking fine
that way too?

Linus

2011-03-02 05:28:05

by Joe Perches

[permalink] [raw]
Subject: Re: [PATCH 5/6] mm: add some KERN_CONT markers to continuation lines

On Tue, 2011-03-01 at 13:46 -0800, Linus Torvalds wrote:
> the concept of
> printk(KERN_CONT "\n")
> is just crazy: you're saying "I want to continue the line, in order to
> print a newline". Whaa?

It's a trivially useful "end of collected printk" mark,
which was made a bit superfluous by the code that added
any necessary newline before every KERN_<level>.

There are a thousand or so of them today.

$ grep -rP --include=*.[ch] "\b(printk\s*\(\s*KERN_CONT|pr_cont\s*\(|printk\s*\()\s*\"\\\n\"" * | wc -l
1061

That code made all message terminating newlines a bit
obsolete. I won't be submitting any patches to remove
those EOM newlines any time soon.

I hope no one does that.

It would be actually useful to have some form like:

cookie = collected_printk_start()
loop:
collected_printk(cookie, ...) (...)
collected_printk_end(cookie)

so that interleaved messages from multiple
concurrent streams could be sensibly collected
either post processed or buffered.