Re: [PATCH 1/1] driver-core: Shut up dev_dbg_reatelimited() without DEBUG

From: Hin-Tak Leung
Date: Thu Aug 23 2012 - 09:01:19 EST

Next message: Shilimkar, Santosh: "Re: [PATCH 2/6] ARM: omap: allow building omap44xx without SMP"
Previous message: Eric Dumazet: "RE: [PATCH 1/1] tcp: Wrong timeout for SYN segments"
In reply to: Antti Palosaari: "Re: [PATCH 1/1] driver-core: Shut up dev_dbg_reatelimited() withoutDEBUG"
Next in thread: Hiroshi Doyu: "[PATCH 1/1] driver-core: Shut up dev_dbg_reatelimited() withoutDEBUG"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

--- On Wed, 22/8/12, Antti Palosaari <crope@xxxxxx> wrote:

> On 08/22/2012 04:57 PM, Hin-Tak Leung
> wrote:
> > Antti Palosaari wrote:
> >> Hello Hiroshi,
> >>
> >> On 08/21/2012 10:02 AM, Hiroshi Doyu wrote:
> >>> Antti Palosaari <crope@xxxxxx>
> wrote @ Mon, 20 Aug 2012 23:29:34 +0200:
> >>>
> >>>> On 08/20/2012 02:14 PM, Hiroshi Doyu
> wrote:
> >>>>> Hi Antti,
> >>>>>
> >>>>> Antti Palosaari <crope@xxxxxx>
> wrote @ Sat, 18 Aug 2012 02:11:56
> >>>>> +0200:
> >>>>>
> >>>>>> On 08/17/2012 09:04 AM, Hiroshi
> Doyu wrote:
> >>>>>>> dev_dbg_reatelimited() without
> DEBUG printed "217078 callbacks
> >>>>>>> suppressed". This shouldn't
> print anything without DEBUG.
> >>>>>>>
> >>>>>>> Signed-off-by: Hiroshi Doyu
> <hdoyu@xxxxxxxxxx>
> >>>>>>> Reported-by: Antti Palosaari
> <crope@xxxxxx>
> >>>>>>> ---
> >>>>>>>
>    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
> >>>>>>> *
> >>>>>>>
> >>>>>>
> >>>>>> NACK. I don't think that's correct
> behavior. After that patch it
> >>>>>> kills
> >>>>>> all output of
> dev_dbg_ratelimited(). If I use dynamic debugs and
> >>>>>> order
> >>>>>> debugs, I expect to see debugs as
> earlier.
> >>>>>
> >>>>> You are right. I attached the update
> patch, just moving *_ratelimited
> >>>>> functions after dev_dbg() definitions.
> >>>>>
> >>>>> With DEBUG defined/undefined in your
> "test.ko", it works fine. With
> >>>>> CONFIG_DYNAMIC_DEBUG, it works with
> "+p", but with "-p", still
> >>>>> "..callbacks suppressed" is printed.
> >>>>
> >>>> I am using dynamic debugs and behavior is
> now just same as it was when
> >>>> reported that bug. OK, likely for static
> debug it is now correct.
> >>>
> >>> The following patch can also refrain
> "..callbacks suppressed" with
> >>> "-p". I think that it's ok for all cases.
> >>>
> >>>> From
> b4c6aa9160f03b61ed17975c73db36c983a48927 Mon Sep 17 00:00:00
> 2001
> >>> From: Hiroshi Doyu <hdoyu@xxxxxxxxxx>
> >>> Date: Mon, 20 Aug 2012 13:49:19 +0300
> >>> Subject: [v3 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.
> >>>
> >>> With CONFIG_DYNAMIC_DEBUG, the print should be
> configured as expected.
> >>>
> >>> Signed-off-by: Hiroshi Doyu <hdoyu@xxxxxxxxxx>
> >>> Reported-by: Antti Palosaari <crope@xxxxxx>
> >>> ---
> >>>   include/linux/device.h
> |   62
> >>>
> +++++++++++++++++++++++++++++------------------
> >>>   1 files changed, 38
> insertions(+), 24 deletions(-)
> >>>
> >>> diff --git a/include/linux/device.h
> b/include/linux/device.h
> >>> index 9648331..bb6ffcb 100644
> >>> --- a/include/linux/device.h
> >>> +++ b/include/linux/device.h
> >>> @@ -932,6 +932,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,
> \
> >>> @@ -955,33 +981,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
> >>
> >> That seems to work correctly now. I tested it using
> dynamic debugs. It
> >> was
> >> Hin-Tak who originally reported that bug for me
> after I added few
> >> ratelimited
> >> debugs for DVB stack. Thank you!
> >>
> >> Reported-by: Hin-Tak Leung <htl10@xxxxxxxxxxxxxxxxxxxxx>
> >> Tested-by: Antti Palosaari <crope@xxxxxx>
> >>
> >>
> >> regards
> >> Antti
> >>
> >
> > This is with mediatree/for_v3.7-8 , playing DVB-T video
> with mplayer.
> >
> > echo 'file ...media_build/v4l/usb_urb.c +p' >
> > /sys/kernel/debug/dynamic_debug/control
> >
> > With +p
> >
> > [137749.698202] usb 1-3: usb_urb_complete: bulk urb
> completed status=0
> > length=4096/4096 pack_num=0 errors=0
> > [137749.699449] usb 1-3: usb_urb_complete: bulk urb
> completed status=0
> > length=4096/4096 pack_num=0 errors=0
> > [137749.700825] usb 1-3: usb_urb_complete: bulk urb
> completed status=0
> > length=4096/4096 pack_num=0 errors=0
> > [137754.690862] usb_urb_complete: 3570 callbacks
> suppressed
> > [137754.690888] usb 1-3: usb_urb_complete: bulk urb
> completed status=0
> > length=4096/4096 pack_num=0 errors=0
> > [137754.692489] usb 1-3: usb_urb_complete: bulk urb
> completed status=0
> > length=4096/4096 pack_num=0 errors=0
> > [137754.693745] usb 1-3: usb_urb_complete: bulk urb
> completed status=0
> > length=4096/4096 pack_num=0 errors=0
> > [137754.694882] usb 1-3: usb_urb_complete: bulk urb
> completed status=0
> > length=4096/4096 pack_num=0 errors=0
> > [137754.696240] usb 1-3: usb_urb_complete: bulk urb
> completed status=0
> > length=4096/4096 pack_num=0 errors=0
> > [137754.697483] usb 1-3: usb_urb_complete: bulk urb
> completed status=0
> > length=4096/4096 pack_num=0 errors=0
> > [137754.699002] usb 1-3: usb_urb_complete: bulk urb
> completed status=0
> > length=4096/4096 pack_num=0 errors=0
> > [137754.700884] usb 1-3: usb_urb_complete: bulk urb
> completed status=0
> > length=4096/4096 pack_num=0 errors=0
> > [137754.701613] usb 1-3: usb_urb_complete: bulk urb
> completed status=0
> > length=4096/4096 pack_num=0 errors=0
> > [137754.702986] usb 1-3: usb_urb_complete: bulk urb
> completed status=0
> > length=4096/4096 pack_num=0 errors=0
> > [137759.695906] usb_urb_complete: 3595 callbacks
> suppressed
> > [137759.695934] usb 1-3: usb_urb_complete: bulk urb
> completed status=0
> > length=4096/4096 pack_num=0 errors=0
> > [137759.697788] usb 1-3: usb_urb_complete: bulk urb
> completed status=0
> > length=4096/4096 pack_num=0 errors=0
> > [137759.698772] usb 1-3: usb_urb_complete: bulk urb
> completed status=0
> > length=4096/4096 pack_num=0 errors=0
> >
> > with -p
> >
> > [137814.730303] usb_urb_complete: 3555 callbacks
> suppressed
> > [137819.740698] usb_urb_complete: 3519 callbacks
> suppressed
> > [137824.744857] usb_urb_complete: 3443 callbacks
> suppressed
> > [137829.746023] usb_urb_complete: 3345 callbacks
> suppressed
> > [137834.749931] usb_urb_complete: 3558 callbacks
> suppressed
> > [137839.753102] usb_urb_complete: 3465 callbacks
> suppressed
> > [137844.755521] usb_urb_complete: 3438 callbacks
> suppressed
>
> I think you are using media_build.git (with my devel tree)?
> Could that
> be due to that as there is some compat stuff? I am not very
> familiar
> with media_build.git...

Acked-by: Hin-Tak Leung <htl10@xxxxxxxxxxxxxxxxxxxxx>
Reported-by: Hin-Tak Leung <htl10@xxxxxxxxxxxxxxxxxxxxx>

Yes, sorry about that. media_build is picking up the system's kernel header, I think - dev_dbg_ratelimited is defined in the older kernel 3.5.x's include/linux/device.h .

Yes, it was me who first noticed the problem (when DVB-usb started using the define).
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/

Next message: Shilimkar, Santosh: "Re: [PATCH 2/6] ARM: omap: allow building omap44xx without SMP"
Previous message: Eric Dumazet: "RE: [PATCH 1/1] tcp: Wrong timeout for SYN segments"
In reply to: Antti Palosaari: "Re: [PATCH 1/1] driver-core: Shut up dev_dbg_reatelimited() withoutDEBUG"
Next in thread: Hiroshi Doyu: "[PATCH 1/1] driver-core: Shut up dev_dbg_reatelimited() withoutDEBUG"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]