[alsa-devel] Problems with usb soundcard in kernels > 3.3
Hello all,
After spending a couple of days searching the web for a solution, I write here to ask for help. I am using an usb soundcard (Phoenix Audio Technologies Phnx MT201solo) on Debian Wheezy, and started to experience problems when using kernels
3.3.
The issue I am experiencing is a ~4 seconds delay in playing sound. I am reproducing the problem using aplay. The sound play is being delayed by more or less 4 seconds from the moment the file is sent to the card. I have tested with kernels 3.2 and 3.3, which work properly. I have noticed this delay/wait when using kernels 3.15, 3.16. Below are some details:
WORKING PROPERLY # uname -rv 3.2.0-4-686-pae #1 SMP Debian 3.2.63-2 # dpkg -l | grep alsa ii alsa-base 1.0.25+3~deb7u1 all ALSA driver configuration files ii alsa-utils 1.0.25-4 i386 Utilities for configuring and using ALSA # dmesg .... usb 3-1: New USB device found, idVendor=1de7, idProduct=0011 usb 3-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 usb 3-1: Product: Phnx MT201solo usb 3-1: Manufacturer: Phoenix Audio Technologies ....
# time aplay /usr/share/sounds/alsa/Rear_Left.wav Playing WAVE '/usr/share/sounds/alsa/Rear_Left.wav' : Signed 16 bit Little Endian, Rate 48000 Hz, Mono
real 0m2.498s <--- this is OK user 0m0.032s sys 0m0.024s
DELAY INTRODUCED # uname -rv 3.16-0.bpo.2-686-pae #1 SMP Debian 3.16.3-2~bpo70+1 (2014-09-21) # dpkg -l | grep alsa ii alsa-base 1.0.25+3~deb7u1 all ALSA driver configuration files ii alsa-utils 1.0.25-4 i386 Utilities for configuring and using ALSA # dmesg .... usb 2-1: New USB device found, idVendor=1de7, idProduct=0011 usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 usb 2-1: Product: Phnx MT201solo usb 2-1: Manufacturer: Phoenix Audio Technologies .... # time aplay /usr/share/sounds/alsa/Rear_Left.wav Playing WAVE '/usr/share/sounds/alsa/Rear_Left.wav' : Signed 16 bit Little Endian, Rate 48000 Hz, Mono
real 0m6.387s <----4 more seconds delay, NOK user 0m0.016s sys 0m0.024s
I have done a strace, see below where the 4 seconds are lost, maybe it helps:
open("/dev/snd/pcmC0D0p", O_RDWR|O_NONBLOCK|O_CLOEXEC) = 4 fcntl64(4, F_SETFD, FD_CLOEXEC) = 0 ioctl(4, AGPIOC_ACQUIRE or APM_IOC_STANDBY, 0xbf823f4c) = 0 close(3) = 0 ioctl(4, AGPIOC_ACQUIRE or APM_IOC_STANDBY, 0xbf823dac) = 0 fcntl64(4, F_GETFL) = 0x802 (flags O_RDWR|O_NONBLOCK) ioctl(4, AGPIOC_INFO, 0xbf823d14) = 0 clock_gettime(CLOCK_MONOTONIC, {5839, 700325532}) = 0 ioctl(4, AGPIOC_SETUP, 0xbf823d1c) = 0 mmap2(NULL, 4096, PROT_READ, MAP_SHARED, 4, 0x80000) = 0xb72db000 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_SHARED, 4, 0x81000) = 0xb72da000 ioctl(4, 0xc25c4110, 0xbf823ee0) = 0 ioctl(4, 0xc25c4110, 0xbf823ee0) = 0 ioctl(4, 0xc25c4110, 0xbf823ee0) = 0 ioctl(4, 0xc25c4110, 0xbf823ee0) = 0 ioctl(4, 0xc25c4110, 0xbf823ee0) = 0 ioctl(4, 0xc25c4110, 0xbf823ee0) = 0 ioctl(4, 0xc25c4110, 0xbf823ee0) = 0 ioctl(4, 0xc25c4110, 0xbf823ee0) = 0 ioctl(4, 0xc25c4111, 0xbf823ee0) = 0 ioctl(4, 0xc0684113, 0xbf823d94) = 0 ioctl(4, 0x80104132, 0xbf823cd0) = 0 ioctl(4, 0x80104132, 0xbf823cd0) = 0 mmap2(NULL, 65536, PROT_READ|PROT_WRITE, MAP_SHARED, 4, 0) = 0xb7293000 ----> ioctl(4, 0x4140, 0xb7718ff4) = 0 <---- !!! Here is where the 4 seconds are lost !!! ioctl(4, 0xc0684113, 0xbf823e60) = 0 ioctl(4, 0x4142, 0xb7709c16) = 0 ioctl(4, AGPIOC_INFO, 0xbf8241a0) = 0 shmget(0x56a4d6, 131072, IPC_CREAT|0660) = 163841 shmctl(163841, IPC_64|IPC_STAT, 0xbf82415c) = 0 shmctl(163841, IPC_64|IPC_SET, 0xbf82415c) = 0 ....
I think this is a problem in the snd-usb-audio module introduced in kernels > 3.3. Can anyone help me with this issue?
Thanks, Bogdan
Bogdan Veringioiu wrote:
The issue I am experiencing is a ~4 seconds delay in playing sound. I am reproducing the problem using aplay. The sound play is being delayed by more or less 4 seconds from the moment the file is sent to the card. I have tested with kernels 3.2 and 3.3, which work properly. I have noticed this delay/wait when using kernels 3.15, 3.16.
Any messages in the system log when this happens?
Regards, Clemens
Hi,
thanks for your availability. There is one message that appears in syslog, but it is always displayed when I test with aplay, unregarding the kernel version. It shows both with the working kernel (3.2) and with the problematic one (3.16).
--> with kernel 3.2.0-4-686-pae /var/log/syslog ... kernel: [ 2829.369380] 2:1:1: cannot get freq at ep 0x2 ...
--> with kernel 3.16-0.bpo.2-686-pae /var/log/syslog ... kernel: [ 199.353227] usb 2-1: 1:1: cannot get freq at ep 0x2 ...
Bogdan
On 11/11/2014 02:32 PM, Clemens Ladisch wrote:
Bogdan Veringioiu wrote:
The issue I am experiencing is a ~4 seconds delay in playing sound. I am reproducing the problem using aplay. The sound play is being delayed by more or less 4 seconds from the moment the file is sent to the card. I have tested with kernels 3.2 and 3.3, which work properly. I have noticed this delay/wait when using kernels 3.15, 3.16.
Any messages in the system log when this happens?
Regards, Clemens
Hi,
any idea on how to further debug this issue? Thanks, Bogdan
On 11/11/2014 03:06 PM, Bogdan Veringioiu wrote:
Hi,
thanks for your availability. There is one message that appears in syslog, but it is always displayed when I test with aplay, unregarding the kernel version. It shows both with the working kernel (3.2) and with the problematic one (3.16).
--> with kernel 3.2.0-4-686-pae /var/log/syslog ... kernel: [ 2829.369380] 2:1:1: cannot get freq at ep 0x2 ...
--> with kernel 3.16-0.bpo.2-686-pae /var/log/syslog ... kernel: [ 199.353227] usb 2-1: 1:1: cannot get freq at ep 0x2 ...
Bogdan
On 11/11/2014 02:32 PM, Clemens Ladisch wrote:
Bogdan Veringioiu wrote:
The issue I am experiencing is a ~4 seconds delay in playing sound. I am reproducing the problem using aplay. The sound play is being delayed by more or less 4 seconds from the moment the file is sent to the card. I have tested with kernels 3.2 and 3.3, which work properly. I have noticed this delay/wait when using kernels 3.15, 3.16.
Any messages in the system log when this happens?
Regards, Clemens
Bogdan Veringioiu wrote:
There is one message that appears in syslog, but it is always displayed when I test with aplay, unregarding the kernel version.
--> with kernel 3.2.0-4-686-pae kernel: [ 2829.369380] 2:1:1: cannot get freq at ep 0x2
--> with kernel 3.16-0.bpo.2-686-pae kernel: [ 199.353227] usb 2-1: 1:1: cannot get freq at ep 0x2
This indicates a bug in the device's firmware.
The timeout for control messages was increased from 100 ms to 1000 ms in kernel 3.3.
Regards, Clemens
Thank you very much. Your insight was helpful. Indeed the wait is caused by the timeout in control messages. The timeout is now (kernels 3.15, 3.16) set according with the global timeout defined in usb.h (5 seconds):
-->linux/usb.h #define USB_CTRL_GET_TIMEOUT 5000 #define USB_CTRL_SET_TIMEOUT 5000
-->sound/usb/helper.c if (requesttype & USB_DIR_IN) timeout = USB_CTRL_GET_TIMEOUT; else timeout = USB_CTRL_SET_TIMEOUT; err = usb_control_msg(dev, pipe, request, requesttype, value, index, buf, size, timeout);
so, this explains the 5 seconds delay.
In kernel 3.2, the timeout in helper.c was 1 second (hardcoded):
-->sound/usb/helper.c err = usb_control_msg(dev, pipe, request, requesttype, value, index, buf, size, 1000);
this explains the faster response in older kernels.
The timeout is received when reading the sample rate from the device, and then the error message "cannot get freq..." is displayed in syslog.
I have modified the timeout (reverted to 1 second) as a test in the new kernel and recompiled the module, the result was as expected, faster response.
I will contact the manufacturer to ask about this problem.
Thank you again. Bogdan
On 11/12/2014 03:36 PM, Clemens Ladisch wrote:
Bogdan Veringioiu wrote:
There is one message that appears in syslog, but it is always displayed when I test with aplay, unregarding the kernel version.
--> with kernel 3.2.0-4-686-pae kernel: [ 2829.369380] 2:1:1: cannot get freq at ep 0x2
--> with kernel 3.16-0.bpo.2-686-pae kernel: [ 199.353227] usb 2-1: 1:1: cannot get freq at ep 0x2
This indicates a bug in the device's firmware.
The timeout for control messages was increased from 100 ms to 1000 ms in kernel 3.3.
Regards, Clemens
participants (2)
-
Bogdan Veringioiu -
Clemens Ladisch