USB DAC dropouts/glitches

[DBMandrake]

Hi,

I'm testing a Behringer U-Phoria UMC204HD USB sound interface with my Pi 2B running the latest version of Volumio and I'm experiencing random glitches/dropouts in the sound which after some investigation I suspect may be related to USB packet loss or timing - issues that have been looked at in the past for the Pi.

The interface supports up to 192Khz 24bit with 4 output channels, however I'm seeing the same symptoms down at 44Khz 16 bit - which is a pop or momentary dropout in the audio at random roughly every 3 to 10 seconds, whether playing audio via Volumio or directly using aplay from the command line. The sample rate makes very little difference to the frequency of occurance of the pops and clicks.

I've already experimented with the various dwc options discussed elsewhere and nothing seems to make much difference - the only one that made some difference was dwc_otg.speed=1 to disable hi-speed mode, which did significantly reduce the frequency of the glitches but did not eliminate them, and of course that is not a viable solution since it affects Ethernet speed etc...

These are the current cmdline options and kernel version used by Volumio that I am testing with:

splash quiet plymouth.ignore-serial-consoles dwc_otg.lpm_enable=0 dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0x3 console=serial0,115200 kgdboc=serial0,115200 console=tty1 imgpart=/dev/mmcblk0p2 imgfile=/volumio_current.sqsh elevator=noop rootwait smsc95xx.turbo_mode=N bootdelay=5 logo.nologo vt.global_cursor_default=0 loglevel=0

Linux version 4.9.36-v7+ (dc4@dc4-XPS13-9333) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611) ) #1015 SMP Thu Jul 6 16:14:20 BST 2017

For a comparison I installed the Cubox version of Volumio on a dual core Cubox-i that I have which is a comparable speed to a Pi 3, (so a bit faster than my Pi 2) and the interface works perfectly with both Volumio and aplay with no dropouts whatsoever, so I think this rules out a problem with the interface being supported properly in Linux on arm devices.

Here is the output from lsusb:

lsusb.txt

If there is anything else I can do to test or help debug this please let me know.

[DBMandrake]

After further reading I think I may be affected by the problem described in this issue:

#2134

I will attempt to build a custom version of Volumio with the very latest kernel (rpi-update cannot be used) to see if it fixes the problem as even the latest dev build of volumio is only 4.9.41 - shown to be bad in issue 2134.

[DBMandrake]

I've now tested a 4.9.51-v7+ kernel hoping that the timer fix for isochronous transfer in 43 described above would be the solution but unfortunately it doesn't fix this issue.

The severity of the problem seems to be reduced by about half - with a 36 or 41 kernel I get on about 6 dropouts per minute which audibly last probably 1/10th of a second, with the 51 kernel I am seeing maybe 3 dropouts per minute and they don't "sound" as bad, but they are definitely still there and the audio is not bit perfect or glitch free, and can easily be heard on a sinewave test signal played using aplay.

Is there any further testing or debugging I can do to get to the bottom of this issue or at least prove whether it is a hardware limitation or still potentially fixable in software ?

[DBMandrake]

More testing and some interesting conclusions. First of all this problem is not fixed by newer kernels and doesn't seem to be related to the timer fix in issue #2134, unfortunately. I can reproduce the same problem with 4.9.36, 4.9.41 and 4.9.51 with very little difference contrary to what I said above.

I found that when I tested on a fresh install of Raspbian I was not experiencing audio glitches using aplay. at either 44.1Khz 16 bit or 96Khz 16 bit.

I then tried to narrow down what was different between Raspbian and Volumio. It turns out that the main Volumio service - which is a node js server for the web interface, when running leads to glitches/dropouts in the audio. When I stop that service the glitches almost entirely stop although I can still reproduce a very occasional glitch with it stopped, maybe once every 2-3 minutes, instead of every few seconds when it is running.

Nodejs is using very little CPU time (under 10%) when the web interface is idle yet still causes pretty bad sound glitches. If I renice nodejs to a low priority or aplay to a high priority it makes no difference at all, which suggests its not aplay being starved for CPU time. (aplay never reports any underruns anyway)

I experimented with the snd-usb-audio nrpacks module option - no change at all. I also experimented with every buffer related alsa configuration setting - no improvement. Finally I tried dwc_otg.speed=1 to disable USB2.0 support and the symptoms are gone - absolutely no glitches or dropouts in about an hour of testing on test signals and music, despite nodejs running as before.

