small regression in mediatree/for_v3.7-3 - media_build

small regression in mediatree/for_v3.7-3 - media_build

[Hin-Tak Leung]

There seems to be a small regression on mediatree/for_v3.7-3
- dmesg/klog get flooded with these:

[201145.140260] dvb_frontend_poll: 15 callbacks suppressed
[201145.586405] usb_urb_complete: 88 callbacks suppressed
[201150.587308] usb_urb_complete: 3456 callbacks suppressed

[201468.630197] usb_urb_complete: 3315 callbacks suppressed
[201473.632978] usb_urb_complete: 3529 callbacks suppressed
[201478.635400] usb_urb_complete: 3574 callbacks suppressed

It seems to be every 5 seconds, but I think that's just klog skipping repeats and collapsing duplicate entries. This does not happen the last time I tried playing with the TV stick :-).

Re: small regression in mediatree/for_v3.7-3 - media_build

[Antti Palosaari]

On 08/15/2012 02:39 AM, Hin-Tak Leung wrote:
> There seems to be a small regression on mediatree/for_v3.7-3
> - dmesg/klog get flooded with these:
>
> [201145.140260] dvb_frontend_poll: 15 callbacks suppressed
> [201145.586405] usb_urb_complete: 88 callbacks suppressed
> [201150.587308] usb_urb_complete: 3456 callbacks suppressed
>
> [201468.630197] usb_urb_complete: 3315 callbacks suppressed
> [201473.632978] usb_urb_complete: 3529 callbacks suppressed
> [201478.635400] usb_urb_complete: 3574 callbacks suppressed
>
> It seems to be every 5 seconds, but I think that's just klog skipping repeats and collapsing duplicate entries. This does not happen the last time I tried playing with the TV stick :-).

That's because you has dynamic debugs enabled!
modprobe dvb_core; echo -n 'module dvb_core +p' > 
/sys/kernel/debug/dynamic_debug/control
modprobe dvb_usbv2; echo -n 'module dvb_usbv2 +p' > 
/sys/kernel/debug/dynamic_debug/control

If you don't add dvb_core and dvb_usbv2 modules to 
/sys/kernel/debug/dynamic_debug/control you will not see those.

I have added ratelimited version for those few debugs that are flooded 
normally. This suppressed is coming from ratelimit - it does not print 
all those similar debugs.

regards
Antti

-- 
http://palosaari.fi/

Re: small regression in mediatree/for_v3.7-3 - media_build

[Hin-Tak Leung]

--- On Wed, 15/8/12, Antti Palosaari <crope@iki.fi> wrote:

> On 08/15/2012 02:39 AM, Hin-Tak Leung
> wrote:
> > There seems to be a small regression on
> mediatree/for_v3.7-3
> > - dmesg/klog get flooded with these:
> > 
> > [201145.140260] dvb_frontend_poll: 15 callbacks
> suppressed
> > [201145.586405] usb_urb_complete: 88 callbacks
> suppressed
> > [201150.587308] usb_urb_complete: 3456 callbacks
> suppressed
> > 
> > [201468.630197] usb_urb_complete: 3315 callbacks
> suppressed
> > [201473.632978] usb_urb_complete: 3529 callbacks
> suppressed
> > [201478.635400] usb_urb_complete: 3574 callbacks
> suppressed
> > 
> > It seems to be every 5 seconds, but I think that's just
> klog skipping repeats and collapsing duplicate entries. This
> does not happen the last time I tried playing with the TV
> stick :-).
> 
> That's because you has dynamic debugs enabled!
> modprobe dvb_core; echo -n 'module dvb_core +p' >
> /sys/kernel/debug/dynamic_debug/control
> modprobe dvb_usbv2; echo -n 'module dvb_usbv2 +p' >
> /sys/kernel/debug/dynamic_debug/control
> 
> If you don't add dvb_core and dvb_usbv2 modules to
> /sys/kernel/debug/dynamic_debug/control you will not see
> those.
> 
> I have added ratelimited version for those few debugs that
> are flooded normally. This suppressed is coming from
> ratelimit - it does not print all those similar debugs.

I did not enable it - it is as shipped :-).

