RPi audio output timing is inconsistent with USB audio device

[John Langner]

RPi audio output timing is inconsistent with USB audio device.
--------------------------------------------------------------

Background:
-----------

A certain application turns on a radio transmitter,
sends some audio from a modem, and turns the transmitter off again.

It has occasionally been reported that there is sometimes an inconsistent substantial
delay between the transmitter being turned on and the start of the audio.

In my testing I found that the timing delay problem only occurs with a USB audio adapter
connected to a Raspberry Pi. The problem does not occur using the builtin audio
device on the RPi. The problem does NOT occur when using a USB audio adapter
on an x86 desktop.

Rather than opening and closing the audio output device for each transmission,
it opens the device once when the application starts up.
Between transmissions, the audio output device is allowed to have data underrun.
When it time for the next transmission, it should be brought back into
running mode with snd_pcm_prepare.

Test case:
----------

The enclosed test case has a small part of the original application trimmed
down to a managable size to demonstrate this problem. Do the following:

 git clone https://github.com/wb2osz/rpi-usb-audio-bug
 cd rpi-usb-audio-bug
 make

My results were with a model 3B (not +) and Raspbian stretch with all the
most recent updates as of Feb. 10, 2019.

To run the test, you will need a USB audio adapter such as one of these:

 https://www.adafruit.com/product/1475
  (Generalplus Technology Inc. 1b3f 2008)
 https://www.amazon.com/external-Adapter-Windows-Microphone-SD-CM-UAUD/dp/B001MSS6CS
  (CMedia CM119 0d8c 0008)

The particular chip inside, CMedia or other, does not seem to matter.

If nothing special is done, the built in audio output shows up as card 0
and the USB adapter is card 1:

 aplay -l
 **** List of PLAYBACK Hardware Devices ****
 card 0: ALSA [bcm2835 ALSA], device 0: bcm2835 ALSA [bcm2835 ALSA]
   Subdevices: 7/7
   Subdevice #0: subdevice #0
   Subdevice #1: subdevice #1
   Subdevice #2: subdevice #2
   Subdevice #3: subdevice #3
   Subdevice #4: subdevice #4
   Subdevice #5: subdevice #5
   Subdevice #6: subdevice #6
 card 0: ALSA [bcm2835 ALSA], device 1: bcm2835 ALSA [bcm2835 IEC958/HDMI]
   Subdevices: 1/1
   Subdevice #0: subdevice #0
 card 1: Device [C-Media USB Audio Device], device 0: USB Audio [USB Audio]
   Subdevices: 1/1
   Subdevice #0: subdevice #0

The enclosed test application demonstrates the very inconsistent results.

Run the enclosed test program with the card number as the command line argument.
e.g.

 ./bug 0 # for built in audio
 ./bug 1 # for USB audio adapter

This is what the test case does:

 - Wait some number of seconds then wait for the next second boundary.
 - Print the number of milliseconds after the second boundary. (should be 0)
 - Generate audio tone for a quarter of a second.
 - Wait for end of audio output (snd_pcm_drain)
 - Print number of milliseconds elapsed since the start of the tone.

If you watch the screen and listen, the tone will usually start when the 0 is printed.
The elapsed time is generally a little over 250, which is what you would expect for a
quarter second tone plus some latency and overhead.

Sometimes, there is a noticable delay between the 0 line being printed and start
of the sound. In this case we also see a much larger elapsed time.

The follwing files capture the results from different test conditions.

x86-usb.log x86 computer, usb audio, very consistent.

rpi-bcm.log RPi, bcm2835 audio out, also consistent.

rpi-usb-gt.log RPi, USB audio, Generalplus Technology, frequent long delays.

rpi-usb-119.log RPi, USB audio, CMedia CM119, frequent long delays.

The inconsistent behavior occurs only for a USB audio device on the RPi.

Observations:
-------------

The delays seem to be random at first but some interesting patterns
emerge.

- The problem is more likely to occur with an even number of seconds
  between the tones.

- The delays before the start of the tone are not entirely random.
  Numbers are often in a 1:2 ratio.

[Rysiek Labus (sq9mdd)]

I have a similar problem. I can not finish my raspberry pi project zero because of this.

[Maciej Zieliński (sq2ibk)]

I've got the same problem. Please help.

[Tomasz Zajdel (sq8jmd)]

Same problem here.

[Craig Lamparter (craigerl)]

Same here, up to a full second of delay before audio starts, happens at random. Roughly one third of all starts have the delay. Using cmedia USB audio dongle. Raspberry Pi3, Stretch image dated 11/13/18.

Symptom is not observed using Fe-Pi audio hat on a Raspberry Pi ZeroW.

Impact, as indicated in initial post, is significant in high-power packet radio applications, introducing dead air and polluting an already crowded frequency. Show-stopper for this application.

[Rysiek Labus (sq9mdd)]

