[PATCH] drivers-core: beware dev_printk() from printing nonsense

[PATCH] drivers-core: beware dev_printk() from printing nonsense

[Sebastian Andrzej Siewior]

on boot I saw plenty of rubbish like:

|ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
|pci_root PNP0A03:00: Force enabled HPET at 0x%lx
|host bridge window [io  0x0000-0x0cf7] (ignored)
|pci_root PNP0A03:00: Force enabled HPET at 0x%lx
|host bridge window [io  0x0d00-0xffff] (ignored)
|pci_root PNP0A03:00: Force enabled HPET at 0x%lx
|ACPI: PCI Interrupt Link [LNKA] enabled at IRQ 10
|virtio-pci 0000:00:05.0: Force enabled HPET at 0x%lx

First I wonder myself why the kernel Force enables more than one HPET
and why the address isn't printed. Then I wasn't sure why virtio-pci
does the same thing.
As it turns out commit af7f2158fdee ("drivers-core: make structured
logging play nice with dynamic-debug") has probably an off by one error.
Since commit 314ba3520 ("printk: add kern_levels.h to make KERN_<LEVEL>
available for asm use") the whole shrunk by one byte. And for some
reason the compiler put the HPET string just after one of the kernel log
levels so level[3] was always true.

This should make the rubish go away, I am not sure if the dynamic debug
is still working. Jim could you please try?

Cc: Jim Cromie <jim.cromie@gmail.com>
Cc: Jason Baron <jbaron@redhat.com>
Cc: stable <stable@vger.kernel.org>
Cc: Kay Sievers <kay.sievers@vrfy.org>
Cc: Joe Perches <joe@perches.com>
Signed-off-by: Sebastian Andrzej Siewior <bigeasy@linutronix.de>
---
 drivers/base/core.c |    2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/drivers/base/core.c b/drivers/base/core.c
index cdd01c5..5a864c3 100644
--- a/drivers/base/core.c
+++ b/drivers/base/core.c
@@ -1912,7 +1912,7 @@ int __dev_printk(const char *level, const struct device *dev,
 				    "DEVICE=+%s:%s", subsys, dev_name(dev));
 	}
 skip:
-	if (level[3])
+	if (level[sizeof(KERN_ERR) - 1])
 		level_extra = &level[3]; /* skip past "<L>" */
 
 	return printk_emit(0, level[1] - '0',
-- 
1.7.10.4

Re: [PATCH] drivers-core: beware dev_printk() from printing nonsense

[Greg Kroah-Hartman]

On Mon, Aug 20, 2012 at 12:33:37PM +0200, Sebastian Andrzej Siewior wrote:
> on boot I saw plenty of rubbish like:
> 
> |ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
> |pci_root PNP0A03:00: Force enabled HPET at 0x%lx
> |host bridge window [io  0x0000-0x0cf7] (ignored)
> |pci_root PNP0A03:00: Force enabled HPET at 0x%lx
> |host bridge window [io  0x0d00-0xffff] (ignored)
> |pci_root PNP0A03:00: Force enabled HPET at 0x%lx
> |ACPI: PCI Interrupt Link [LNKA] enabled at IRQ 10
> |virtio-pci 0000:00:05.0: Force enabled HPET at 0x%lx
> 
> First I wonder myself why the kernel Force enables more than one HPET
> and why the address isn't printed. Then I wasn't sure why virtio-pci
> does the same thing.
> As it turns out commit af7f2158fdee ("drivers-core: make structured
> logging play nice with dynamic-debug") has probably an off by one error.
> Since commit 314ba3520 ("printk: add kern_levels.h to make KERN_<LEVEL>
> available for asm use") the whole shrunk by one byte. And for some
> reason the compiler put the HPET string just after one of the kernel log
> levels so level[3] was always true.
> 
> This should make the rubish go away, I am not sure if the dynamic debug
> is still working. Jim could you please try?
> 
> Cc: Jim Cromie <jim.cromie@gmail.com>
> Cc: Jason Baron <jbaron@redhat.com>
> Cc: stable <stable@vger.kernel.org>
> Cc: Kay Sievers <kay.sievers@vrfy.org>
> Cc: Joe Perches <joe@perches.com>
> Signed-off-by: Sebastian Andrzej Siewior <bigeasy@linutronix.de>
> ---
>  drivers/base/core.c |    2 +-
>  1 file changed, 1 insertion(+), 1 deletion(-)
> 
> diff --git a/drivers/base/core.c b/drivers/base/core.c
> index cdd01c5..5a864c3 100644
> --- a/drivers/base/core.c
> +++ b/drivers/base/core.c
> @@ -1912,7 +1912,7 @@ int __dev_printk(const char *level, const struct device *dev,
>  				    "DEVICE=+%s:%s", subsys, dev_name(dev));
>  	}
>  skip:
> -	if (level[3])
> +	if (level[sizeof(KERN_ERR) - 1])

This has already been fixed in my driver-core tree and will go to Linus
in a few hours.

thanks,

greg k-h

Re: [PATCH] drivers-core: beware dev_printk() from printing nonsense

[Sebastian Andrzej Siewior]

On 08/20/2012 05:26 PM, Greg Kroah-Hartman wrote:
>>   skip:
>> -	if (level[3])
>> +	if (level[sizeof(KERN_ERR) - 1])
>
> This has already been fixed in my driver-core tree and will go to Linus
> in a few hours.

Ah. So I'm too late. Care to send a patch which replace [2] with the
sizeof() operator like above?

>
> thanks,
>
> greg k-h

Sebastian

Re: [PATCH] drivers-core: beware dev_printk() from printing nonsense

[Joe Perches]

On Mon, 2012-08-20 at 18:53 +0200, Sebastian Andrzej Siewior wrote:
> On 08/20/2012 05:26 PM, Greg Kroah-Hartman wrote:
> >>   skip:
> >> -	if (level[3])
> >> +	if (level[sizeof(KERN_ERR) - 1])
> >
> > This has already been fixed in my driver-core tree and will go to Linus
> > in a few hours.
> 
> Ah. So I'm too late. Care to send a patch which replace [2] with the
> sizeof() operator like above?

Nope, the better fix is to use a different mechanism.

See commit acc8fa41ad31c5
("printk: add generic functions to find KERN_<LEVEL> headers")

and

commit 04d2c8c83d0e3a
("printk: convert the format for KERN_<LEVEL> to a 2 byte pattern")

I'll submit that "better fix" shortly after Greg's update has
been pulled/merged by Linus.

cheers, Joe