# grep 'CONFIG_DYNAMIC' /boot/config*
/boot/config-3.4.6-2.fc17.x86_64:CONFIG_DYNAMIC_FTRACE=y
/boot/config-3.4.6-2.fc17.x86_64:CONFIG_DYNAMIC_DEBUG=y
/boot/config-3.5.0-2.fc17.x86_64:CONFIG_DYNAMIC_FTRACE=y
/boot/config-3.5.0-2.fc17.x86_64:CONFIG_DYNAMIC_DEBUG=y
/boot/config-3.5.1-1.fc17.x86_64:CONFIG_DYNAMIC_FTRACE=y
/boot/config-3.5.1-1.fc17.x86_64:CONFIG_DYNAMIC_DEBUG=y

Now I wonder why I didn't have those usb_urb_complete messages before? The last time I played with mediatree was with 3.4.4-5.fc17.x86_64, and with the mediatree2/dvb_core branch - and I did not have these then.

Re: small regression in mediatree/for_v3.7-3 - media_build

[Antti Palosaari]

On 08/15/2012 03:44 AM, Hin-Tak Leung wrote:
> --- On Wed, 15/8/12, Antti Palosaari <crope@iki.fi> wrote:
>
>> On 08/15/2012 02:39 AM, Hin-Tak Leung
>> wrote:
>>> There seems to be a small regression on
>> mediatree/for_v3.7-3
>>> - dmesg/klog get flooded with these:
>>>
>>> [201145.140260] dvb_frontend_poll: 15 callbacks
>> suppressed
>>> [201145.586405] usb_urb_complete: 88 callbacks
>> suppressed
>>> [201150.587308] usb_urb_complete: 3456 callbacks
>> suppressed
>>>
>>> [201468.630197] usb_urb_complete: 3315 callbacks
>> suppressed
>>> [201473.632978] usb_urb_complete: 3529 callbacks
>> suppressed
>>> [201478.635400] usb_urb_complete: 3574 callbacks
>> suppressed
>>>
>>> It seems to be every 5 seconds, but I think that's just
>> klog skipping repeats and collapsing duplicate entries. This
>> does not happen the last time I tried playing with the TV
>> stick :-).
>>
>> That's because you has dynamic debugs enabled!
>> modprobe dvb_core; echo -n 'module dvb_core +p' >
>> /sys/kernel/debug/dynamic_debug/control
>> modprobe dvb_usbv2; echo -n 'module dvb_usbv2 +p' >
>> /sys/kernel/debug/dynamic_debug/control
>>
>> If you don't add dvb_core and dvb_usbv2 modules to
>> /sys/kernel/debug/dynamic_debug/control you will not see
>> those.
>>
>> I have added ratelimited version for those few debugs that
>> are flooded normally. This suppressed is coming from
>> ratelimit - it does not print all those similar debugs.
>
> I did not enable it - it is as shipped :-).
>
> # grep 'CONFIG_DYNAMIC' /boot/config*
> /boot/config-3.4.6-2.fc17.x86_64:CONFIG_DYNAMIC_FTRACE=y
> /boot/config-3.4.6-2.fc17.x86_64:CONFIG_DYNAMIC_DEBUG=y
> /boot/config-3.5.0-2.fc17.x86_64:CONFIG_DYNAMIC_FTRACE=y
> /boot/config-3.5.0-2.fc17.x86_64:CONFIG_DYNAMIC_DEBUG=y
> /boot/config-3.5.1-1.fc17.x86_64:CONFIG_DYNAMIC_FTRACE=y
> /boot/config-3.5.1-1.fc17.x86_64:CONFIG_DYNAMIC_DEBUG=y
>
> Now I wonder why I didn't have those usb_urb_complete messages before? The last time I played with mediatree was with 3.4.4-5.fc17.x86_64, and with the mediatree2/dvb_core branch - and I did not have these then.

Yeah, you are correct. There is something wrong now. I see also those 
ratelimited debugs even didn't ordered...

I think dev_dbg_ratelimited() is very new, there is no other users... I 
have to find out whats wrong.

Now I am finalizing DVB USB reset_resume(). Very cool. Looks like I can 
now continue watching television even USB controller gets reseted during 
suspend (reset resume). Every DVB USB device I have here seems to 
survive both normal resume and reset resume =)

