Bug 204087 - Bad handling of removing a USB device while recording audio from it
Summary: Bad handling of removing a USB device while recording audio from it
Status: REOPENED
Alias: None
Product: v4l-dvb
Classification: Unclassified
Component: v4l-other (show other bugs)
Hardware: All Linux
: P1 normal
Assignee: v4l-other
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2019-07-07 13:11 UTC by Tom Mason
Modified: 2020-04-27 00:47 UTC (History)
2 users (show)

See Also:
Kernel Version: 4.19
Subsystem:
Regression: No
Bisected commit-id:


Attachments
dmesg including backtrace of deadlock (2.41 KB, text/plain)
2020-04-27 00:47 UTC, Zebediah Figura
Details

Description Tom Mason 2019-07-07 13:11:27 UTC
I have a particular USB capture device (this one: https://www.alza.cz/manhattan-usb-audio-video-grabber-d4941424.htm) which causes problems if I unplug the USB device while recording.

If I use arecord like this: arecord -f dat -d 20 -D hw:1,0 test.wav, then uplug the card while the recorsing is running, arecord will print an error and hang, and the card will still show up in lsusb.
If I unplug the card while not recording, it is removed correctly.

Output of arecord:
> 
>$ arecord -f dat -d 20 -D hw:1,0 test.wav
>Recording WAVE 'test.wav' : Signed 16 bit Little Endian, Rate 48000 Hz, Stereo
>arecord: pcm_read:2145: read error: No such device

arecord now hangs and can't be killed.


Here is my alsa-info.sh output: http://alsa-project.org/db/?f=fe35240549bb5d9e292fdb93d31da96bf374317a.

Syslog output from attaching the card, then detaching it while recording:
> 
>Jul  7 15:00:07 wheybrem kernel: [ 1057.902737] usb 1-2: new high-speed USB
>device number 5 using xhci_hcd
>Jul  7 15:00:07 wheybrem kernel: [ 1058.058309] usb 1-2: New USB device found,
>idVendor=1f4d, idProduct=0102, bcdDevice=40.02
>Jul  7 15:00:07 wheybrem kernel: [ 1058.058317] usb 1-2: New USB device
>strings: Mfr=1, Product=2, SerialNumber=3
>Jul  7 15:00:07 wheybrem kernel: [ 1058.058321] usb 1-2: Product: OTG102
>Jul  7 15:00:07 wheybrem kernel: [ 1058.058326] usb 1-2: Manufacturer:
>Geniatech
>Jul  7 15:00:07 wheybrem kernel: [ 1058.058330] usb 1-2: SerialNumber:
>20090427
>Jul  7 15:00:07 wheybrem kernel: [ 1058.063004] cx231xx 1-2:1.1: New device
>Geniatech OTG102 @ 480 Mbps (1f4d:0102) with 6 interfaces
>Jul  7 15:00:07 wheybrem kernel: [ 1058.063030] cx231xx 1-2:1.1: Identified as
>Geniatech OTG102 (card=17)
>Jul  7 15:00:07 wheybrem kernel: [ 1058.063175] i2c i2c-7: Added multiplexed
>i2c bus 9
>Jul  7 15:00:07 wheybrem kernel: [ 1058.063202] i2c i2c-7: Added multiplexed
>i2c bus 10
>Jul  7 15:00:07 wheybrem kernel: [ 1058.193588] cx25840 6-0044: cx23102 A/V
>decoder found @ 0x88 (cx231xx #0-0)
>Jul  7 15:00:07 wheybrem kernel: [ 1058.213826] cx25840 6-0044: firmware:
>direct-loading firmware v4l-cx231xx-avcore-01.fw
>Jul  7 15:00:09 wheybrem kernel: [ 1060.381804] cx25840 6-0044: loaded
>v4l-cx231xx-avcore-01.fw firmware (16382 bytes)
>Jul  7 15:00:09 wheybrem kernel: [ 1060.421440] cx231xx 1-2:1.1: v4l2 driver
>version 0.0.3
>Jul  7 15:00:09 wheybrem kernel: [ 1060.522125] cx231xx 1-2:1.1: Registered
>video device video0 [v4l2]
>Jul  7 15:00:09 wheybrem kernel: [ 1060.522210] cx231xx 1-2:1.1: Registered
>VBI device vbi0
>Jul  7 15:00:09 wheybrem kernel: [ 1060.522413] cx231xx 1-2:1.1: audio
>EndPoint Addr 0x83, Alternate settings: 3
>Jul  7 15:00:09 wheybrem kernel: [ 1060.522434] cx231xx 1-2:1.1: video
>EndPoint Addr 0x84, Alternate settings: 5
>Jul  7 15:00:09 wheybrem kernel: [ 1060.522439] cx231xx 1-2:1.1: VBI EndPoint
>Addr 0x85, Alternate settings: 2
>Jul  7 15:00:09 wheybrem kernel: [ 1060.522445] cx231xx 1-2:1.1: sliced CC
>EndPoint Addr 0x86, Alternate settings: 2
>Jul  7 15:00:09 wheybrem mtp-probe: checking bus 1, device 5:
>"/sys/devices/pci0000:00/0000:00:14.0/usb1/1-2"
>Jul  7 15:00:09 wheybrem mtp-probe: bus: 1, device: 5 was not an MTP device
>Jul  7 15:00:09 wheybrem mtp-probe: checking bus 1, device 5:
>"/sys/devices/pci0000:00/0000:00:14.0/usb1/1-2"
>Jul  7 15:00:09 wheybrem mtp-probe: bus: 1, device: 5 was not an MTP device
>Jul  7 15:00:09 wheybrem rtkit-daemon[736]: Supervising 3 threads of 1
>processes of 1 users.
>Jul  7 15:00:09 wheybrem rtkit-daemon[736]: Successfully made thread 5657 of
>process 1047 (n/a) owned by '1000' RT at priority 5.
>Jul  7 15:00:09 wheybrem rtkit-daemon[736]: Supervising 4 threads of 1
>processes of 1 users.
>Jul  7 15:00:27 wheybrem kernel: [ 1078.421141] usb 1-2: USB disconnect,
>device number 5

When I detach while not recording, I get the following:
> 
>Jul  7 14:59:59 wheybrem kernel: [ 1050.406945] usb 1-2: USB disconnect,
>device number 4
>Jul  7 14:59:59 wheybrem kernel: [ 1050.427300] cx231xx 1-2:1.1: V4L2 device
>vbi0 deregistered
>Jul  7 14:59:59 wheybrem kernel: [ 1050.429259] cx231xx 1-2:1.1: V4L2 device
>video0 deregistered


I originally reported this bug to the pulseaudio developers, here is the original bug report: https://gitlab.freedesktop.org/pulseaudio/pulseaudio/issues/698

If anyone wants ssh access to a machine with the card in it, I can provide that, or post the card to a developer if they agree to post it back. but I will be away for the next week, and unavailable.
Comment 1 Takashi Iwai 2019-08-12 12:15:06 UTC
It's the expected behavior.  In Linux kernel, you can't delete the file object from the kernel side while it's in use.  The handling of such a situation differs with each driver / subsystem, and for the sound subsystem, we replace the file ops to respond only but closing when a device gets disconnected.
Comment 2 Tom Mason 2019-08-12 12:34:04 UTC
So, this behaviour causes pulseaudio to hang if it is using the device while it's pulled. Is this indeed a bug in pulseaudio? Also, this behavior does not occur with a different usb sound card.
Comment 3 Takashi Iwai 2019-08-12 12:47:40 UTC
OK, then it's a bug in that V4L driver.  cx231xx is no USB-audio device, but a V4L driver supporting ALSA device, and probably it has no proper disconnection handling for the audio.

I try to change the component.  You might report to another V4L bug tracking, if this isn't taken.
Comment 4 Zebediah Figura 2020-04-27 00:47:26 UTC
Created attachment 288741 [details]
dmesg including backtrace of deadlock

I encountered this with the Hauppauge 955Q (2040:b123). dmesg shows the attached backtrace, using the same "arecord" command.

Looking at the code, it seems that cx231xx_usb_disconnect() holds a mutex while waiting for open fds to be closed [through cx231xx_close_extension() -> snd_card_free()], but snd_cx231xx_pcm_close() also grabs that mutex when closing the file on behalf of arecord.

This is obviously not desirable, but I don't know the correct way to fix it.

Note You need to log in before you can comment on or make changes to this bug.