So something the nodejs service is doing is causing issues with USB2.0 transmission - perhaps certain syscalls that it is calling are disabling interrupts for a long time, or the syscalls are just taking too long to return leading to the kernel missing a time critical USB transmission.

Perhaps a realtime kernel would help here. I would add that this sound interface is USB2.0 (but also supports fallback to USB1.1) so I don't think this relates to the fiq fixes from the last few years ?

Is there anything I can do to improve the USB 2.0 performance to avoid dropouts in the audio or am I stuck using USB1.1 as a workaround ?

[P33M]

Hello.

From an examination of your lsusb listing, the audio device is a high-speed device. The descriptors for the isochronous OUT endpoints (i.e. audio streams) also specify a bInterval of 1 which means a packet transfer every microframe - this is a particularly strenuous requirement for the Pi as it means the maximum hardware interrupt latency tolerable is <125uS.

The FIQ code attempts to improve matters by performing batches of transfers, but it can only perform as many transfers as the submitted URB requests - at the boundary where URBs are returned/the next one queued, control is passed to the IRQ-driven driver so there's a window of vulnerability where a latency spike could cause frame slippage.

dwc_otg.speed=1 will increase the hardIRQ latency tolerance to 1ms as that's the frame interval at full-speed. It's no surprise that the glitches disappear when clobbering the bus speed.

The issue described above should cause at most momentary audio dropouts (typically less than 1ms) but this is a function of how the USB device behaves when presented with an underrun condition (i.e. missing data). Can you capture a typical output stream via line-out -> recording device (e.g. line-in on a PC or similar) and upload the wav somewhere?

What's puzzling is the apparent difference between running a "heavy" userspace application (which should have negligible effect on hardIRQ latency) and plain aplay.

[popcornmix]

@P33M one thing @DBMandrake mentioned to me was strace showed node js doing a number of cacheflush operations. It does make use of JIT and so is likely triggering instruction/data cache flushes in the kernel.
I wonder whether there is any disabling of interrupts when that occurs? (or otherwise harming of interrupt latency)

[DBMandrake]

From an examination of your lsusb listing, the audio device is a high-speed device. The descriptors for the isochronous OUT endpoints (i.e. audio streams) also specify a bInterval of 1 which means a packet transfer every microframe - this is a particularly strenuous requirement for the Pi as it means the maximum hardware interrupt latency tolerable is <125uS.

That makes sense. This interface is designed for home recording studio use and as such minimising round trip latency from record to playback is a key factor in it's design, possibly at the expense of not being as "easy" to drive by the host OS.

The problem felt like a latency to me issue as well - the glitches don't seem particularly worse if I play 96Khz 24bit (which I believe is sent as 32bit to the card) than if I send 44.1Khz 16 bit, suggesting it wasn't a throughput issue.

The issue described above should cause at most momentary audio dropouts (typically less than 1ms) but this is a function of how the USB device behaves when presented with an underrun condition (i.e. missing data). Can you capture a typical output stream via line-out -> recording device (e.g. line-in on a PC or similar) and upload the wav somewhere?

Yes I can can make some recordings for you, I should be able to do this tomorrow. The severity varies from a small "click" that you can only hear on a simple and uncluttered test signal like a sine wave (but not easily in music) all the way to a loud "pop" that is easily heard during music.

Even if the click was subtle though, any glitch or dropout does defeat the purpose of trying to set up bit perfect playback from a high quality DAC.

What's puzzling is the apparent difference between running a "heavy" userspace application (which should have negligible effect on hardIRQ latency) and plain aplay.

Yes it is very puzzling - when I identified nodejs as the application that was placing the problematic "load" on the system (stopping the service eliminated 99% of the symptoms) I spent a few hours trying to figure out why.

I found it didn't seem to be just raw CPU use that was causing the issue, as adjusting relative priority of the nodejs service (which is a parent thread and 3-4 worker threads) and aplay made absolutely no difference, and I was still getting glitches even when nodejs was mostly "idle". (less than 5% CPU use)

Also other high cpu loads that I tried putting on the system were not causing trouble. Memory use also wasn't an issue as the service is using about 200MB of ram and the system is not using swap and has plenty of free ram.

I concluded that if it was causing this problem with such low cpu use even at low scheduling priority it must be making system call(s) that were somehow harming interrupt response time so I decided to strace the parent nodejs process and as popcornmix says I noticed there were a lot of cacheflush calls being made, especially soon after the service was started. (When audio glitches were even worse still)

The cacheflush calls might be a red herring, but it was the only thing that jumped out at me and seemed like something worth following up.