regards
Antti


-- 
http://palosaari.fi/

noisy dev_dbg_ratelimited() [Re: small regression in mediatree/for_v3.7-3 - media_build]

[Antti Palosaari]

Hello Hiroshi,

I see you have added dev_dbg_ratelimited() recently, commit 
6ca045930338485a8cdef117e74372aa1678009d .

However it seems to be noisy as expected similar behavior than normal 
dev_dbg() without a ratelimit.

I looked ratelimit.c and there is:
printk(KERN_WARNING "%s: %d callbacks suppressed\n", func, rs->missed);

What it looks my eyes it will print those "callbacks suppressed" always 
because KERN_WARNING.

On 08/15/2012 04:05 AM, Antti Palosaari wrote:
> On 08/15/2012 03:44 AM, Hin-Tak Leung wrote:
>> --- On Wed, 15/8/12, Antti Palosaari <crope@iki.fi> wrote:
>>
>>> On 08/15/2012 02:39 AM, Hin-Tak Leung
>>> wrote:
>>>> There seems to be a small regression on
>>> mediatree/for_v3.7-3
>>>> - dmesg/klog get flooded with these:
>>>>
>>>> [201145.140260] dvb_frontend_poll: 15 callbacks
>>> suppressed
>>>> [201145.586405] usb_urb_complete: 88 callbacks
>>> suppressed
>>>> [201150.587308] usb_urb_complete: 3456 callbacks
>>> suppressed
>>>>
>>>> [201468.630197] usb_urb_complete: 3315 callbacks
>>> suppressed
>>>> [201473.632978] usb_urb_complete: 3529 callbacks
>>> suppressed
>>>> [201478.635400] usb_urb_complete: 3574 callbacks
>>> suppressed
>>>>
>>>> It seems to be every 5 seconds, but I think that's just
>>> klog skipping repeats and collapsing duplicate entries. This
>>> does not happen the last time I tried playing with the TV
>>> stick :-).
>>>
>>> That's because you has dynamic debugs enabled!
>>> modprobe dvb_core; echo -n 'module dvb_core +p' >
>>> /sys/kernel/debug/dynamic_debug/control
>>> modprobe dvb_usbv2; echo -n 'module dvb_usbv2 +p' >
>>> /sys/kernel/debug/dynamic_debug/control
>>>
>>> If you don't add dvb_core and dvb_usbv2 modules to
>>> /sys/kernel/debug/dynamic_debug/control you will not see
>>> those.
>>>
>>> I have added ratelimited version for those few debugs that
>>> are flooded normally. This suppressed is coming from
>>> ratelimit - it does not print all those similar debugs.
>>
>> I did not enable it - it is as shipped :-).
>>
>> # grep 'CONFIG_DYNAMIC' /boot/config*
>> /boot/config-3.4.6-2.fc17.x86_64:CONFIG_DYNAMIC_FTRACE=y
>> /boot/config-3.4.6-2.fc17.x86_64:CONFIG_DYNAMIC_DEBUG=y
>> /boot/config-3.5.0-2.fc17.x86_64:CONFIG_DYNAMIC_FTRACE=y
>> /boot/config-3.5.0-2.fc17.x86_64:CONFIG_DYNAMIC_DEBUG=y
>> /boot/config-3.5.1-1.fc17.x86_64:CONFIG_DYNAMIC_FTRACE=y
>> /boot/config-3.5.1-1.fc17.x86_64:CONFIG_DYNAMIC_DEBUG=y
>>
>> Now I wonder why I didn't have those usb_urb_complete messages before?
>> The last time I played with mediatree was with 3.4.4-5.fc17.x86_64,
>> and with the mediatree2/dvb_core branch - and I did not have these then.
>
> Yeah, you are correct. There is something wrong now. I see also those
> ratelimited debugs even didn't ordered...
>
> I think dev_dbg_ratelimited() is very new, there is no other users... I
> have to find out whats wrong.

regards
Antti

-- 
http://palosaari.fi/

Re: noisy dev_dbg_ratelimited()

[Hiroshi Doyu]

