usb headset causes "retire_playback_urb ... callbacks suppressed" spam in dmesg

[Steve Magoun]

With my USB headset plugged in to my computer. When the headset is plugged in, I get tens of messages like the following in dmesg and syslog:
May 14 11:25:24 aether kernel: [ 315.447988] retire_playback_urb: 829 callbacks suppressed
May 14 11:25:29 aether kernel: [ 320.458042] retire_playback_urb: 831 callbacks suppressed

The following patch was written to supress these rate-limited messages in syslog https://lkml.org/lkml/2014/5/2/156 .

ProblemType: Bug
DistroRelease: Ubuntu 14.04
Package: linux-image-3.13.0-26-generic 3.13.0-26.48
ProcVersionSignature: Ubuntu 3.13.0-26.48-generic 3.13.11
Uname: Linux 3.13.0-26-generic x86_64
ApportVersion: 2.14.1-0ubuntu3.1
Architecture: amd64
AudioDevicesInUse:
 USER PID ACCESS COMMAND
 /dev/snd/controlC2: steve 2643 F.... pulseaudio
 /dev/snd/controlC1: steve 2643 F.... pulseaudio
 /dev/snd/controlC0: steve 2643 F.... pulseaudio
CurrentDesktop: Unity
Date: Wed May 14 11:29:19 2014
DistributionChannelDescriptor:
 # This is a distribution channel descriptor
 # For more information see http://wiki.ubuntu.com/DistributionChannelDescriptor
 canonical-oem-somerville-precise-amd64-20130203-1
EcryptfsInUse: Yes
HibernationDevice: RESUME=UUID=79084358-087f-4cee-a0be-e2f78361873f
InstallationDate: Installed on 2013-12-02 (162 days ago)
InstallationMedia: Ubuntu 12.04 "Precise" - Build amd64 LIVE Binary 20130203-13:50
MachineType: Dell Inc. XPS13 9333
ProcFB: 0 inteldrmfb
ProcKernelCmdLine: BOOT_IMAGE=/boot/vmlinuz-3.13.0-26-generic root=UUID=0b9db31c-747b-40ad-bbbd-13a9a29caece ro quiet splash vt.handoff=7
RelatedPackageVersions:
 linux-restricted-modules-3.13.0-26-generic N/A
 linux-backports-modules-3.13.0-26-generic N/A
 linux-firmware 1.127.2
SourcePackage: linux
UpgradeStatus: Upgraded to trusty on 2014-02-12 (90 days ago)
dmi.bios.date: 11/11/2013
dmi.bios.vendor: Dell Inc.
dmi.bios.version: A01
dmi.board.name: 0GFTRT
dmi.board.vendor: Dell Inc.
dmi.board.version: A00
dmi.chassis.type: 8
dmi.chassis.vendor: Dell Inc.
dmi.chassis.version: 0.1
dmi.modalias: dmi:bvnDellInc.:bvrA01:bd11/11/2013:svnDellInc.:pnXPS139333:pvr:rvnDellInc.:rn0GFTRT:rvrA00:cvnDellInc.:ct8:cvr0.1:
dmi.product.name: XPS13 9333
dmi.sys.vendor: Dell Inc.

[Joseph Salisbury (jsalisbury)]

Commit is in mainline:
b7a7723 ALSA: usb-audio: Prevent printk ratelimiting from spamming kernel log while DEBUG not defined

However, it was not cc'd to stable.

I'll build a test kernel with a cherry-pick of this commit.

[Brad Figg (brad-figg)]

This change was made by a bot.

[Joseph Salisbury (jsalisbury)]

I had to backport commit b7a7723 for it to apply to Trusty. I built a test kernel, which can be downloaded from:

http://kernel.ubuntu.com/~jsalisbury/lp1319457/

Can you test this kernel and see if it resolves the bug?

[Joseph Salisbury (jsalisbury)]

Note, you will need to install both the linux-image and linux-image-extra .deb packages.

[luca (llucax)]

This seems to be applied to 3.13.0-27

[Steve Magoun (smagoun)]

@luca: I can still reproduce the "retire_playback_urb: xxx callbacks suppressed" messages in 3.13.0-27

[Joseph Salisbury (jsalisbury)]

@luca: Commit b7a7723 has not yet been applied to the Trusty stable kernel. It was not CC'd to stable when applied to mainline, so it will not make it's way into stable unless we specifically request it. If commit b7a7723 resolves this bug, we can submit an SRU request to have it included in Trusty.

Did the kernel posted in comment #4 fix the bug?

[Pietrek B. (ptrbrzozowski)]

