2014-06-18 18:32:26

by Joseph Salisbury

[permalink] [raw]
Subject: [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

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 <[email protected]>
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


2014-06-18 18:32:25

by Joseph Salisbury

[permalink] [raw]
Subject: [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

From: Sander Eikelenboom <[email protected]>

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 <[email protected]>
Signed-off-by: Takashi Iwai <[email protected]>
(backported from commit b7a7723513dc89f83d6df13206df55d4dc26e825)
Signed-off-by: Joseph Salisbury <[email protected]>
---
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

2014-06-19 01:52:53

by Ben Hutchings

[permalink] [raw]
Subject: 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

On Wed, 2014-06-18 at 14:32 -0400, Joseph Salisbury wrote:
> From: Sander Eikelenboom <[email protected]>
>
> 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 <[email protected]>
> Signed-off-by: Takashi Iwai <[email protected]>
> (backported from commit b7a7723513dc89f83d6df13206df55d4dc26e825)
> Signed-off-by: Joseph Salisbury <[email protected]>

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

commit a5065eb6da55b226661456e6a7435f605df98111
Author: Tim Gardner <[email protected]>
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.


Attachments:
signature.asc (811.00 B)
This is a digitally signed message part

2014-06-20 15:21:14

by Joseph Salisbury

[permalink] [raw]
Subject: 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

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 <[email protected]>
>>
>> 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 <[email protected]>
>> Signed-off-by: Takashi Iwai <[email protected]>
>> (backported from commit b7a7723513dc89f83d6df13206df55d4dc26e825)
>> Signed-off-by: Joseph Salisbury <[email protected]>
> It looks like you have combined the commit identified here with the
> preceding:
>
> commit a5065eb6da55b226661456e6a7435f605df98111
> Author: Tim Gardner <[email protected]>
> 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

2014-06-20 18:22:07

by Joseph Salisbury

[permalink] [raw]
Subject: 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

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 <[email protected]>
>>>
>>> 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 <[email protected]>
>>> Signed-off-by: Takashi Iwai <[email protected]>
>>> (backported from commit b7a7723513dc89f83d6df13206df55d4dc26e825)
>>> Signed-off-by: Joseph Salisbury <[email protected]>
>> It looks like you have combined the commit identified here with the
>> preceding:
>>
>> commit a5065eb6da55b226661456e6a7435f605df98111
>> Author: Tim Gardner <[email protected]>
>> 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

2014-06-21 12:06:07

by Ben Hutchings

[permalink] [raw]
Subject: 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

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


Attachments:
signature.asc (811.00 B)
This is a digitally signed message part

2014-06-21 19:48:41

by Greg KH

[permalink] [raw]
Subject: 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

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

2014-07-07 22:21:42

by Greg KH

[permalink] [raw]
Subject: 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

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}