Hi Antti,

Antti Palosaari <crope@iki.fi> wrote @ Thu, 16 Aug 2012 03:11:56 +0200:

> Hello Hiroshi,
> 
> I see you have added dev_dbg_ratelimited() recently, commit 
> 6ca045930338485a8cdef117e74372aa1678009d .
> 
> However it seems to be noisy as expected similar behavior than normal 
> dev_dbg() without a ratelimit.
> 
> I looked ratelimit.c and there is:
> printk(KERN_WARNING "%s: %d callbacks suppressed\n", func, rs->missed);
> 
> What it looks my eyes it will print those "callbacks suppressed" always 
> because KERN_WARNING.

Right. Can the following fix the problem?

>From 905b1dedb6c64bc46a70f6d203ef98c23fccb107 Mon Sep 17 00:00:00 2001
From: Hiroshi Doyu <hdoyu@nvidia.com>
Date: Thu, 16 Aug 2012 10:02:11 +0300
Subject: [PATCH 1/1] driver-core: Shut up dev_dbg_reatelimited() without
 DEBUG

dev_dbg_reatelimited() without DEBUG printed "217078 callbacks
suppressed". This shouldn't print anything without DEBUG.

Signed-off-by: Hiroshi Doyu <hdoyu@nvidia.com>
Reported-by: Antti Palosaari <crope@iki.fi>
---
 include/linux/device.h |    6 +++++-
 1 files changed, 5 insertions(+), 1 deletions(-)