It's possible the problem isn't even in the USB driver at all but somewhere else in the kernel where some user space accessible system call(s) are doing something that is hurting interrupt response times or maybe even causing driver interrupts to be missed altogether ?

[DBMandrake]

As promised here are some recordings of the problem made using audacity via line input, they are in 192Kbit 32 bit float wav format, uncompressed. This is a 20Hz sinewave - low enough in frequency that it won't be heard on most speakers/headphones but the resulting clicks will be.

The first one was made after volumio had been booted for a while and was largely "idle". cpu use of nodejs at this point is under 10%:

https://drive.google.com/open?id=0B5qpN5dK9MKjdWc4Y2F2SmlDNTA

Clicking is more subtle and I count roughly 6 glitches over 30 seconds. I measured a couple in Audacity and they were about 0.4ms long, but because the amplitude jumps back to near zero it makes it quite audible.

This second recording was started while the nodejs service was stopped, and then the service was started at about 5 seconds into the recording, with symptoms much more severe as a lot more work is being done by the service including setting up child threads:

https://drive.google.com/open?id=0B5qpN5dK9MKjOURST3VfWUdEVHM

It takes a few seconds but it starts crackling badly between 16 and 22 seconds. I measured one dropout at about 17.7 seconds that lasts a full 8ms, which suggests something is very wrong.

Here is the original test file I'm playing with aplay:

https://drive.google.com/open?id=0B5qpN5dK9MKjbkhhdTFfdHNzbDg

Most of the dropouts appear to be the sample simply dropping to near zero for the duration then returning to where it should be, but I did see at least one dropout in the second file where you can see from the sinewave that time sync has been lost altogether and the sample has been "delayed", at about 17.79 seconds.

Just to try to rule out cpu hogging I repeated the test again with the nodejs service niced to 19 and it was no better, if anything it was worse: (although there is a lot of random variation from test to test)

https://drive.google.com/open?id=0B5qpN5dK9MKjTXh4Nk5YWGxCMkE

In this last one I see a 3ms dropout where the time sync seems to have slipped at 16.38s although most of the glitches are about 0.5ms in length. Here is a screen grab from that area:

Hopefully these files are useful to help at least classify the nature of the problem - if you need any more testing done please let me know.

[musicwonder]

Hi there, we are happy to find this thread. In short: We have the same problem with the ARM architecture. We tried:

• Hardware: Raspberry Pi 3, Asus Tinker Board
• Software: Raspbian, Volumio, Armbian, Ubuntu Mate

All the hints we found in lots of forums didn't help, but
It WORKS on:

• Hardware: UP Board with Atom Processor, PC Mainboards
• Software: Linux Mint

So it's clear that there must be a timing / time slice issue with the isochronous data streams on ARM devices.

[P33M]

@musicwonder Can you confirm which USB controller the DAC is connected to on the tinker board?

A lsusb -t will tell you.

[DBMandrake]

So it's clear that there must be a timing / time slice issue with the isochronous data streams on ARM devices.

It's not actually all arm devices. While this problem is being looked into I've been running Volumio on a dual core Cubox-i (imx6 arm architecture) and I have absolutely zero problems with glitches or dropouts with this USB interface even when the box is under heavy load. Unfortunately the Cubox-i build of Volumio is older than the Pi build and not kept as up to date by the developers (new versions are always released for the Pi first) so I would prefer to run the Pi version if the problem can be solved satisfactorily.

I've also tried this Behringer interface on a Vero4k (Amlogic S905X arm chipset) and there are no glitches there either, although to be fair this is much faster hardware than a Pi so is not a fair comparison, and there are no Volumio builds available for it. (I tested with both Kodi and aplay)

[musicwonder]

@P33M: It happens at each of the 4 USB Ports.

[P33M]

I've been toying with the idea of adding low-key profiling to the dwc_otg driver - it's possible to get reliable indication that you're missing interrupts (FIQ->IRQ latency being too big, for example).

Unfortunately time is tight at the moment so it will be a while before I can look at this.

[musicwonder]

Is there a chance that the issue is gone with a rt-kernel? If so, I would it give a try.

[DBMandrake]

Unfortunately time is tight at the moment so it will be a while before I can look at this.

No problem - meanwhile I am using it on my Cubox, when you get a chance to look at it I'll be around to do any testing required.

[musicwonder]

No I have made a test with an orange pi pc2 with armbian 4.13. Same issue but less often. One dropout per 1-4 minutes. Why only arm devices?