linux-kernel - Re: [PATCH] Sound USB: Prevent printk ratelimiting from spamming kernel log while DEBUG not defined

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [day] [month] [year] [list]

Date:	Fri, 2 May 2014 18:25:30 +0200
From:	Sander Eikelenboom <linux@...elenboom.it>
To:	Takashi Iwai <tiwai@...e.de>
CC:	Greg Kroah-Hartman <gregkh@...uxfoundation.org>,
	Julia Lawall <julia.lawall@...6.fr>,
	<linux-sound@...r.kernel.org>,
	linux-kernel <linux-kernel@...r.kernel.org>
Subject: Re: [PATCH] Sound USB: Prevent printk ratelimiting from spamming kernel log while DEBUG not defined


Friday, May 2, 2014, 6:13:09 PM, you wrote:

> At Fri,  2 May 2014 15:09:27 +0200,
> Sander Eikelenboom wrote:
>> 
>> This (widely used) construction:
>> 
>> if(printk_ratelimit())
>>       dev_dbg()
>> 
>> Causes the ratelimiting to spam the kernel log with the "callbacks suppressed"
>> message below, even while the dev_dbg it is supposed to rate limit wouldn't
>> print anything because DEBUG is not defined for this device.
>> 
>> [  533.803964] retire_playback_urb: 852 callbacks suppressed
>> [  538.807930] retire_playback_urb: 852 callbacks suppressed
>> [  543.811897] retire_playback_urb: 852 callbacks suppressed
>> [  548.815745] retire_playback_urb: 852 callbacks suppressed
>> [  553.819826] retire_playback_urb: 852 callbacks suppressed
>> 
>> So use dev_dbg_ratelimited() instead of this construction.
>> 
>> Signed-off-by: Sander Eikelenboom <linux@...elenboom.it>

> Thanks, applied.  This is a result of the recent rewrite to dev_dbg()
> from plain printk(), I suppose.

Yes that patch (https://lkml.org/lkml/2014/4/9/457) prevented spamming the kernel log when debugging was enabled ..
but  now the rate limiting code starts spamming the kernel log instead :-)

I must say i wasn't very aware of that effect either and also used this construction on 
debug patches.


> Takashi

>> ---
>>  sound/usb/pcm.c |    5 ++---
>>  1 file changed, 2 insertions(+), 3 deletions(-)
>> 
>> diff --git a/sound/usb/pcm.c b/sound/usb/pcm.c
>> index 131336d..c62a165 100644
>> --- a/sound/usb/pcm.c
>> +++ b/sound/usb/pcm.c
>> @@ -1501,9 +1501,8 @@ static void retire_playback_urb(struct snd_usb_substream *subs,
>>        * The error should be lower than 2ms since the estimate relies
>>        * on two reads of a counter updated every ms.
>>        */
>> -     if (printk_ratelimit() &&
>> -         abs(est_delay - subs->last_delay) * 1000 > runtime->rate * 2)
>> -             dev_dbg(&subs->dev->dev,
>> +     if (abs(est_delay - subs->last_delay) * 1000 > runtime->rate * 2)
>> +             dev_dbg_ratelimited(&subs->dev->dev,
>>                       "delay: estimated %d, actual %d\n",
>>                       est_delay, subs->last_delay);
>>  
>> -- 
>> 1.7.10.4
>> 


--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/