diff --git a/include/linux/device.h b/include/linux/device.h
index eb945e1..d4dc26e 100644
--- a/include/linux/device.h
+++ b/include/linux/device.h
@@ -962,9 +962,13 @@ do {									\
 	dev_level_ratelimited(dev_notice, dev, fmt, ##__VA_ARGS__)
 #define dev_info_ratelimited(dev, fmt, ...)				\
 	dev_level_ratelimited(dev_info, dev, fmt, ##__VA_ARGS__)
+#if defined(DEBUG)
 #define dev_dbg_ratelimited(dev, fmt, ...)				\
 	dev_level_ratelimited(dev_dbg, dev, fmt, ##__VA_ARGS__)
-
+#else
+#define dev_dbg_ratelimited(dev, fmt, ...)			\
+	no_printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__)
+#endif
 /*
  * Stupid hackaround for existing uses of non-printk uses dev_info
  *
-- 
1.7.5.4

Re: noisy dev_dbg_ratelimited()

[Antti Palosaari]

Hello Hiroshi

On 08/16/2012 10:12 AM, Hiroshi Doyu wrote:
> Hi Antti,
>
> Antti Palosaari <crope@iki.fi> wrote @ Thu, 16 Aug 2012 03:11:56 +0200:
>
>> Hello Hiroshi,
>>
>> I see you have added dev_dbg_ratelimited() recently, commit
>> 6ca045930338485a8cdef117e74372aa1678009d .
>>
>> However it seems to be noisy as expected similar behavior than normal
>> dev_dbg() without a ratelimit.
>>
>> I looked ratelimit.c and there is:
>> printk(KERN_WARNING "%s: %d callbacks suppressed\n", func, rs->missed);
>>
>> What it looks my eyes it will print those "callbacks suppressed" always
>> because KERN_WARNING.
>
> Right. Can the following fix the problem?

No. That silences dev_dbg_reatelimited() totally.
dev_dbg() works as expected printing all the debugs. But when I change 
it to dev_dbg_reatelimited() all printings are silenced.


>>From 905b1dedb6c64bc46a70f6d203ef98c23fccb107 Mon Sep 17 00:00:00 2001
> From: Hiroshi Doyu <hdoyu@nvidia.com>
> Date: Thu, 16 Aug 2012 10:02:11 +0300
> Subject: [PATCH 1/1] driver-core: Shut up dev_dbg_reatelimited() without
>   DEBUG
>
> dev_dbg_reatelimited() without DEBUG printed "217078 callbacks
> suppressed". This shouldn't print anything without DEBUG.
>
> Signed-off-by: Hiroshi Doyu <hdoyu@nvidia.com>
> Reported-by: Antti Palosaari <crope@iki.fi>
> ---
>   include/linux/device.h |    6 +++++-
>   1 files changed, 5 insertions(+), 1 deletions(-)
>
> diff --git a/include/linux/device.h b/include/linux/device.h
> index eb945e1..d4dc26e 100644
> --- a/include/linux/device.h
> +++ b/include/linux/device.h
> @@ -962,9 +962,13 @@ do {									\
>   	dev_level_ratelimited(dev_notice, dev, fmt, ##__VA_ARGS__)
>   #define dev_info_ratelimited(dev, fmt, ...)				\
>   	dev_level_ratelimited(dev_info, dev, fmt, ##__VA_ARGS__)
> +#if defined(DEBUG)
>   #define dev_dbg_ratelimited(dev, fmt, ...)				\
>   	dev_level_ratelimited(dev_dbg, dev, fmt, ##__VA_ARGS__)
> -
> +#else
> +#define dev_dbg_ratelimited(dev, fmt, ...)			\
> +	no_printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__)
> +#endif
>   /*
>    * Stupid hackaround for existing uses of non-printk uses dev_info
>    *
>

regards
Antti

-- 
http://palosaari.fi/

Re: noisy dev_dbg_ratelimited()

[Hin-Tak Leung]

--- On Thu, 16/8/12, Antti Palosaari <crope@iki.fi> wrote:

> Hello Hiroshi
> 
> On 08/16/2012 10:12 AM, Hiroshi Doyu wrote:
> > Hi Antti,
> >
> > Antti Palosaari <crope@iki.fi>
> wrote @ Thu, 16 Aug 2012 03:11:56 +0200:
> >
> >> Hello Hiroshi,
> >>
> >> I see you have added dev_dbg_ratelimited()
> recently, commit
> >> 6ca045930338485a8cdef117e74372aa1678009d .
> >>
> >> However it seems to be noisy as expected similar
> behavior than normal
> >> dev_dbg() without a ratelimit.
> >>
> >> I looked ratelimit.c and there is:
> >> printk(KERN_WARNING "%s: %d callbacks
> suppressed\n", func, rs->missed);
> >>
> >> What it looks my eyes it will print those
> "callbacks suppressed" always
> >> because KERN_WARNING.
> >
> > Right. Can the following fix the problem?
> 
> No. That silences dev_dbg_reatelimited() totally.
> dev_dbg() works as expected printing all the debugs. But
> when I change 
> it to dev_dbg_reatelimited() all printings are silenced.

That's probably correct - the patch looks a bit strange... I did not try the patch, but had a quick look at the file and noted that in include/linux/device.h, "info" (and possibly another level) are treated specially... just thought I should mention this.

> >>From 905b1dedb6c64bc46a70f6d203ef98c23fccb107 Mon
> Sep 17 00:00:00 2001
> > From: Hiroshi Doyu <hdoyu@nvidia.com>
> > Date: Thu, 16 Aug 2012 10:02:11 +0300
> > Subject: [PATCH 1/1] driver-core: Shut up
> dev_dbg_reatelimited() without
> >   DEBUG
> >
> > dev_dbg_reatelimited() without DEBUG printed "217078
> callbacks
> > suppressed". This shouldn't print anything without
> DEBUG.
> >
> > Signed-off-by: Hiroshi Doyu <hdoyu@nvidia.com>
> > Reported-by: Antti Palosaari <crope@iki.fi>
> > ---
> >   include/linux/device.h |   
> 6 +++++-
> >   1 files changed, 5 insertions(+), 1
> deletions(-)
> >
> > diff --git a/include/linux/device.h
> b/include/linux/device.h
> > index eb945e1..d4dc26e 100644
> > --- a/include/linux/device.h
> > +++ b/include/linux/device.h
> > @@ -962,9 +962,13 @@ do {   
>            
>            
>         \
> >      
> dev_level_ratelimited(dev_notice, dev, fmt, ##__VA_ARGS__)
> >   #define dev_info_ratelimited(dev, fmt,
> ...)           
>     \
> >      
> dev_level_ratelimited(dev_info, dev, fmt, ##__VA_ARGS__)
> > +#if defined(DEBUG)
> >   #define dev_dbg_ratelimited(dev, fmt,
> ...)           
>     \
> >      
> dev_level_ratelimited(dev_dbg, dev, fmt, ##__VA_ARGS__)
> > -
> > +#else
> > +#define dev_dbg_ratelimited(dev, fmt,
> ...)           
> \
> > +    no_printk(KERN_DEBUG pr_fmt(fmt),
> ##__VA_ARGS__)
> > +#endif
> >   /*
> >    * Stupid hackaround for existing uses of
> non-printk uses dev_info
> >    *
> >
> 
> regards
> Antti
> 
> -- 
> http://palosaari.fi/
> 

Re: noisy dev_dbg_ratelimited()

[Hiroshi Doyu]

On Thu, 16 Aug 2012 22:29:43 +0200
Hin-Tak Leung <htl10@users.sourceforge.net> wrote:

> --- On Thu, 16/8/12, Antti Palosaari <crope@iki.fi> wrote:
> 
> > Hello Hiroshi
> > 
> > On 08/16/2012 10:12 AM, Hiroshi Doyu wrote:
> > > Hi Antti,
> > >
> > > Antti Palosaari <crope@iki.fi>
> > wrote @ Thu, 16 Aug 2012 03:11:56 +0200:
> > >
> > >> Hello Hiroshi,
> > >>
> > >> I see you have added dev_dbg_ratelimited()
> > recently, commit
> > >> 6ca045930338485a8cdef117e74372aa1678009d .
> > >>
> > >> However it seems to be noisy as expected similar
> > behavior than normal
> > >> dev_dbg() without a ratelimit.
> > >>
> > >> I looked ratelimit.c and there is:
> > >> printk(KERN_WARNING "%s: %d callbacks
> > suppressed\n", func, rs->missed);
> > >>
> > >> What it looks my eyes it will print those
> > "callbacks suppressed" always
> > >> because KERN_WARNING.
> > >
> > > Right. Can the following fix the problem?
> > 
> > No. That silences dev_dbg_reatelimited() totally.
> > dev_dbg() works as expected printing all the debugs. But
> > when I change 
> > it to dev_dbg_reatelimited() all printings are silenced.

I tested again locally. With DEBUG, it prints sometimes with inserting
"...28916 callbacks suppressed", without DEBUG, it doesn't print
anything. This looks the expected behavior. 

> That's probably correct - the patch looks a bit strange... I did not
> try the patch, but had a quick look at the file and noted that in
> include/linux/device.h, "info" (and possibly another level) are
> treated specially... just thought I should mention this.

I may not get your point correctly, but I think that the debug case is
different from the others(info, warn, err...etc) because, the others
always prints anything, but not debug depends on DEBUG. With DEBUG
it's expected to print at least something, and without DEBUG it's
expected to print nothing at all.

Re: small regression in mediatree/for_v3.7-3 - media_build

[VDR User]

On Tue, Aug 14, 2012 at 4:51 PM, Antti Palosaari <crope@iki.fi> wrote:
>> There seems to be a small regression on mediatree/for_v3.7-3
>> - dmesg/klog get flooded with these:
>>
>> [201145.140260] dvb_frontend_poll: 15 callbacks suppressed
>> [201145.586405] usb_urb_complete: 88 callbacks suppressed
>> [201150.587308] usb_urb_complete: 3456 callbacks suppressed
>>
>> [201468.630197] usb_urb_complete: 3315 callbacks suppressed
>> [201473.632978] usb_urb_complete: 3529 callbacks suppressed
>> [201478.635400] usb_urb_complete: 3574 callbacks suppressed
>>
>> It seems to be every 5 seconds, but I think that's just klog skipping
>> repeats and collapsing duplicate entries. This does not happen the last time
>> I tried playing with the TV stick :-).
>
> That's because you has dynamic debugs enabled!
> modprobe dvb_core; echo -n 'module dvb_core +p' >
> /sys/kernel/debug/dynamic_debug/control
> modprobe dvb_usbv2; echo -n 'module dvb_usbv2 +p' >
> /sys/kernel/debug/dynamic_debug/control
>
> If you don't add dvb_core and dvb_usbv2 modules to
> /sys/kernel/debug/dynamic_debug/control you will not see those.

I'm getting massive amounts of "dvb_frontend_poll: 20 callbacks
suppressed" messages in dmesg also and I definitely did not put
dvb_core or anything else in /sys/kernel/debug/dynamic_debug/control.
For that matter I don't even have a
/sys/kernel/debug/dynamic_debug/control file.

> I have added ratelimited version for those few debugs that are flooded
> normally. This suppressed is coming from ratelimit - it does not print all
> those similar debugs.

I'm using kernel 3.6.3 with media_build from Oct. 21, 2012. How I can
disable those messages? I'd rather not see hundreds, possibly
thousands or millions of those messages. :)

Re: small regression in mediatree/for_v3.7-3 - media_build

[Hin-Tak Leung]

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

--- On Sat, 3/11/12, VDR User <user.vdr@gmail.com> wrote:

> On Tue, Aug 14, 2012 at 4:51 PM,
> Antti Palosaari <crope@iki.fi>
> wrote:
> >> There seems to be a small regression on
> mediatree/for_v3.7-3
> >> - dmesg/klog get flooded with these:
> >>
> >> [201145.140260] dvb_frontend_poll: 15 callbacks
> suppressed
> >> [201145.586405] usb_urb_complete: 88 callbacks
> suppressed
> >> [201150.587308] usb_urb_complete: 3456 callbacks
> suppressed
> >>
> >> [201468.630197] usb_urb_complete: 3315 callbacks
> suppressed
> >> [201473.632978] usb_urb_complete: 3529 callbacks
> suppressed
> >> [201478.635400] usb_urb_complete: 3574 callbacks
> suppressed
> >>
> >> It seems to be every 5 seconds, but I think that's
> just klog skipping
> >> repeats and collapsing duplicate entries. This does
> not happen the last time
> >> I tried playing with the TV stick :-).
> >
> > That's because you has dynamic debugs enabled!
> > modprobe dvb_core; echo -n 'module dvb_core +p' >
> > /sys/kernel/debug/dynamic_debug/control
> > modprobe dvb_usbv2; echo -n 'module dvb_usbv2 +p' >
> > /sys/kernel/debug/dynamic_debug/control
> >
> > If you don't add dvb_core and dvb_usbv2 modules to
> > /sys/kernel/debug/dynamic_debug/control you will not
> see those.
> 
> I'm getting massive amounts of "dvb_frontend_poll: 20
> callbacks
> suppressed" messages in dmesg also and I definitely did not
> put
> dvb_core or anything else in
> /sys/kernel/debug/dynamic_debug/control.
> For that matter I don't even have a
> /sys/kernel/debug/dynamic_debug/control file.
> 
> > I have added ratelimited version for those few debugs
> that are flooded
> > normally. This suppressed is coming from ratelimit - it
> does not print all
> > those similar debugs.
> 
> I'm using kernel 3.6.3 with media_build from Oct. 21, 2012.
> How I can
> disable those messages? I'd rather not see hundreds,
> possibly
> thousands or millions of those messages. :)

okay, if you had followed the threads further down, you would probably see that I patched the host side copy of device.h, i.e:

/lib/modules/`uname -r `/build/include/linux/device.h

to get around this, since media_build does not use a full dev kernel tree, but uses the host-side copy of the kernel headers.

So you need to apply the patch (attached) to that. i.e.
  cd /lib/modules/`uname -r `/build/include/linux/
  patch -p3 < /tmp/patch

Mind you this messes up your kernel-dev headers. In my case, because that file is part of the fedora distro kernel-devel package, and as soon as I get a new kernel the whole thing is thrown away, so I don't care. But if you compile your own kernel (and hence have your own kernel-devel headers which you want to keep in clean state), you might want to take note about this.

Hope this helps.

[-- Attachment #2: patch --]
[-- Type: application/octet-stream, Size: 3161 bytes --]

commit d572f2958352dbe7b6552511c9e80d15929bfea6
Author: Hiroshi Doyu <hdoyu@nvidia.com>
Date:   Tue Aug 21 06:02:04 2012 +0000

    driver-core: Shut up dev_dbg_reatelimited() without DEBUG
    
    dev_dbg_reatelimited() without DEBUG printed "217078 callbacks
    suppressed". This shouldn't print anything without DEBUG.
    
    With CONFIG_DYNAMIC_DEBUG, the print should be configured as expected.
    
    Signed-off-by: Hiroshi Doyu <hdoyu@nvidia.com>
    Reported-by: Antti Palosaari <crope@iki.fi>
    Signed-off-by: Antti Palosaari <crope@iki.fi>

diff --git a/include/linux/device.h b/include/linux/device.h
index 52a5f15..4d91265 100644
--- a/include/linux/device.h
+++ b/include/linux/device.h
@@ -946,6 +946,32 @@ int _dev_info(const struct device *dev, const char *fmt, ...)
 
 #endif
 
+/*
+ * Stupid hackaround for existing uses of non-printk uses dev_info
+ *
+ * Note that the definition of dev_info below is actually _dev_info
+ * and a macro is used to avoid redefining dev_info
+ */
+
+#define dev_info(dev, fmt, arg...) _dev_info(dev, fmt, ##arg)
+
+#if defined(CONFIG_DYNAMIC_DEBUG)
+#define dev_dbg(dev, format, ...)		     \
+do {						     \
+	dynamic_dev_dbg(dev, format, ##__VA_ARGS__); \
+} while (0)
+#elif defined(DEBUG)
+#define dev_dbg(dev, format, arg...)		\
+	dev_printk(KERN_DEBUG, dev, format, ##arg)
+#else
+#define dev_dbg(dev, format, arg...)				\
+({								\
+	if (0)							\
+		dev_printk(KERN_DEBUG, dev, format, ##arg);	\
+	0;							\
+})
+#endif
+
 #define dev_level_ratelimited(dev_level, dev, fmt, ...)			\
 do {									\
 	static DEFINE_RATELIMIT_STATE(_rs,				\
@@ -969,33 +995,21 @@ do {									\
 	dev_level_ratelimited(dev_notice, dev, fmt, ##__VA_ARGS__)
 #define dev_info_ratelimited(dev, fmt, ...)				\
 	dev_level_ratelimited(dev_info, dev, fmt, ##__VA_ARGS__)
+#if defined(CONFIG_DYNAMIC_DEBUG) || defined(DEBUG)
 #define dev_dbg_ratelimited(dev, fmt, ...)				\
-	dev_level_ratelimited(dev_dbg, dev, fmt, ##__VA_ARGS__)
-
-/*
- * Stupid hackaround for existing uses of non-printk uses dev_info
- *
- * Note that the definition of dev_info below is actually _dev_info
- * and a macro is used to avoid redefining dev_info
- */
-
-#define dev_info(dev, fmt, arg...) _dev_info(dev, fmt, ##arg)
-
-#if defined(CONFIG_DYNAMIC_DEBUG)
-#define dev_dbg(dev, format, ...)		     \
-do {						     \
-	dynamic_dev_dbg(dev, format, ##__VA_ARGS__); \
+do {									\
+	static DEFINE_RATELIMIT_STATE(_rs,				\
+				      DEFAULT_RATELIMIT_INTERVAL,	\
+				      DEFAULT_RATELIMIT_BURST);		\
+	DEFINE_DYNAMIC_DEBUG_METADATA(descriptor, fmt);			\
+	if (unlikely(descriptor.flags & _DPRINTK_FLAGS_PRINT) &&	\
+	    __ratelimit(&_rs))						\
+		__dynamic_pr_debug(&descriptor, pr_fmt(fmt),		\
+				   ##__VA_ARGS__);			\
 } while (0)
-#elif defined(DEBUG)
-#define dev_dbg(dev, format, arg...)		\
-	dev_printk(KERN_DEBUG, dev, format, ##arg)
 #else
-#define dev_dbg(dev, format, arg...)				\
-({								\
-	if (0)							\
-		dev_printk(KERN_DEBUG, dev, format, ##arg);	\
-	0;							\
-})
+#define dev_dbg_ratelimited(dev, fmt, ...)			\
+	no_printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__)
 #endif
 
 #ifdef VERBOSE_DEBUG