Same thing with USB soundcard - Bus 006 Device 002: ID 041e:3040 Creative Technology, Ltd SoundBlaster Live! 24-bit External SB0490 and kernel: 3.13.0-27-generic #50-Ubuntu SMP Thu May 15 18:06:16 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux

[stargazer (stargazer05)]

@Joseph Salisbury (jsalisbury);

The kernel, posted in comment #4, fixes the bug! Tested with Logitech, Inc. H600 [Wireless Headset].

Please submit an SRU request to include the commit in Trusty stable.

Thanks, Bernhard

[penalvch (penalvch)]

Bernhard, this would not be considered Status In Progress as outlined in https://wiki.ubuntu.com/Bugs/Bug%20statuses .

[Tim Passingham (tim-8aw3u04umo)]

I am getting flooded with this as well. I had wondered why my PC was recently misbehaving in odd ways, including sometimes not responding to my USB mouse/keyboard at boot time. On looking at my log today it had masses of

retire_playback_urb:....

and also

usb 3-2.2: Not enough bandwidth for altsetting 0
usb 3-2.2: Not enough bandwidth for alltsetting 1
7:1:1: usb_set_interface failed (-19)

I not sure whether the two are related or not. The latter appeared whilst I was charging my mobile via my USB hub at boot time. I'm sure I've done this before with no difficulty.

[Steve Magoun (smagoun)]

@Joseph: The kernel in comment #4 fixes the bug for me too

[Tim Passingham (tim-8aw3u04umo)]

 I get the same problem with a Meridian explorer USB DAC on an Xubuntu 14.04 system.

I know little about the bug fixing process but I really hope this fix gets into the trusty stable kernel soon. I was hoping it might be in "3.13.0-29-generic #53-Ubuntu SMP Wed Jun 4 21:00:20 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux" installed today, but no such luck.

[mickoz (michael-kozielski)]

I also have the same Problem with Logitech H390 USB Headset.
syslog is spammed with:
retire_playback_urb: 832 callbacks suppressed
every ~5 seconds

[Pietrek B. (ptrbrzozowski)]

Nope. Scatch my last comment, kernel from comment #4 fixes it for me, but 3.13.0-29-generic doesn't.

[tatu (tatu)]

Kernel from #4 fixes this for me but only the urb callback issue. When I connect my usb headset, I will randomly get either the loudspeaker or microphone but not both.

pactl list shows either profile
                output:analog-stereo: Analog Stereo Output (sinks: 1, sources: 0, priority. 6000)
                off: Off (sinks: 0, sources: 0, priority. 0)
or
                input:analog-mono: Analog Mono Input (sinks: 0, sources: 1, priority. 1)
                off: Off (sinks: 0, sources: 0, priority. 0)

but not both, which would be correct (or as with kernel 3.5.7.1):

                input:analog-mono: Analog Mono Input (sinks: 0, sources: 1, priority. 1)
                output:analog-stereo: Analog Stereo Output (sinks: 1, sources: 0, priority. 6000)
                output:analog-stereo+input:analog-mono: Analog Stereo Output + Analog Mono Input (sinks: 1, sources: 1, priority. 6001)
                off: Off (sinks: 0, sources: 0, priority. 0)

[tatu (tatu)]

Correcting a bit my previous comment #18... seems not to be kernel related, on both 3.13.0-26 and 3.5.7.1 behaviour is random, sometimes you get loudspeaker, sometimes microphone and maybe once out of dozen tries you get both loudspeaker and microphone.

[penalvch (penalvch)]

tatu, thank you for your comment. So your hardware and problem may be tracked, could you please file a new report with Ubuntu by executing the following in a terminal while booted into the default Ubuntu kernel (not a mainline one) via:
ubuntu-bug linux

For more on this, please read the official Ubuntu documentation:
Ubuntu Bug Control and Ubuntu Bug Squad: https://wiki.ubuntu.com/Bugs/BestPractices#X.2BAC8-Reporting.Focus_on_One_Issue
Ubuntu Kernel Team: https://wiki.ubuntu.com/KernelTeam/KernelTeamBugPolicies#Filing_Kernel_Bug_reports
Ubuntu Community: https://help.ubuntu.com/community/ReportingBugs#Bug_reporting_etiquette

When opening up the new report, please feel free to subscribe me to it.

Thank you for your understanding.

Helpful bug reporting tips:
https://wiki.ubuntu.com/ReportingBugs

[Joe (jherbert)]

I can confirm I'm seeing this behavior using a usb soundcard since upgrading from Precise to Trusty, it was not evident in Precise

[The Setlaz (dam-brouard)]

Confirm as well. I have the same with USB plugged on external "soundcard" (Marantz device).

