Thread (9 messages) 9 messages, 3 authors, 2012-08-23

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

From: Hin-Tak Leung <hidden>
Date: 2012-08-23 13:00:37
Also in: linux-media, lkml 

--- On Wed, 22/8/12, Antti Palosaari <crope-X3B1VOXEql0@public.gmane.org> wrote:

On 08/22/2012 04:57 PM, Hin-Tak Leung
wrote:
quoted
Antti Palosaari wrote:
quoted
Hello Hiroshi,

On 08/21/2012 10:02 AM, Hiroshi Doyu wrote:
quoted
Antti Palosaari [off-list ref]
wrote @ Mon, 20 Aug 2012 23:29:34 +0200:
quoted
quoted
quoted
quoted
On 08/20/2012 02:14 PM, Hiroshi Doyu
wrote:
quoted
quoted
quoted
quoted
quoted
Hi Antti,

Antti Palosaari [off-list ref]
wrote @ Sat, 18 Aug 2012 02:11:56
quoted
quoted
quoted
quoted
quoted
+0200:

quoted
On 08/17/2012 09:04 AM, Hiroshi
Doyu wrote:
quoted
quoted
quoted
quoted
quoted
quoted
quoted
dev_dbg_reatelimited() without
DEBUG printed "217078 callbacks
quoted
quoted
quoted
quoted
quoted
quoted
quoted
suppressed". This shouldn't
print anything without DEBUG.
quoted
quoted
quoted
quoted
quoted
quoted
quoted
Signed-off-by: Hiroshi Doyu
[off-list ref]
quoted
quoted
quoted
quoted
quoted
quoted
quoted
Reported-by: Antti Palosaari
[off-list ref]
quoted
quoted
quoted
quoted
quoted
quoted
quoted
---
   include/linux/device.h |    6
+++++-
quoted
quoted
quoted
quoted
quoted
quoted
quoted
    1 files
