[v3.10.y][v3.11.y][3.12.y][v3.13.y][v3.14.y][SRU][PATCH 0/1][V2] ALSA: usb-audio: Prevent printk ratelimiting from spamming kernel log while DEBUG not defined

[v3.10.y][v3.11.y][3.12.y][v3.13.y][v3.14.y][SRU][PATCH 0/1][V2] ALSA: usb-audio: Prevent printk ratelimiting from spamming kernel log while DEBUG not defined

[Joseph Salisbury]

Hello,

Please consider including upstream commit b7a77235 in the next v3.13.y release.  It was included upstream as of v3.15-rc5.  It has been tested and confirmed to resolve http://bugs.launchpad.net/bugs/1319457 .

commit b7a7723513dc89f83d6df13206df55d4dc26e825
Author: Sander Eikelenboom <linux@eikelenboom.it>
Date:   Fri May 2 15:09:27 2014 +0200

    ALSA: usb-audio: Prevent printk ratelimiting from spamming kernel log while DEBUG not defined


This original commit does not apply cleanly to v3.13, so I performed a backport, which is in email 1/1.  The backport has been tested and cleanly applies to upstream 3.10.y, 3.11.y, 3.12.y and 3.14.y.  The backport is not applicable to longterm stable 3.2.y or 3.4.y.


Sander Eikelenboom (1):
  ALSA: usb-audio: Prevent printk ratelimiting from spamming kernel log
    while DEBUG not defined

 sound/usb/pcm.c | 3 ++-
 1 file changed, 2 insertions(+), 1 deletion(-)

-- 
2.0.0

[v3.10.y][v3.11.y][v3.12.y][v3.13.y][v3.14.y][PATCH 1/1][V2] ALSA: usb-audio: Prevent printk ratelimiting from spamming kernel log while DEBUG not defined

[Joseph Salisbury]

From: Sander Eikelenboom <linux@eikelenboom.it>

BugLink: http://bugs.launchpad.net/bugs/1319457

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@eikelenboom.it>
Signed-off-by: Takashi Iwai <tiwai@suse.de>
(backported from commit b7a7723513dc89f83d6df13206df55d4dc26e825)
Signed-off-by: Joseph Salisbury <joseph.salisbury@canonical.com>
---
 sound/usb/pcm.c | 3 ++-
 1 file changed, 2 insertions(+), 1 deletion(-)