[Johan Ferner (johan-ferner)]

Confirmed with a Startech.com usb "soundcard".

[Johan Ferner (johan-ferner)]

I think it would be helpful if the backport in comment #4 was attached as a patch so we can fix this until it has reached Trusty proper. The patch at https://lkml.org/lkml/2014/5/2/156 does not apply cleanly for me.
Thanks!

[Joseph Salisbury (jsalisbury)]

I sent an SRU request to have my backport included in Trusty. I'll also attach the backported patch to the bug report.

[Johan Ferner (johan-ferner)]

Thank you! Applied the patch cleenly, rebuilt the kernel debs and the problem is gone.

[John Burke (johnburke)]

Joseph

I've had issues ith your patch; see the attachment for details. I'm using a SoundBlaster Extigy, but until I found this bug I thought the problem was related to bluetooth devices. I know that there's a problem when my keyboard autorepeats.

Let me know what other information might help.

Regards

John

[Tim Passingham (tim-8aw3u04umo)]

I am now on 3.13.0-30-generic #54-Ubuntu SMP Mon Jun 9 22:45:01 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux (ubuntu 14.04).

I still get volumes of these messages so have to disconnect my headphones every time. Being no expert I don't know if the patch is expected to have been included or not.

[pdknsk (pdknsk)]

It didn't make it, but it's in 3.13.0-31.55 available from trusty-proposed now.

https://launchpad.net/ubuntu/+source/linux/3.13.0-31.55

[Luis Henriques (henrix)]

This bug is awaiting verification that the kernel in -proposed solves the problem. Please test the kernel and update this bug with the results. If the problem is solved, change the tag 'verification-needed-trusty' to 'verification-done-trusty'.

If verification is not done by 5 working days from today, this fix will be dropped from the source code, and this bug will be closed.

See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Thank you!

[Tim Passingham (tim-8aw3u04umo)]

I'm no expert. If someone can give me exact instructions on how to update just the appropriate package on 14.04, and nothing else, I'll test it.

The documentation is a bit too generic for me to be 100% sure I know what I'm doing - I am not even sure of the exact package name and whether there are related packages that need to be installed as well. I am fully aware this seems very dim of me, but this machine is my main desktop and I really can't afford to mess it up.

[stargazer (stargazer05)]

For 12.04.x and 14.04 the kernel 3.13.0-32.56 and 31.55 is working!

No messages "retire_playback_urb: 829 callbacks suppressed" anymore!

[Paweł Wilk (siefca)]

Installing kernel 3.13.0-31.55 has fixed this issue in my case!

CPU: AMD Phenom 9650 Quad-Core

Sound device: i-tec ( C-Media Electronics, Inc. CM106 Like Sound Device )
Sound device chip: C-Media CM6206

[Paweł Wilk (siefca)]

However:

Sound card is eating about 5% of one CPU core:

Line from top:

 93 root -51 0 0 0 0 S 4,6 0,0 2:44.19 irq/16-

Fragment of /proc/interrupts

Is it normal for USB sound devices to generate such load?

           CPU0 CPU1 CPU2 CPU3
  0: 193 632 11469 650551 IO-APIC-edge timer
  1: 0 0 1 1 IO-APIC-edge i8042
  7: 1 0 0 0 IO-APIC-edge
  8: 0 0 0 0 IO-APIC-edge rtc0
  9: 0 0 0 0 IO-APIC-fasteoi acpi
 12: 1 0 0 4 IO-APIC-edge i8042
 14: 0 1 49 4226 IO-APIC-edge pata_amd
 15: 0 0 0 0 IO-APIC-edge pata_amd
 16: 4326115 10821 8863 214 IO-APIC-fasteoi , # btw, what comma does here instead of name?
 17: 0 0 0 0 IO-APIC-fasteoi eth0

The IRQ16 stops using CPU if USB sound card is disconnected. The card is connected to USB 3.0 PCI card identified as USB controller: Renesas Technology Corp. uPD720202 USB 3.0 Host Controller.

[Paweł Wilk (siefca)]

After plugging the device into USB 2.0 socket (nVidia chip) syslog messages re-appeared:

 [ 191.028275] retire_capture_urb: 29 callbacks suppressed
[ 214.789697] retire_capture_urb: 2 callbacks suppressed
[ 249.805552] retire_capture_urb: 11 callbacks suppressed
[ 254.804116] retire_capture_urb: 21 callbacks suppressed
[ 269.988701] retire_capture_urb: 3 callbacks suppressed
[ 316.323057] retire_capture_urb: 11 callbacks suppressed
[ 328.135311] retire_capture_urb: 11 callbacks suppressed
[ 338.685139] retire_capture_urb: 15 callbacks suppressed