Raspberry Pi 3 A+ also affected :(

[Paweł Muszyński (x98pl)]

I have the same problem on my Raspberry Pi Zero with Raspbian Stretch Lite (release 2019-04-08). I have to move my project to Orange Pi Zero with Armbian Bionic (mainline based kernel 4.19.y) where the problem doesn't occur.

[Jan (dj1an)]

Same Problem here.

[Sandy J (tonedev)]

I can confirm that I'm experiencing the same issue on a Pi Zero and the 3B+. Multiple USB audio devices have been tested and everything is up-to-date in regards to what's available on the Raspbian repos for the two devices.

[Matthew Annen (mpannen1979)]

Same unexpected, deficient behavior for me as well.

[Pander (pander)]

Can someone reproduce this on Buster please?

[John Langner (wb2osz)]

Thanks for taking a look at this.

The problem still exists with Buster on an RPi 3.
It has the latest updates as of today.
$ uname -a
Linux raspberrypi 4.19.57-v7+ #1244 SMP Thu Jul 4 18:45:25 BST 2019 armv7l GNU/Linux

One person, in a discussion group, reported that the problem does NOT exist with the RPi 4.
(i.e. the timing is correct. no extra delays of up to a second before the audio starts.)
I don't have an RPi 4 so I can't confirm that.

[Paweł Muszyński (x98pl)]

The bug still exists on Raspberry Pi Zero and Buster for kernel 4.19.58+ and 4.19.58+ and for even 4.19.66+ (after rpi-update).

[Craig Lamparter (craigerl)]

pi-zerow stretch, usb audio, same problem. Since Debian holds the radio transmit open, I've since had to switch to a pcm audio device (fe-pi hat), and stop using usb audio.

[Casey J. Davis (infinitepossibilities)]

Another data point. I have this problem on a Raspberry Pi 3B when using Ubuntu Server 18.04.3 LTS. Problem is not present on the same hardware when using Arch Linux ARMv7.

[Red Tuby (pe1rrr)]

Another data point:-

$ uname -a
Linux pe1rrr.ampr.org 4.19.97-v7+ #1294 SMP Thu Jan 30 13:15:58 GMT 2020 armv7l GNU/Linux

**** List of PLAYBACK Hardware Devices ****
card 0: Set [C-Media USB Headphone Set], device 0: USB Audio [USB Audio]
  Subdevices: 0/1
  Subdevice #0: subdevice #0

This is impacting almost anyone interested in setting up packet radio systems using the RPI3, as nearly all newbies are looking towards the very fine soundmodems such as direwolf and QtSoundModem that use serial or GPIO for keying the PTT on the radios.

 As of writing I can personally confirm that this issue does not occur on the Raspberry Pi4, but has been a persistent thorn in the foot ever since the RPI3 graced the packet scene (oof!).

There is a semi-working workaround:

This workaround is not 100%, sometimes a CM108 soundcard driver will get messed up somewhere along the way and cause timing errors in the packets themselves. However, it does eliminate the GPIO or Serial signal delay issues already mentioned in the original report, and works for the most part but isn't as I said 100%. YMMV.

Here is a method of "patching" direwolf to use aoss OSS ALSA bridge:

--------------------- snipped from a mailing list -------------------

David Ranch KI6ZHD has a walkthrough for the fix.

Following his walkthrough, here's what works for me on a new install of Raspian Buster, if everything else needed for the latest Direwolf 1.6 developer version is already installed (including cmake):

1. Uninstall any previous version of Direwolf, then:
2. sudo apt-get install alsa-oss
3. sudo nano /etc/modprobe.d/blacklist-bcm2835.conf
Add these two lines to that blacklist file, then save and close it:

blacklist snd_bcm2835
options snd-usb-audio index=0

4. reboot, then:
5. cd ~
6. git clone https://www.github.com/wb2osz/direwolf
7. cd direwolf
8. git checkout dev
9. mkdir build && cd build

10. Stop here but don't close Terminal. Text-edit the CMakeLists.txt file in the home/pi/direwolf directory.

11. Scroll down to around line# 255, to the line that says: find_package (ALSA REQUIRED)
12. delete only the word REQUIRED, then save and close the file.
13. Back in Terminal continue with:
14. cmake -DCMAKE_DISABLE_FIND_PACKAGE_ALSA=TRUE .. (don't forget to include the two ".." at the end)
15. make -j
16. sudo make install
17. make install-conf
18. Edit the direwolf.conf file so that all the ADEVICE lines are disabled. Add a line in that section: ADEVICE /dev/dsp0
19. After editing the rest of it for your particular setup, save and close the file, and run Direwolf from Terminal, preceded by "sudo aoss".
For example, I run mine with "sudo aoss direwolf -qd -T %H:%M:%S"

------------------- end of snip -----------------------

As people are coming back to the amateur radio hobby during the pandemic, there has been quite a few people getting stuck with this issue yet many are not following through with posting a report here, unfortunately that is how it is.