diff --git a/sound/usb/pcm.c b/sound/usb/pcm.c
index ca3256d..ede4b92 100644
--- a/sound/usb/pcm.c
+++ b/sound/usb/pcm.c
@@ -1488,7 +1488,8 @@ static void retire_playback_urb(struct snd_usb_substream *subs,
 	 * on two reads of a counter updated every ms.
 	 */
 	if (abs(est_delay - subs->last_delay) * 1000 > runtime->rate * 2)
-		snd_printk(KERN_DEBUG "delay: estimated %d, actual %d\n",
+		dev_dbg_ratelimited(&subs->dev->dev,
+			"delay: estimated %d, actual %d\n",
 			est_delay, subs->last_delay);
 
 	if (!subs->running) {
-- 
2.0.0

Re: [v3.10.y][v3.11.y][v3.12.y][v3.13.y][v3.14.y][PATCH 1/1][V2] ALSA: usb-audio: Prevent printk ratelimiting from spamming kernel log while DEBUG not defined

[Ben Hutchings]

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

On Wed, 2014-06-18 at 14:32 -0400, Joseph Salisbury wrote:
> From: Sander Eikelenboom <linux@eikelenboom.it>
> 
> BugLink: http://bugs.launchpad.net/bugs/1319457
> 
> 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@eikelenboom.it>
> Signed-off-by: Takashi Iwai <tiwai@suse.de>
> (backported from commit b7a7723513dc89f83d6df13206df55d4dc26e825)
> Signed-off-by: Joseph Salisbury <joseph.salisbury@canonical.com>

It looks like you have combined the commit identified here with the
preceding:

commit a5065eb6da55b226661456e6a7435f605df98111
Author: Tim Gardner <tim.gardner@canonical.com>
Date:   Wed Apr 9 11:30:44 2014 -0600

    ALSA: usb-audio: Suppress repetitive debug messages from retire_playback_urb()

They should not be squashed together like this.

Ben.

> ---
>  sound/usb/pcm.c | 3 ++-
>  1 file changed, 2 insertions(+), 1 deletion(-)
> 
> diff --git a/sound/usb/pcm.c b/sound/usb/pcm.c
> index ca3256d..ede4b92 100644
> --- a/sound/usb/pcm.c
> +++ b/sound/usb/pcm.c
> @@ -1488,7 +1488,8 @@ static void retire_playback_urb(struct snd_usb_substream *subs,
>  	 * on two reads of a counter updated every ms.
>  	 */
>  	if (abs(est_delay - subs->last_delay) * 1000 > runtime->rate * 2)
> -		snd_printk(KERN_DEBUG "delay: estimated %d, actual %d\n",
> +		dev_dbg_ratelimited(&subs->dev->dev,
> +			"delay: estimated %d, actual %d\n",
>  			est_delay, subs->last_delay);
>  
>  	if (!subs->running) {

-- 
Ben Hutchings
It's easier to fight for one's principles than to live up to them.

[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 811 bytes --]

Re: Re: [v3.10.y][v3.11.y][v3.12.y][v3.13.y][v3.14.y][PATCH 1/1][V2] ALSA: usb-audio: Prevent printk ratelimiting from spamming kernel log while DEBUG not defined

[Joseph Salisbury]

On 06/18/2014 09:52 PM, Ben Hutchings wrote:
> On Wed, 2014-06-18 at 14:32 -0400, Joseph Salisbury wrote:
>> From: Sander Eikelenboom <linux@eikelenboom.it>
>>
>> BugLink: http://bugs.launchpad.net/bugs/1319457
>>
>> 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@eikelenboom.it>
>> Signed-off-by: Takashi Iwai <tiwai@suse.de>
>> (backported from commit b7a7723513dc89f83d6df13206df55d4dc26e825)
>> Signed-off-by: Joseph Salisbury <joseph.salisbury@canonical.com>
> It looks like you have combined the commit identified here with the
> preceding:
>
> commit a5065eb6da55b226661456e6a7435f605df98111
> Author: Tim Gardner <tim.gardner@canonical.com>
> Date:   Wed Apr 9 11:30:44 2014 -0600
>
>     ALSA: usb-audio: Suppress repetitive debug messages from retire_playback_urb()
>
> They should not be squashed together like this.
>
> Ben.
>
>> ---
>>  sound/usb/pcm.c | 3 ++-
>>  1 file changed, 2 insertions(+), 1 deletion(-)
>>
>> diff --git a/sound/usb/pcm.c b/sound/usb/pcm.c
>> index ca3256d..ede4b92 100644
>> --- a/sound/usb/pcm.c
>> +++ b/sound/usb/pcm.c
>> @@ -1488,7 +1488,8 @@ static void retire_playback_urb(struct snd_usb_substream *subs,
>>  	 * on two reads of a counter updated every ms.
>>  	 */
>>  	if (abs(est_delay - subs->last_delay) * 1000 > runtime->rate * 2)
>> -		snd_printk(KERN_DEBUG "delay: estimated %d, actual %d\n",
>> +		dev_dbg_ratelimited(&subs->dev->dev,
>> +			"delay: estimated %d, actual %d\n",
>>  			est_delay, subs->last_delay);
>>  
>>  	if (!subs->running) {
Hi Ben,

Thanks for the feedback.  Do you think it's best to cherry-pick these
two commits?  If so, I'll do that and test.  If it all works, I can send
a request to stable to cherry pick the commits and revert my backport.

Thanks,

Joe

Re: [v3.10.y][v3.11.y][v3.12.y][v3.13.y][v3.14.y][PATCH 1/1][V2] ALSA: usb-audio: Prevent printk ratelimiting from spamming kernel log while DEBUG not defined

[Joseph Salisbury]

On 06/20/2014 11:21 AM, Joseph Salisbury wrote:
> On 06/18/2014 09:52 PM, Ben Hutchings wrote:
>> On Wed, 2014-06-18 at 14:32 -0400, Joseph Salisbury wrote:
>>> From: Sander Eikelenboom <linux@eikelenboom.it>
>>>
>>> BugLink: http://bugs.launchpad.net/bugs/1319457
>>>
>>> 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@eikelenboom.it>
>>> Signed-off-by: Takashi Iwai <tiwai@suse.de>
>>> (backported from commit b7a7723513dc89f83d6df13206df55d4dc26e825)
>>> Signed-off-by: Joseph Salisbury <joseph.salisbury@canonical.com>
>> It looks like you have combined the commit identified here with the
>> preceding:
>>
>> commit a5065eb6da55b226661456e6a7435f605df98111
>> Author: Tim Gardner <tim.gardner@canonical.com>
>> Date:   Wed Apr 9 11:30:44 2014 -0600
>>
>>     ALSA: usb-audio: Suppress repetitive debug messages from retire_playback_urb()
>>
>> They should not be squashed together like this.
>>
>> Ben.
>>
>>> ---
>>>  sound/usb/pcm.c | 3 ++-
>>>  1 file changed, 2 insertions(+), 1 deletion(-)
>>>
>>> diff --git a/sound/usb/pcm.c b/sound/usb/pcm.c
>>> index ca3256d..ede4b92 100644
>>> --- a/sound/usb/pcm.c
>>> +++ b/sound/usb/pcm.c
>>> @@ -1488,7 +1488,8 @@ static void retire_playback_urb(struct snd_usb_substream *subs,
>>>  	 * on two reads of a counter updated every ms.
>>>  	 */
>>>  	if (abs(est_delay - subs->last_delay) * 1000 > runtime->rate * 2)
>>> -		snd_printk(KERN_DEBUG "delay: estimated %d, actual %d\n",
>>> +		dev_dbg_ratelimited(&subs->dev->dev,
>>> +			"delay: estimated %d, actual %d\n",
>>>  			est_delay, subs->last_delay);
>>>  
>>>  	if (!subs->running) {
> Hi Ben,
>
> Thanks for the feedback.  Do you think it's best to cherry-pick these
> two commits?  If so, I'll do that and test.  If it all works, I can send
> a request to stable to cherry pick the commits and revert my backport.
>
> Thanks,
>
> Joe
>

Hi Ben,

I looked at this some more.   It seems like my v2 backport may be the
most suitable for the releases mentioned in the subject line, but I'd
like to get additional feedback.

The lines added by commit a5065eb just get removed by commit b7a77235. 
Also, if I apply commit a5065eb, it will also require a backport to pull
in just a piece of code(Remove snd_printk() and add dev_dbg()) from
another prior commit(0ba41d9).  No backport would be needed at all if I
cherry-pick 0ba41d9, but that commit seems to have too may changes for a
stable release.

Thanks,

Joe

Re: [v3.10.y][v3.11.y][v3.12.y][v3.13.y][v3.14.y][PATCH 1/1][V2] ALSA: usb-audio: Prevent printk ratelimiting from spamming kernel log while DEBUG not defined

[Ben Hutchings]

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

On Fri, 2014-06-20 at 14:21 -0400, Joseph Salisbury wrote:
[...]
> I looked at this some more.   It seems like my v2 backport may be the
> most suitable for the releases mentioned in the subject line, but I'd
> like to get additional feedback.
> 
> The lines added by commit a5065eb just get removed by commit b7a77235. 
> Also, if I apply commit a5065eb, it will also require a backport to pull
> in just a piece of code(Remove snd_printk() and add dev_dbg()) from
> another prior commit(0ba41d9).  No backport would be needed at all if I
> cherry-pick 0ba41d9, but that commit seems to have too may changes for a
> stable release.

Keep the changes squashed together if you like, but do include both
commit hashes and commit messages.

Ben.

-- 
Ben Hutchings
Who are all these weirdos? - David Bowie, reading IRC for the first time

[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 811 bytes --]

Re: [v3.10.y][v3.11.y][v3.12.y][v3.13.y][v3.14.y][PATCH 1/1][V2] ALSA: usb-audio: Prevent printk ratelimiting from spamming kernel log while DEBUG not defined

[Greg KH]

On Sat, Jun 21, 2014 at 01:05:53PM +0100, Ben Hutchings wrote:
> On Fri, 2014-06-20 at 14:21 -0400, Joseph Salisbury wrote:
> [...]
> > I looked at this some more.   It seems like my v2 backport may be the
> > most suitable for the releases mentioned in the subject line, but I'd
> > like to get additional feedback.
> > 
> > The lines added by commit a5065eb just get removed by commit b7a77235. 
> > Also, if I apply commit a5065eb, it will also require a backport to pull
> > in just a piece of code(Remove snd_printk() and add dev_dbg()) from
> > another prior commit(0ba41d9).  No backport would be needed at all if I
> > cherry-pick 0ba41d9, but that commit seems to have too may changes for a
> > stable release.
> 
> Keep the changes squashed together if you like, but do include both
> commit hashes and commit messages.

No, I don't want to see "squashed together" patches, please keep them as
close to the original patch as possible.  It saves time in the long run,
trust me...

greg k-h

Re: [v3.10.y][v3.11.y][v3.12.y][v3.13.y][v3.14.y][PATCH 1/1][V2] ALSA: usb-audio: Prevent printk ratelimiting from spamming kernel log while DEBUG not defined

[Greg KH]

On Sat, Jun 21, 2014 at 12:48:27PM -0700, Greg KH wrote:
> On Sat, Jun 21, 2014 at 01:05:53PM +0100, Ben Hutchings wrote:
> > On Fri, 2014-06-20 at 14:21 -0400, Joseph Salisbury wrote:
> > [...]
> > > I looked at this some more.   It seems like my v2 backport may be the
> > > most suitable for the releases mentioned in the subject line, but I'd
> > > like to get additional feedback.
> > > 
> > > The lines added by commit a5065eb just get removed by commit b7a77235. 
> > > Also, if I apply commit a5065eb, it will also require a backport to pull
> > > in just a piece of code(Remove snd_printk() and add dev_dbg()) from
> > > another prior commit(0ba41d9).  No backport would be needed at all if I
> > > cherry-pick 0ba41d9, but that commit seems to have too may changes for a
> > > stable release.
> > 
> > Keep the changes squashed together if you like, but do include both
> > commit hashes and commit messages.
> 
> No, I don't want to see "squashed together" patches, please keep them as
> close to the original patch as possible.  It saves time in the long run,
> trust me...

And since no one did this work for me, I had to do it myself...

{grumble}