[Paweł Wilk (siefca)]

But they've stopped appearing with such a frequency.

[Paweł Wilk (siefca)]

The patch is working, after re-plugging it to previous USB messages stopped appearing.

I think I know why it is consuming CPU. Pulseaudio is constantly "listening" from the plugged-in line input; it consumes even more CPU cycles.

[Alan Robertson (alanr-unix)]

I observe the same bug with a nuForce USB audio device. Didn't see it before trusty.

[Launchpad Janitor (janitor)]

This bug was fixed in the package linux - 3.13.0-32.57

---------------
linux (3.13.0-32.57) trusty; urgency=low

  [ Upstream Kernel Changes ]

  * l2tp: Privilege escalation in ppp over l2tp sockets
    - LP: #1341472
    - CVE-2014-4943

linux (3.13.0-32.56) trusty; urgency=low

  [ Luis Henriques ]

  * Merged back Ubuntu-3.13.0-30.55 security release
  * Revert "x86_64,ptrace: Enforce RIP <= TASK_SIZE_MAX (CVE-2014-4699)"
    - LP: #1337339
  * Release Tracking Bug
    - LP: #1338524

  [ Upstream Kernel Changes ]

  * ptrace,x86: force IRET path after a ptrace_stop()
    - LP: #1337339
    - CVE-2014-4699
  * hpsa: add new Smart Array PCI IDs (May 2014)
    - LP: #1337516

linux (3.13.0-31.55) trusty; urgency=low

  [ Luis Henriques ]

  * Release Tracking Bug
    - LP: #1336278

  [ Andy Whitcroft ]

  * [Config] switch hyper-keyboard to virtual
    - LP: #1325306
  * [Packaging] linux-udeb-flavour -- standardise on linux prefix

  [ dann frazier ]

  * [Config] CONFIG_GPIO_DWAPB=m
    - LP: #1334823

  [ Feng Kan ]

  * SAUCE: (no-up) arm64: dts: Add Designware GPIO dts binding to APM
    X-Gene platform
    - LP: #1334823

  [ John Johansen ]

  * SAUCE: (no-up) apparmor: fix apparmor spams log with warning message
    - LP: #1308761

  [ Kamal Mostafa ]

  * [Config] updateconfigs ACPI_PROCFS_POWER=y after v3.13.11.4 rebase

  [ Loc Ho ]

  * SAUCE: (no-up) phy-xgene: Use correct tuning for Mustang
    - LP: #1335636

  [ Michael Ellerman ]

  * SAUCE: (no-up) powerpc/perf: Ensure all EBB register state is cleared
    on fork()
    - LP: #1328914

  [ Ming Lei ]

  * Revert "SAUCE: (no-up) rtc: Add X-Gene SoC Real Time Clock Driver"
    - LP: #1274305

  [ Suman Tripathi ]

  * SAUCE: (no-up) libahci: Implement the function ahci_restart_engine to
    restart the port dma engine.
    - LP: #1335645
  * SAUCE: (no-up) ata: Fix the dma state machine lockup for the IDENTIFY
    DEVICE PIO mode command.
    - LP: #1335645

  [ Tim Gardner ]

  * [Config] CONFIG_POWERNV_CPUFREQ=y for powerpc, ppc64el
    - LP: #1324571
  * [Debian] Add UTS_UBUNTU_RELEASE_ABI to utsrelease.h
    - LP: #1327619
  * [Config] CONFIG_HAVE_MEMORYLESS_NODES=y
    - LP: #1332063
  * [Config] CONFIG_HID_RMI=m
    - LP: #1305522

  [ Upstream Kernel Changes ]

  * Revert "offb: Add palette hack for little endian"
    - LP: #1333430
  * Revert "net: mvneta: fix usage as a module on RGMII configurations"
    - LP: #1333837
  * Revert "USB: serial: add usbid for dell wwan card to sierra.c"
    - LP: #1333837
  * Revert "macvlan : fix checksums error when we are in bridge mode"
    - LP: #1333838
  * serial: uart: add hw flow control support configuration
    - LP: #1328295
  * mm/numa: Remove BUG_ON() in __handle_mm_fault()
    - LP: #1323165
  * Tools: hv: Handle the case when the target file exists correctly
    - LP: #1306215
  * Documentation/devicetree/bindings: add documentation for the APM X-Gene
    SoC RTC DTS binding
    - LP: #1274305
  * drivers/rtc: add APM X-Gene SoC RTC driver
    - LP: #1274305
  * arm64: add APM X-Gene SoC RTC DTS entry
    - LP: #1274305
  * powerpc/perf: Add Power8 cache & TLB events
    - LP: #1328914
  * powerpc/perf: Configure BH...