changed, 5 insertions(+), 1 deletions(-)
quoted
quoted
quoted
quoted
quoted
quoted
quoted
diff --git
a/include/linux/device.h b/include/linux/device.h
quoted
quoted
quoted
quoted
quoted
quoted
quoted
index eb945e1..d4dc26e 100644
--- a/include/linux/device.h
+++ b/include/linux/device.h
@@ -962,9 +962,13 @@ do { 
               
               
  \
quoted
quoted
quoted
quoted
quoted
quoted
quoted
    
   dev_level_ratelimited(dev_notice, dev,
fmt, ##__VA_ARGS__)
quoted
quoted
quoted
quoted
quoted
quoted
quoted
    #define
dev_info_ratelimited(dev, fmt, ...)     
          \
quoted
quoted
quoted
quoted
quoted
quoted
quoted
    
   dev_level_ratelimited(dev_info, dev, fmt,
##__VA_ARGS__)
quoted
quoted
quoted
quoted
quoted
quoted
quoted
+#if defined(DEBUG)
    #define
dev_dbg_ratelimited(dev, fmt, ...)     
          \
quoted
quoted
quoted
quoted
quoted
quoted
quoted
    
   dev_level_ratelimited(dev_dbg, dev, fmt,
##__VA_ARGS__)
quoted
quoted
quoted
quoted
quoted
quoted
quoted
-
+#else
+#define
dev_dbg_ratelimited(dev, fmt, ...)     
      \
quoted
quoted
quoted
quoted
quoted
quoted
quoted
+   
no_printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__)
quoted
quoted
quoted
quoted
quoted
quoted
quoted
+#endif
    /*
     * Stupid
hackaround for existing uses of non-printk uses
quoted
quoted
quoted
quoted
quoted
quoted
quoted
dev_info
     *
NACK. I don't think that's correct
behavior. After that patch it
quoted
quoted
quoted
quoted
quoted
quoted
kills
all output of
dev_dbg_ratelimited(). If I use dynamic debugs and
quoted
quoted
quoted
quoted
quoted
quoted
order
debugs, I expect to see debugs as
earlier.
quoted
quoted
quoted
quoted
quoted
You are right. I attached the update
patch, just moving *_ratelimited
quoted
quoted
quoted
quoted
quoted
functions after dev_dbg() definitions.

With DEBUG defined/undefined in your
"test.ko", it works fine. With
quoted
quoted
quoted
quoted
quoted
CONFIG_DYNAMIC_DEBUG, it works with
"+p", but with "-p", still
quoted
quoted
quoted
quoted
quoted
"..callbacks suppressed" is printed.
I am using dynamic debugs and behavior is
now just same as it was when
quoted
quoted
quoted
quoted
reported that bug. OK, likely for static
debug it is now correct.
quoted
quoted
quoted
The following patch can also refrain
"..callbacks suppressed" with
quoted
quoted
quoted
"-p". I think that it's ok for all cases.

quoted
From
b4c6aa9160f03b61ed17975c73db36c983a48927 Mon Sep 17 00:00:00
2001
quoted
quoted
quoted
From: Hiroshi Doyu <redacted>
Date: Mon, 20 Aug 2012 13:49:19 +0300
Subject: [v3 1/1] driver-core: Shut up
dev_dbg_reatelimited() without
quoted
quoted
quoted
DEBUG

dev_dbg_reatelimited() without DEBUG printed
"217078 callbacks
quoted
quoted
quoted
suppressed". This shouldn't print anything
without DEBUG.
quoted
quoted
quoted
With CONFIG_DYNAMIC_DEBUG, the print should be
configured as expected.
quoted
quoted
quoted
Signed-off-by: Hiroshi Doyu <redacted>
Reported-by: Antti Palosaari <redacted>
---
  include/linux/device.h
|   62
quoted
quoted
quoted
+++++++++++++++++++++++++++++------------------
quoted
quoted
quoted
  1 files changed, 38
insertions(+), 24 deletions(-)
quoted
quoted
quoted
diff --git a/include/linux/device.h
b/include/linux/device.h
quoted
quoted
quoted
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
quoted
quoted
quoted
char *fmt,
...)

  #endif

+/*
+ * Stupid hackaround for existing uses of
non-printk uses dev_info
quoted
quoted
quoted
+ *
+ * Note that the definition of dev_info below
is actually _dev_info
quoted
quoted
quoted
+ * and a macro is used to avoid redefining
dev_info
quoted
quoted
quoted
+ */
+
+#define dev_info(dev, fmt, arg...)
_dev_info(dev, fmt, ##arg)
quoted
quoted
quoted
+
+#if defined(CONFIG_DYNAMIC_DEBUG)
+#define dev_dbg(dev, format, ...)   
         \
quoted
quoted
quoted
+do {           
             
   \
quoted
quoted
quoted
+    dynamic_dev_dbg(dev, format,
##__VA_ARGS__); \
quoted
quoted
quoted
+} while (0)
+#elif defined(DEBUG)
+#define dev_dbg(dev, format, arg...) 
      \
quoted
quoted
quoted
+    dev_printk(KERN_DEBUG, dev,
format, ##arg)
quoted
quoted
quoted
+#else
+#define dev_dbg(dev, format, arg...) 
              \
quoted
quoted
quoted
+({           
               
    \
quoted
quoted
quoted
+    if (0)     
               
      \
quoted
quoted
quoted
+       
dev_printk(KERN_DEBUG, dev, format, ##arg);    \
quoted
quoted
quoted
+    0;       
               
    \
quoted
quoted
quoted
+})
+#endif
+
  #define
dev_level_ratelimited(dev_level, dev, fmt, ...)   
        \
quoted
quoted
quoted
  do {     
               
              \
quoted
quoted
quoted
      static
DEFINE_RATELIMIT_STATE(_rs,       
        \
quoted
quoted
quoted
@@ -955,33 +981,21 @@ do {     
               
              \
quoted
quoted
quoted
  
   dev_level_ratelimited(dev_notice, dev,
fmt, ##__VA_ARGS__)
quoted
quoted
quoted
  #define
dev_info_ratelimited(dev, fmt, ...)     
          \
quoted
quoted
quoted
  
   dev_level_ratelimited(dev_info, dev, fmt,
##__VA_ARGS__)
quoted
quoted
quoted
+#if defined(CONFIG_DYNAMIC_DEBUG) ||
defined(DEBUG)
quoted
quoted
quoted
  #define
dev_dbg_ratelimited(dev, fmt, ...)     
          \
quoted
quoted
quoted
-    dev_level_ratelimited(dev_dbg,
dev, fmt, ##__VA_ARGS__)
quoted
quoted
quoted
-
-/*
- * Stupid hackaround for existing uses of
non-printk uses dev_info
quoted
quoted
quoted
- *
- * Note that the definition of dev_info below
is actually _dev_info
quoted
quoted
quoted
- * and a macro is used to avoid redefining
dev_info
quoted
quoted
quoted
- */
-
-#define dev_info(dev, fmt, arg...)
_dev_info(dev, fmt, ##arg)
quoted
quoted
quoted
-
-#if defined(CONFIG_DYNAMIC_DEBUG)
-#define dev_dbg(dev, format, ...)   
         \
quoted
quoted
quoted
-do {           
             
   \
quoted
quoted
quoted
-    dynamic_dev_dbg(dev, format,
##__VA_ARGS__); \
quoted
quoted
quoted
+do {           
               
        \
quoted
quoted
quoted
+    static
DEFINE_RATELIMIT_STATE(_rs,       
        \
quoted
quoted
quoted
+           
         
DEFAULT_RATELIMIT_INTERVAL,    \
quoted
quoted
quoted
+           
         
DEFAULT_RATELIMIT_BURST);        \
quoted
quoted
quoted
+   
DEFINE_DYNAMIC_DEBUG_METADATA(descriptor, fmt);   
        \
quoted
quoted
quoted
+    if (unlikely(descriptor.flags
& _DPRINTK_FLAGS_PRINT) &&    \
quoted
quoted
quoted
+       
__ratelimit(&_rs))         
              \
quoted
quoted
quoted
+       
__dynamic_pr_debug(&descriptor, pr_fmt(fmt), 
      \
quoted
quoted
quoted
+           
       ##__VA_ARGS__);   
        \
quoted
quoted
quoted
  } while (0)
-#elif defined(DEBUG)
-#define dev_dbg(dev, format, arg...) 
      \
quoted
quoted
quoted
-    dev_printk(KERN_DEBUG, dev,
format, ##arg)
quoted
quoted
quoted
  #else
-#define dev_dbg(dev, format, arg...) 
              \
quoted
quoted
quoted
-({           
               
    \
quoted
quoted
quoted
-    if (0)     
               
      \
quoted
quoted
quoted
-       
dev_printk(KERN_DEBUG, dev, format, ##arg);    \
quoted
quoted
quoted
-    0;       
               
    \
quoted
quoted
quoted
-})
+#define dev_dbg_ratelimited(dev, fmt,
...)            \
quoted
quoted
quoted
+    no_printk(KERN_DEBUG
pr_fmt(fmt), ##__VA_ARGS__)
quoted
quoted
quoted
  #endif

  #ifdef VERBOSE_DEBUG
That seems to work correctly now. I tested it using
dynamic debugs. It
quoted
quoted
was
Hin-Tak who originally reported that bug for me
after I added few
quoted
quoted
ratelimited
debugs for DVB stack. Thank you!

Reported-by: Hin-Tak Leung <redacted>
Tested-by: Antti Palosaari <redacted>


regards
Antti
This is with mediatree/for_v3.7-8 , playing DVB-T video
with mplayer.
quoted
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
quoted
length=4096/4096 pack_num=0 errors=0
[137749.699449] usb 1-3: usb_urb_complete: bulk urb
completed status=0
quoted
length=4096/4096 pack_num=0 errors=0
[137749.700825] usb 1-3: usb_urb_complete: bulk urb
completed status=0
quoted
length=4096/4096 pack_num=0 errors=0
[137754.690862] usb_urb_complete: 3570 callbacks
suppressed
quoted
[137754.690888] usb 1-3: usb_urb_complete: bulk urb
completed status=0
quoted
length=4096/4096 pack_num=0 errors=0
[137754.692489] usb 1-3: usb_urb_complete: bulk urb
completed status=0
quoted
length=4096/4096 pack_num=0 errors=0
[137754.693745] usb 1-3: usb_urb_complete: bulk urb
completed status=0
quoted
length=4096/4096 pack_num=0 errors=0
[137754.694882] usb 1-3: usb_urb_complete: bulk urb
completed status=0
quoted
length=4096/4096 pack_num=0 errors=0
[137754.696240] usb 1-3: usb_urb_complete: bulk urb
completed status=0
quoted
length=4096/4096 pack_num=0 errors=0
[137754.697483] usb 1-3: usb_urb_complete: bulk urb
completed status=0
quoted
length=4096/4096 pack_num=0 errors=0
[137754.699002] usb 1-3: usb_urb_complete: bulk urb
completed status=0
quoted
length=4096/4096 pack_num=0 errors=0
[137754.700884] usb 1-3: usb_urb_complete: bulk urb
completed status=0
quoted
length=4096/4096 pack_num=0 errors=0
[137754.701613] usb 1-3: usb_urb_complete: bulk urb
completed status=0
quoted
length=4096/4096 pack_num=0 errors=0
[137754.702986] usb 1-3: usb_urb_complete: bulk urb
completed status=0
quoted
length=4096/4096 pack_num=0 errors=0
[137759.695906] usb_urb_complete: 3595 callbacks
suppressed
quoted
[137759.695934] usb 1-3: usb_urb_complete: bulk urb
completed status=0
quoted
length=4096/4096 pack_num=0 errors=0
[137759.697788] usb 1-3: usb_urb_complete: bulk urb
completed status=0
quoted
length=4096/4096 pack_num=0 errors=0
[137759.698772] usb 1-3: usb_urb_complete: bulk urb
completed status=0
quoted
length=4096/4096 pack_num=0 errors=0

with -p

[137814.730303] usb_urb_complete: 3555 callbacks
suppressed
quoted
[137819.740698] usb_urb_complete: 3519 callbacks
suppressed
quoted
[137824.744857] usb_urb_complete: 3443 callbacks
suppressed
quoted
[137829.746023] usb_urb_complete: 3345 callbacks
suppressed
quoted
[137834.749931] usb_urb_complete: 3558 callbacks
suppressed
quoted
[137839.753102] usb_urb_complete: 3465 callbacks
suppressed
quoted
[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 <redacted>
Reported-by: Hin-Tak Leung <redacted>

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).
  



    
  

  
    

      

        Keyboard shortcuts
      

      

        
          
hback out one level

          
jnext message in thread

          
kprevious message in thread

          
ldrill in

          
Escclose help / fold thread tree

          
?toggle this help