Bug 35922
| Summary: | SND_USB_AUDIO recording device not initializing correctly | ||
|---|---|---|---|
| Product: | Drivers | Reporter: | bjoern |
| Component: | Sound(ALSA) | Assignee: | Jaroslav Kysela (perex) |
| Status: | RESOLVED PATCH_ALREADY_AVAILABLE | ||
| Severity: | normal | CC: | bastian.beischer, bigbedue, dgbaley27, florian, jose1711, joseph.salisbury, kernelorg, lephilousophe, maciej.rutecki, migo, oliver, rjw, stefan.heinsen, tiwai |
| Priority: | P1 | ||
| Hardware: | All | ||
| OS: | Linux | ||
| Kernel Version: | 2.6.39 | Subsystem: | |
| Regression: | Yes | Bisected commit-id: | |
| Bug Depends on: | |||
| Bug Blocks: | 32012 | ||
| Attachments: |
Output of lsusb -v
dmesg from step 3 dmesg from step 5 dmesg from step 5 dmesg from step 5 add RESET_RESUME quirk |
||
|
Description
bjoern
2011-05-26 10:30:32 UTC
The only major USB-audio change is the support autosuspend and a fix of suspned/resume code. Can it be the case? They are commit 88a8516a2128a6d078a106ead48092240e8a138f and edf7de31c25ce72f163bf7d1fc0d2711869d073c Otherwise I'd rather suspect a change in the USB core / controller side. I just reverted the two commits you mentioned from the 2.6.39 Kernel And now the microphone works correctly again. So it is definitely related to USB-audio. Could you figure out which of these commit affects? According to my testing commit 88a8516a2128a6d078a106ead48092240e8a138f is the offending one. So it's the auto-suspend patch... (In reply to comment #0) > Hello. > > I found a regression. When trying to record audio from the integrated Mic of > my > Logitech webcam with the 2.6.39 Kernel the record is choppy or doesn't work > at > all, sometimes it works for one record but after that its broken again. > In kernel 2.6.38 everything works fine. > > Here is what dmesg is telling me: > 2:3:4: cannot set freq 48000 to ep 0x86 > usb 1-3: reset high speed USB device number 2 using ehci_hcd > snd-usb-audio 1-3:1.2: no reset_resume for driver snd-usb-audio? > snd-usb-audio 1-3:1.3: no reset_resume for driver snd-usb-audio? I need to know why the kernel wants to do a reset_resume(). Can you please attach "lsusb -v"? Created attachment 60132 [details]
Output of lsusb -v
Heres The output of lsusb -v with the camera connected. I didn't record anything beforehand.
This still doesn't make clear why reset_resume() is called. Could you compile with CONFIG_PM_DEBUG and do the following test: 1. attach device 2. write "auto" into its power/control attribute, wait 10 seconds write "on 3. attach dmesg 4. write "auto", wait 10 seconds, record something 4. attach dmesg I'll be on holiday this weekend. so won't be able to try this until Monday. Created attachment 60942 [details]
dmesg from step 3
Created attachment 60952 [details]
dmesg from step 5
I just did what you said.
I wrote the power contol things to the file:
/sys/devices/pci0000:00/0000:00:1d.0/usb2/driver/1-3/1-3:1.2/sound/card1/power/control
Hope this was correct.
The dmesg from step 5 was saved after recording worked fist time. Beforehand it failed about 4 times.
there is a flood of:
"scsi host1: rpm_resume flags 0x4
scsi host1: rpm_resume returns 1"
(and some other funny stuff)
in the log, I hope this doesn't matter.
(In reply to comment #11) > Hope this was correct. Absolutely correct. > The dmesg from step 5 was saved after recording worked fist time. Beforehand > it > failed about 4 times. That _is_ a problem. I need a log of a failure to know what's wrong > there is a flood of: > "scsi host1: rpm_resume flags 0x4 > scsi host1: rpm_resume returns 1" > (and some other funny stuff) > in the log, I hope this doesn't matter. The SCSI core now can do power management. The message means that it thinks that a device would have to be resumed no. And "rpm_resume returns 1" means that everything is alright. A device doesn't need to be resumed, because it is already active. Created attachment 61142 [details]
dmesg from step 5
Ok. now here the last one is a fail.
(In reply to comment #13) > Created an attachment (id=61142) [details] > dmesg from step 5 > > Ok. now here the last one is a fail. This log contains no failure coming from the kernel. Did you see only arecord fail? Could you indicate when exactly in a log the failure happens? And please also compile with CONFIG_USB_DEBUG. This bug is hiding itself well. Created attachment 63442 [details]
dmesg from step 5
... ok I recompiled with USB_DEBUG.
I see this happen with arecord, audacity, teamspeak3 and Skype .... so it's definitely no application specific Problem.
When it works I think it most of the time kinda lags before the record is beginning.
When it fails there are two possibilities. Either the audio stream just seems to stay empty and will give me empty record files.
Or I get an error message like: "Error while opening sound device." (from audacity)
I cut out a part of the log-file that should correspond to the moment where it failed with an error message:
scsi host1: rpm_resume flags 0x4
scsi host1: rpm_resume returns 1
scsi host1: rpm_resume flags 0x4
scsi host1: rpm_resume returns 1
snd-usb-audio 1-3:1.2: rpm_resume flags 0x4
usb 1-3: rpm_resume flags 0x0
usb usb1: rpm_resume flags 0x0
ehci_hcd 0000:00:1d.7: rpm_resume flags 0x0
ehci_hcd 0000:00:1d.7: rpm_resume returns 1
usb usb1: usb auto-resume
ehci_hcd 0000:00:1d.7: resume root hub
hub 1-0:1.0: hub_resume
hub 1-0:1.0: port 3: status 0507 change 0000
usb usb1: rpm_resume returns 0
usb 1-3: usb auto-resume
hub 1-0:1.0: state 7 ports 8 chg 0000 evt 0000
hub 1-0:1.0: rpm_resume flags 0x4
hub 1-0:1.0: rpm_resume returns 0
hub 1-0:1.0: rpm_suspend flags 0x4
hub 1-0:1.0: rpm_suspend returns 0
ehci_hcd 0000:00:1d.7: GetStatus port:3 status 001005 0 ACK POWER sig=se0 PE CONNECT
usb 1-3: finish resume
usb 1-3: rpm_resume returns 0
snd-usb-audio 1-3:1.2: rpm_resume returns 0
PM: Adding info for No Bus:ep_86
scsi host1: rpm_resume flags 0x4
scsi host1: rpm_resume returns 1
PM: Removing info for No Bus:ep_86
snd-usb-audio 1-3:1.2: rpm_suspend flags 0x4
snd-usb-audio 1-3:1.2: rpm_suspend returns 0
usb 1-3: rpm_suspend flags 0x8
usb 1-3: rpm_suspend returns 0
scsi host1: rpm_resume flags 0x4
scsi host1: rpm_resume returns 1
snd-usb-audio 1-3:1.2: rpm_resume flags 0x4
snd-usb-audio 1-3:1.2: rpm_resume returns 0
PM: Adding info for No Bus:ep_86
usb 1-3: rpm_suspend flags 0x9
usb 1-3: rpm_suspend returns -16
scsi host1: rpm_resume flags 0x4
scsi host1: rpm_resume returns 1
PM: Removing info for No Bus:ep_86
snd-usb-audio 1-3:1.2: rpm_suspend flags 0x4
snd-usb-audio 1-3:1.2: rpm_suspend returns 0
usb 1-3: rpm_suspend flags 0x8
usb 1-3: rpm_suspend returns 0
scsi host1: rpm_resume flags 0x4
scsi host1: rpm_resume returns 1
usb 1-3: rpm_suspend flags 0x9
usb 1-3: rpm_suspend returns 0
usb 1-3: rpm_suspend flags 0xa
usb 1-3: usb auto-suspend
usb 1-3: rpm_suspend returns 0
usb usb1: rpm_suspend flags 0x8
usb usb1: rpm_suspend returns 0
scsi host1: rpm_resume flags 0x4
scsi host1: rpm_resume returns 1
usb usb1: rpm_suspend flags 0x9
usb usb1: rpm_suspend returns 0
usb usb1: rpm_suspend flags 0x9
usb usb1: rpm_suspend returns 0
usb usb1: rpm_suspend flags 0xa
hub 1-0:1.0: hub_suspend
usb usb1: bus auto-suspend
ehci_hcd 0000:00:1d.7: suspend root hub
usb usb1: rpm_suspend returns 0
scsi host1: rpm_resume flags 0x4
scsi host1: rpm_resume returns 1
snd-usb-audio 1-3:1.2: rpm_resume flags 0x4
usb 1-3: rpm_resume flags 0x0
usb usb1: rpm_resume flags 0x0
ehci_hcd 0000:00:1d.7: rpm_resume flags 0x0
ehci_hcd 0000:00:1d.7: rpm_resume returns 1
usb usb1: usb auto-resume
ehci_hcd 0000:00:1d.7: resume root hub
hub 1-0:1.0: hub_resume
hub 1-0:1.0: port 3: status 0507 change 0000
usb usb1: rpm_resume returns 0
usb 1-3: usb auto-resume
hub 1-0:1.0: state 7 ports 8 chg 0000 evt 0000
hub 1-0:1.0: rpm_resume flags 0x4
hub 1-0:1.0: rpm_resume returns 0
hub 1-0:1.0: rpm_suspend flags 0x4
hub 1-0:1.0: rpm_suspend returns 0
ehci_hcd 0000:00:1d.7: GetStatus port:3 status 001005 0 ACK POWER sig=se0 PE CONNECT
usb 1-3: finish resume
usb 1-3: rpm_resume returns 0
snd-usb-audio 1-3:1.2: rpm_resume returns 0
PM: Adding info for No Bus:ep_86
scsi host1: rpm_resume flags 0x4
scsi host1: rpm_resume returns 1
PM: Removing info for No Bus:ep_86
snd-usb-audio 1-3:1.2: rpm_suspend flags 0x4
snd-usb-audio 1-3:1.2: rpm_suspend returns 0
usb 1-3: rpm_suspend flags 0x8
usb 1-3: rpm_suspend returns 0
scsi host1: rpm_resume flags 0x4
scsi host1: rpm_resume returns 1
snd-usb-audio 1-3:1.2: rpm_resume flags 0x4
snd-usb-audio 1-3:1.2: rpm_resume returns 0
PM: Adding info for No Bus:ep_86
usb 1-3: rpm_suspend flags 0x9
usb 1-3: rpm_suspend returns -16
scsi host1: rpm_resume flags 0x4
scsi host1: rpm_resume returns 1
PM: Removing info for No Bus:ep_86
snd-usb-audio 1-3:1.2: rpm_suspend flags 0x4
snd-usb-audio 1-3:1.2: rpm_suspend returns 0
usb 1-3: rpm_suspend flags 0x8
usb 1-3: rpm_suspend returns 0
usb 1-3: rpm_suspend flags 0x9
usb 1-3: rpm_suspend returns 0
scsi host1: rpm_resume flags 0x4
scsi host1: rpm_resume returns 1
usb 1-3: rpm_suspend flags 0x9
usb 1-3: rpm_suspend returns 0
usb 1-3: rpm_suspend flags 0xa
usb 1-3: usb auto-suspend
usb 1-3: rpm_suspend returns 0
usb usb1: rpm_suspend flags 0x8
usb usb1: rpm_suspend returns 0
snd-usb-audio 1-3:1.2: rpm_resume flags 0x4
usb 1-3: rpm_resume flags 0x0
usb usb1: rpm_resume flags 0x0
usb usb1: rpm_resume returns 1
usb 1-3: usb auto-resume
ehci_hcd 0000:00:1d.7: GetStatus port:3 status 001005 0 ACK POWER sig=se0 PE CONNECT
usb 1-3: finish resume
usb 1-3: rpm_resume returns 0
snd-usb-audio 1-3:1.2: rpm_resume returns 0
PM: Adding info for No Bus:ep_86
usb usb1: rpm_suspend flags 0x9
usb usb1: rpm_suspend returns -16
scsi host1: rpm_resume flags 0x4
scsi host1: rpm_resume returns 1
PM: Removing info for No Bus:ep_86
snd-usb-audio 1-3:1.2: rpm_suspend flags 0x4
snd-usb-audio 1-3:1.2: rpm_suspend returns 0
usb 1-3: rpm_suspend flags 0x8
usb 1-3: rpm_suspend returns 0
scsi host1: rpm_resume flags 0x4
scsi host1: rpm_resume returns 1
usb 1-3: rpm_suspend flags 0x9
usb 1-3: rpm_suspend returns 0
usb 1-3: rpm_suspend flags 0xa
usb 1-3: usb auto-suspend
usb 1-3: rpm_suspend returns 0
usb usb1: rpm_suspend flags 0x8
usb usb1: rpm_suspend returns 0
scsi host1: rpm_resume flags 0x4
scsi host1: rpm_resume returns 1
snd-usb-audio 1-3:1.2: rpm_resume flags 0x4
usb 1-3: rpm_resume flags 0x0
usb usb1: rpm_resume flags 0x0
usb usb1: rpm_resume returns 1
usb 1-3: usb auto-resume
ehci_hcd 0000:00:1d.7: GetStatus port:3 status 001005 0 ACK POWER sig=se0 PE CONNECT
usb 1-3: finish resume
usb 1-3: rpm_resume returns 0
snd-usb-audio 1-3:1.2: rpm_resume returns 0
PM: Adding info for No Bus:ep_86
usb 1-3: audacity timed out on ep0in len=3/3
2:3:4: cannot get freq at ep 0x86
usb usb1: rpm_suspend flags 0x9
usb usb1: rpm_suspend returns -16
scsi host1: rpm_resume flags 0x4
scsi host1: rpm_resume returns 1
PM: Removing info for No Bus:ep_86
snd-usb-audio 1-3:1.2: rpm_suspend flags 0x4
snd-usb-audio 1-3:1.2: rpm_suspend returns 0
usb 1-3: rpm_suspend flags 0x8
usb 1-3: rpm_suspend returns 0
scsi host1: rpm_resume flags 0x4
scsi host1: rpm_resume returns 1
snd-usb-audio 1-3:1.2: rpm_resume flags 0x4
snd-usb-audio 1-3:1.2: rpm_resume returns 0
PM: Adding info for No Bus:ep_86
usb 1-3: rpm_suspend flags 0x9
usb 1-3: rpm_suspend returns -16
usb 1-3: audacity timed out on ep0out len=0/3
2:3:4: cannot set freq 48000 to ep 0x86
PM: Removing info for No Bus:ep_86
snd-usb-audio 1-3:1.2: rpm_suspend flags 0x4
snd-usb-audio 1-3:1.2: rpm_suspend returns 0
usb 1-3: rpm_suspend flags 0x8
usb 1-3: rpm_suspend returns 0
scsi host1: rpm_resume flags 0x4
scsi host1: rpm_resume returns 1
usb 1-3: rpm_suspend flags 0x9
usb 1-3: rpm_suspend returns 0
usb 1-3: rpm_suspend flags 0xa
usb 1-3: usb auto-suspend
usb 1-3: rpm_suspend returns 0
usb usb1: rpm_suspend flags 0x8
usb usb1: rpm_suspend returns 0
scsi host1: rpm_resume flags 0x4
scsi host1: rpm_resume returns 1
usb usb1: rpm_suspend flags 0x9
usb usb1: rpm_suspend returns 0
usb usb1: rpm_suspend flags 0x9
usb usb1: rpm_suspend returns 0
usb usb1: rpm_suspend flags 0xa
hub 1-0:1.0: hub_suspend
usb usb1: bus auto-suspend
ehci_hcd 0000:00:1d.7: suspend root hub
usb usb1: rpm_suspend returns 0
scsi host1: rpm_resume flags 0x4
scsi host1: rpm_resume returns 1
scsi host1: rpm_resume flags 0x4
scsi host1: rpm_resume returns 1
Created attachment 64722 [details]
add RESET_RESUME quirk
According to the log the device has a firmware problem. Please test this patch, also with normal suspend/resume of the whole system.
Hey, I just tested the patch and everything seems to work correctly now. I've tried it several times with different Applications. Audacity sometimes got stuck when the record started and I had to retry but I would think this is a Problem of Audacity since all the other Programs never showed such behaviour. So problem solved, thank you very much. :D Hey, I just wanted to ask what is going to happen now? There shouldn't be any mire Info needed. should it be set to resolved? Hello, I am not sure it's the right place to post. Anyway, I have the same problem with my Logitech C310 webcam. Modifying the patch according to my VID:PID fixes the bug. My VID:PID are : 0x046d, 0x081b Patch: https://bugzilla.kernel.org/attachment.cgi?id=64722 @bjoern; well, now you have to find someone to send it Linus'wards.. which probably Oliver already took care of? Check the archives of the usb mailinglist or ping Oliver about it. @Philippe: submit that patch to the usb mailinglist with a pointer to this bugreport (see Documentation/SubmittingPatches) or just ping Oliver to adapt the original patch accordingly. The problem also appears on a logitech C250 and can be fixed the same way as on the C270.
As noted in #20 at least the C310 has that problem too, probably more devices have.
It would be nice if you could add the C250 to the patch.
lsusb:
> Bus 001 Device 002: ID 046d:0804 Logitech, Inc. Webcam C250
Patches for C250, C270 and C310 have been submitted. Hi, same problem here, with lsusb: 046d:0807 Logitech, Inc. Webcam B500 (The actual name of the webcam - according to the box it was sold in - is C500, instead of B500, don't know what you prefer to call it) I need this for my "06f8:3005 Guillemot Corp. Hercules Dualpix Exchange" and "046d:0809 Logitech, Inc. Webcam Pro 9000". Is there a more general issue here? the patch also resolves same recording problem for C200. lsusb: Bus 001 Device 003: ID 046d:0802 Logitech, Inc. Webcam C200 it would be great if it can be submitted as well. cheers, jose There is a pattern, definitely. The problem is that we cannot fix this by simply not autosuspending webcams. The firmware in those devices seems to have a race condition that can crash them on resumption. This is not limited to runtime power management. It is merely much easier to trigger. It can also happen on ordinary suspend/resume. Hence the devices must be treated as quirky. Oliver, Is there anything that can be done without the quirk in the meantime like a module option or writing something to /sys? (In reply to comment #28) > Oliver, > > Is there anything that can be done without the quirk in the meantime like a > module option or writing something to /sys? You'd race against the autosuspend. And you likely loose that race. You just can disable autosuspend in total with the "autosuspend" kernel parameter, but you can still be bitten if the whole system is suspended. Do I have to open up an additional bug to get the quirks for my two webcams (and the others listed in the comments)? Sorry to reopen this old Thing, but the Problem seems to exists in recent Kernels: Linux scott 3.3.7-1-ARCH #1 SMP PREEMPT Tue May 22 00:26:26 CEST 2012 x86_64 GNU/Linux Is there a new Bug for that Kernel Version? To clarify: My System hangs or doesn't even boot properly "sometimes", then the log is flooded with Jun 2 20:42:17 localhost kernel: [ 984.523418] 2:3:4: cannot set freq 48000 to ep 0x86 Jun 2 20:42:18 localhost kernel: [ 985.523349] 2:3:4: cannot set freq 48000 to ep 0x86 Jun 2 20:42:19 localhost kernel: [ 986.523412] 2:3:4: cannot set freq 48000 to ep 0x86 Blasklisting snd_usb_audio ot unplugging my webcam (Bus 001 Device 002: ID 046d:0825 Logitech, Inc. Webcam C270) solves the Problem. My Logitech C210 webcam stopped to work after some rawhide update a month or so ago (/var/log/messages is flooded with "cannot set freq 48000 to ep 0x86"). # lsusb | grep Webcam Bus 001 Device 010: ID 046d:0819 Logitech, Inc. Webcam C210 # uname -a Linux sparta.2y.net 3.5.0-0.rc3.git0.2.fc18.i686 #1 SMP Mon Jun 18 15:32:29 UTC 2012 i686 i686 i386 GNU/Linux Used a hint in the previous comment to make video (ucview, xaw) work again: # killall pulseaudio # rmmod snd_usb_audio Of course disabling snd_usb_audio solves the webcam video only, but leaves me without a webcam microphone... There is definetely a regression. Tested on two kernel version. 1) 3.4.4 (from core/linux repo) Webcam working, microphone working. # dmesg [ 8.170223] 3:3:2: cannot set freq 24000 to ep 0x86 [ 8.312677] usbcore: registered new interface driver snd-usb-audio # uname -a Linux ROMAN-5720ZG 3.4.4-2-ARCH #1 SMP PREEMPT Sun Jun 24 18:59:47 CEST 2012 x86_64 GNU/Linux # lsusb | grep Webcam Bus 007 Device 003: ID 046d:081b Logitech, Inc. Webcam C310 Configuration: http://dl.dropbox.com/u/42925887/linux_bug35922/linux-3.4.4.config.xz 2) 3.5.0-rc6 (from torvalds/linux.git, commit 918227bb1b59444a2c467711fd50cc22bb4a897b) Webcam NOT working, microphone NOT working. # dmesg [ 9.060432] usbcore: registered new interface driver snd-usb-audio ... [ 62.626139] 3:-1:4: cannot set freq 48000 to ep 0x86 [ 62.632639] 3:-1:4: cannot set freq 48000 to ep 0x86 ... (many same lines in here) [ 76.865398] 3:-1:4: cannot set freq 48000 to ep 0x86 [ 79.204290] uvcvideo: Failed to set UVC probe control : -71 (exp. 26). [ 79.208412] uvcvideo: Failed to set UVC probe control : -71 (exp. 26). [ 79.215681] uvcvideo: Failed to set UVC commit control : -71 (exp. 26). # uname -a Linux ROMAN-5720ZG 3.5.0-rc6-custom #1 SMP PREEMPT Fri Jul 13 11:29:10 MSK 2012 x86_64 GNU/Linux Configuration: http://dl.dropbox.com/u/42925887/linux_bug35922/linux-3.5.0-rc6.config.xz This bug appears to be closed. New bug 44281 was opened for this regression in 3.5.0-rc1. |