[Tom Kistner (duncanthrax)]

sound/usb/pcm.c contains two cases of this bug:

- in retire_playback_urb
- in retire_capture_urb

The above patch only fixes the retire_playback_urb one.

I have attached a patch that fixes the second occurence.

[Harry Coin (hcoin)]

Confirming the problem is not fixed in
3.13.0-46-generic #79-Ubuntu SMP Tue Mar 10 20:06:50 UTC 2015 x86_64 x86_64 x86_64 GNU/Linux

After this in the syslog
Mar 15 15:31:40 ceo1home kernel: [62288.808120] retire_capture_urb: 542 callbacks suppressed
Mar 15 15:31:45 ceo1home kernel: [62293.841065] retire_capture_urb: 527 callbacks suppressed
Mar 15 15:31:50 ceo1home kernel: [62298.868015] retire_capture_urb: 555 callbacks suppressed
Mar 15 15:31:55 ceo1home kernel: [62303.881960] retire_capture_urb: 552 callbacks suppressed
Mar 15 15:32:00 ceo1home kernel: [62308.896913] retire_capture_urb: 572 callbacks suppressed
Mar 15 15:32:05 ceo1home kernel: [62313.914858] retire_capture_urb: 563 callbacks suppressed
Mar 15 15:32:10 ceo1home kernel: [62318.919806] retire_capture_urb: 558 callbacks suppressed
Mar 15 15:32:15 ceo1home kernel: [62323.940758] retire_capture_urb: 548 callbacks suppressed
Mar 15 15:32:20 ceo1home kernel: [62328.974706] retire_capture_urb: 522 callbacks suppressed
Mar 15 15:32:25 ceo1home kernel: [62333.987654] retire_capture_urb: 576 callbacks suppressed

I unplugged the headset, then replugged it to get:

Mar 15 15:45:55 ceo1home kernel: [63144.734024] usb 2-5.2: New USB device found, idVendor=046d, idProduct=0a02
Mar 15 15:45:55 ceo1home kernel: [63144.734030] usb 2-5.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Mar 15 15:45:55 ceo1home kernel: [63144.734034] usb 2-5.2: Product: Logitech USB Headset
Mar 15 15:45:55 ceo1home kernel: [63144.734037] usb 2-5.2: Manufacturer: Logitech
Mar 15 15:45:55 ceo1home kernel: [63144.746773] usb_audio: Warning! Unlikely big volume range (=464), cval->res is probably wrong.
Mar 15 15:45:55 ceo1home kernel: [63144.746778] usb_audio: [6] FU [Mic Playback Volume] ch = 1, val = -10496/-3072/16<6>[63144.763095] input: Logitech Logitech USB Headset as /devices/pci0000:00/0000:00:1d.7/usb2/2-5/2-5.2/2-5.2:1.3/input/input25
Mar 15 15:45:55 ceo1home kernel: [63144.763307] hid-generic 0003:046D:0A02.0006: input,hidraw0: USB HID v1.00 Device [Logitech Logitech USB Headset] on usb-0000:00:1d.7-5.2/input3
Mar 15 15:45:55 ceo1home mtp-probe: checking bus 2, device 9: "/sys/devices/pci0000:00/0000:00:1d.7/usb2/2-5/2-5.2"
Mar 15 15:45:55 ceo1home mtp-probe: bus: 2, device: 9 was not an MTP device
Mar 15 15:45:56 ceo1home rtkit-daemon[3225]: Successfully made thread 13980 of process 28715 (n/a) owned by '1000' RT at priority 5.
Mar 15 15:45:56 ceo1home rtkit-daemon[3225]: Supervising 3 threads of 1 processes of 1 users.
Mar 15 15:45:56 ceo1home rtkit-daemon[3225]: Successfully made thread 13981 of process 28715 (n/a) owned by '1000' RT at priority 5.
Mar 15 15:45:56 ceo1home rtkit-daemon[3225]: Supervising 4 threads of 1 processes of 1 users.
Mar 15 15:45:58 ceo1home kernel: [63147.787367] retire_capture_urb: 528 callbacks suppressed

...
Problem recurs.

Not fixed as yet....

[K1773R (k1773r)]

What is th estatus about the retire_capture_urb ? I still see this on current sable.

[penalvch (penalvch)]

Harry Coin / K1773R, as this report is closed, your issue is not being attended to here.

However, it will help immensely if you filed a new report via a terminal:
ubuntu-bug linux

Please feel free to subscribe me to it.