Sound Drops / Frequency Change

Core Machine (Operating system/System info/Roon build number)

Roon Bridge: RPi 3 B+

**$** cat /etc/os-release
PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
NAME="Raspbian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster
ID=raspbian
ID_LIKE=debian

$ cat /proc/asound/version
Advanced Linux Sound Architecture Driver Version k4.19.55-v7+.

Version 1.0 (build 169) stable
Roon Core:
Macbook Pro
macOS Catalina (10.15 Beta (19A487m)

Roon Version 1.6(build 416) stable (64bit)

Network Details (Including networking gear model/manufacturer and if on WiFi/Ethernet)

Wifi

Audio Devices (Specify what device you’re using and its connection type - USB/HDMI/etc.)

USB/ALSA/PureAudio Lotus DAC5

Description Of Issue

$ tail -f /var/log/syslog
Jun 25 20:01:17 raspberrypi kernel: [ 3404.889444] usb 1-1.1.3: 1:1: cannot set freq 44100 (v2/v3): err -110

$ cat RAATServer_log.txt
06/25 20:01:18 Error: [RAAT::Lotus DAC5] error in snd_pcm_hw_params: Protocol error (-71)
06/25 20:01:18 Warn: [RAAT::Lotus DAC5] [lua@0x7330692c] [192.168.1.19:49878] setup failed: RAAT__OUTPUT_PLUGIN_STATUS_FORMAT_NOT_SUPPORTED
06/25 20:01:18 Trace: [RAAT::Lotus DAC5] [lua@0x7330692c] [192.168.1.19:49878] SENT [11] {"status":"UnexpectedError","message":"RAAT__OUTPUT_PLUGIN_STATUS_FORMAT_NOT_SUPPORTED"}
06/25 20:01:18 Trace: [RAAT::Lotus DAC5] [lua@0x7330692c] [192.168.1.19:49878] GOT [12] {"request":"setup","format":{"sample_type":"pcm","sample_rate":44100,"bits_per_sample":32,"channels":2,"sample_subtype":"none"}}
06/25 20:01:18 Trace: [RAAT::Lotus DAC5] alsa output setup: format is pcm 44100/32/2
06/25 20:01:18 Trace: [RAAT::Lotus DAC5] opening [hw:CARD=DAC5,DEV=0] 44100/32/2
06/25 20:01:18 Trace: [RAAT::Lotus DAC5] prefer larger samples = 0
06/25 20:01:18 Trace: [RAAT::Lotus DAC5] [ALSA] [hw:CARD=DAC5,DEV=0] using hw pcmformat S32_LE bitspersample 32
06/25 20:01:18 Trace: [RAAT::Lotus DAC5] [ALSA] [hw:CARD=DAC5,DEV=0] Requesting 2 periods
06/25 20:01:18 Trace: [RAAT::Lotus DAC5] [ALSA] [hw:CARD=DAC5,DEV=0] Requesting 1764 frames/buffer (882 frames/period)
06/25 20:01:18 Trace: [RAAT::Lotus DAC5] [ALSA] [hw:CARD=DAC5,DEV=0] Initialized with 2 periods with 882 frames/period and 1764 frames/buffer
06/25 20:01:18 Error: [RAAT::Lotus DAC5] error in snd_pcm_hw_params: Protocol error (-71)
06/25 20:01:18 Warn: [RAAT::Lotus DAC5] [lua@0x7330692c] [192.168.1.19:49878] setup failed: RAAT__OUTPUT_PLUGIN_STATUS_FORMAT_NOT_SUPPORTED
06/25 20:01:18 Trace: [RAAT::Lotus DAC5] [lua@0x7330692c] [192.168.1.19:49878] SENT [12] {"status":"UnexpectedError","message":"RAAT__OUTPUT_PLUGIN_STATUS_FORMAT_NOT_SUPPORTED"}
06/25 20:01:19 Trace: [RAAT::Lotus DAC5] [lua@0x7330692c] [192.168.1.19:49878] GOT [13] {"request":"setup","format":{"sample_type":"pcm","sample_rate":44100,"bits_per_sample":32,"channels":2,"sample_subtype":"none"}}
06/25 20:01:19 Trace: [RAAT::Lotus DAC5] alsa output setup: format is pcm 44100/32/2
06/25 20:01:19 Trace: [RAAT::Lotus DAC5] opening [hw:CARD=DAC5,DEV=0] 44100/32/2
06/25 20:01:19 Trace: [RAAT::Lotus DAC5] prefer larger samples = 0
06/25 20:01:19 Trace: [RAAT::Lotus DAC5] [ALSA] [hw:CARD=DAC5,DEV=0] using hw pcmformat S32_LE bitspersample 32
06/25 20:01:19 Trace: [RAAT::Lotus DAC5] [ALSA] [hw:CARD=DAC5,DEV=0] Requesting 2 periods
06/25 20:01:19 Trace: [RAAT::Lotus DAC5] [ALSA] [hw:CARD=DAC5,DEV=0] Requesting 1764 frames/buffer (882 frames/period)
06/25 20:01:19 Trace: [RAAT::Lotus DAC5] [ALSA] [hw:CARD=DAC5,DEV=0] Initialized with 2 periods with 882 frames/period and 1764 frames/buffer
06/25 20:01:19 Error: [RAAT::Lotus DAC5] error in snd_pcm_hw_params: Protocol error (-71)
06/25 20:01:19 Warn: [RAAT::Lotus DAC5] [lua@0x7330692c] [192.168.1.19:49878] setup failed: RAAT__OUTPUT_PLUGIN_STATUS_FORMAT_NOT_SUPPORTED
06/25 20:01:19 Trace: [RAAT::Lotus DAC5] [lua@0x7330692c] [192.168.1.19:49878] SENT [13] {"status":"UnexpectedError","message":"RAAT__OUTPUT_PLUGIN_STATUS_FORMAT_NOT_SUPPORTED"}
06/25 20:01:20 Trace: [RAAT::Lotus DAC5] [lua@0x7330692c] [192.168.1.19:49878] GOT [14] {"request":"setup","format":{"sample_type":"pcm","sample_rate":44100,"bits_per_sample":32,"channels":2,"sample_subtype":"none"}}
06/25 20:01:20 Trace: [RAAT::Lotus DAC5] alsa output setup: format is pcm 44100/32/2
06/25 20:01:20 Trace: [RAAT::Lotus DAC5] opening [hw:CARD=DAC5,DEV=0] 44100/32/2
06/25 20:01:20 Trace: [RAAT::Lotus DAC5] prefer larger samples = 0
06/25 20:01:20 Trace: [RAAT::Lotus DAC5] [ALSA] [hw:CARD=DAC5,DEV=0] using hw pcmformat S32_LE bitspersample 32
06/25 20:01:20 Trace: [RAAT::Lotus DAC5] [ALSA] [hw:CARD=DAC5,DEV=0] Requesting 2 periods
06/25 20:01:20 Trace: [RAAT::Lotus DAC5] [ALSA] [hw:CARD=DAC5,DEV=0] Requesting 1764 frames/buffer (882 frames/period)
06/25 20:01:20 Trace: [RAAT::Lotus DAC5] [ALSA] [hw:CARD=DAC5,DEV=0] Initialized with 2 periods with 882 frames/period and 1764 frames/buffer
06/25 20:01:20 Error: [RAAT::Lotus DAC5] error in snd_pcm_hw_params: Protocol error (-71)
06/25 20:01:20 Warn: [RAAT::Lotus DAC5] [lua@0x7330692c] [192.168.1.19:49878] setup failed: RAAT__OUTPUT_PLUGIN_STATUS_FORMAT_NOT_SUPPORTED
06/25 20:01:20 Trace: [RAAT::Lotus DAC5] [lua@0x7330692c] [192.168.1.19:49878] SENT [14] {"status":"UnexpectedError","message":"RAAT__OUTPUT_PLUGIN_STATUS_FORMAT_NOT_SUPPORTED"}
06/25 20:01:20 Trace: [RAAT::Lotus DAC5] [lua@0x7330692c] [192.168.1.19:49878] GOT [15] {"request":"setup","format":{"sample_type":"pcm","sample_rate":44100,"bits_per_sample":32,"channels":2,"sample_subtype":"none"}}
06/25 20:01:20 Trace: [RAAT::Lotus DAC5] alsa output setup: format is pcm 44100/32/2
06/25 20:01:20 Trace: [RAAT::Lotus DAC5] opening [hw:CARD=DAC5,DEV=0] 44100/32/2
06/25 20:01:20 Trace: [RAAT::Lotus DAC5] prefer larger samples = 0
06/25 20:01:20 Trace: [RAAT::Lotus DAC5] [ALSA] [hw:CARD=DAC5,DEV=0] using hw pcmformat S32_LE bitspersample 32
06/25 20:01:20 Trace: [RAAT::Lotus DAC5] [ALSA] [hw:CARD=DAC5,DEV=0] Requesting 2 periods
06/25 20:01:20 Trace: [RAAT::Lotus DAC5] [ALSA] [hw:CARD=DAC5,DEV=0] Requesting 1764 frames/buffer (882 frames/period)
06/25 20:01:20 Trace: [RAAT::Lotus DAC5] [ALSA] [hw:CARD=DAC5,DEV=0] Initialized with 2 periods with 882 frames/period and 1764 frames/buffer

This workaround works:

pi@raspberrypi:~ $ lsusb -t
/:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=dwc_otg/1p, 480M
    |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/4p, 480M
        |__ Port 1: Dev 13, If 0, Class=Hub, Driver=hub/3p, 480M
            |__ Port 1: Dev 15, If 0, Class=Vendor Specific Class, Driver=lan78xx, 480M
            |__ Port 3: Dev 14, If 0, Class=Audio, Driver=snd-usb-audio, 480M
            |__ Port 3: Dev 14, If 1, Class=Audio, Driver=snd-usb-audio, 480M
            |__ Port 3: Dev 14, If 2, Class=Application Specific Interface, Driver=, 480M
            |__ Port 3: Dev 14, If 3, Class=Human Interface Device, Driver=usbhid, 480M
pi@raspberrypi:~ $ usbreset
Usage:
  usbreset PPPP:VVVV - reset by product and vendor id
  usbreset BBB/DDD   - reset by bus and device number
  usbreset "Product" - reset by product name

Devices:
  Number 001/013  ID 0424:2514  
  Number 001/002  ID 0424:2514  
  Number 001/014  ID 16d0:eca1  Lotus DAC5
  Number 001/015  ID 0424:7800  
pi@raspberrypi:~ $ sudo usbreset 001/002
Resetting  ... ok
pi@raspberrypi:~ $

Hi @Shawn_Kernes,

Can you please provide some more information as to the issue?

  • Do lower sample rates work as expected?
  • When exactly does this behavior occur, only when the sample rate is being switched or regardless of the previous sample rate?
  • How exactly is the sound dropping, is there a stutter or does it completely stop?
  • Are you using the newest firmware version on the Lotus?
  • Have you tried a different USB cable?
  • Is the behavior the same if you bypass the RPi and connect the DAC directly to the Core?

Hi @noris, thanks for looking into this.

  • Do lower sample rates work as expected?
    All sample rates seem work fine most of the time, the issue seems to occur somewhat randomly, but most frequently on sample rate change.

  • When exactly does this behavior occur, only when the sample rate is being switched or regardless of the previous sample rate?
    I thought it was only when the sample rate changed, but it appears it may also occur at other times, i’m going to be listening more tonight and may be able to get more specific.

  • How exactly is the sound dropping, is there a stutter or does it completely stop?
    sound stops completely, rooncore shows that it starts moving down the track queue quickly after that (without playing the songs).

  • Are you using the newest firmware version on the Lotus?
    I don’t believe there have been any firmware updates released for the lotus DAC5.

  • Have you tried a different USB cable?
    I have tried different cables, DAC’s, RPi’s, and RPi power supplies just for good measure, same thing happens in every scenario.

  • Is the behavior the same if you bypass the RPi and connect the DAC directly to the Core?
    It works fine when DAC is connected directly to the rooncore.

Here are a couple other examples from /var/log/syslog:

Jun 25 13:21:37 raspberrypi kernel: [12258.800915] usb 1-1.1.3: 1:1: cannot set freq 44100 (v2/v3): err -110

Jun 25 20:01:17 raspberrypi kernel: [ 3404.889444] usb 1-1.1.3: 1:1: cannot set freq 44100 (v2/v3): err -110

Jun 25 20:40:51 raspberrypi kernel: [ 1288.319039] usb 1-1.1.3: 1:1: cannot set freq 48000 (v2/v3): err -110

Around these timestamps there is nothing but the usual TLS warning that happens all the time in the RoonBridge_log.

the RAATServer log is where most of the key info seems to be, id be happy to send it over.

Hi @Shawn_Kernes,

Thank you for providing that additional info. I would like to try a test here to see if you can get back into this state at will. Can I please ask you to try to enable and disable volume leveling when this issue is not present and see if this triggers the behavior?

Thanks @noris.

Ill try the volume leveling test when i get a chance.

In the meantime, i have had limited time to test, but it looks like todays firmware build from rpi-update may have solved the problem (i reported the issue to rpi as well as roon)…

@noris

I stand corrected… When i turn volume leveling on and mess around with target volume level and volume adjustment when loudness is unknown i still end up in the state when i need to usbreset 001/002.

Hi @Shawn_Kernes,

Thank you for trying the volume leveling test. I would like to get a clean set of logs from this test and ask the technical team to take a look. With this in mind can I ask you to:

  • Have all DSP disabled and Volume Leveling turned off

  • Start playback of a track when the system is working as expected, and note the exact local time that the track started (e.g. 12:43PM on 6/28/19)

  • Try turning volume leveling on and note the exact local time when you did this

  • If the DAC got into the broken state, note the exact local time when this occurred

  • If the DAC is still working as expected, turn off volume leveling and note the time again

  • Check to see if the DAC is still working working as expected, if not, note the time as before

  • Manually send me both your Roon App logs and your RAATServer logs via Dropbox / Google Drive / Send.firefox.com

Can you clarify on what the exact solution is when the DAC is in this state? Do you power cycle the DAC to get it to start working again, reboot the Core, power cycle the RPi itself or just power cycle the RPi USB ports? Do any of the other methods above re-establish connectivity or is it just one of these methods?

Hey @noris,
Ill try to run those tests and send the files when i get home tonight… You probably also want the syslog as well.

Just as a reminder, this problem only occurs when running the latest version of raspbian with the latest raspberry pi firmware installed… the stuff that was just recently released in order to add support for the RPi 4B.

My test system setup was:

  1. RPi 3 B+ (one that i have been using for the last 6 months or so).
  2. new 16 gb SD card
  3. Copy the latest version of noobs onto the SD card
  4. Choose to install raspbian from the list (which now installs raspbian 10 - Buster).
  5. make sure everything is updated (apt-get update, upgrade, dist-upgrade, autoclean)
  6. install roonbridge using “roonbridge-installer-linuxarm7hf.sh”

Everything still works fine using an SD card with raspbian 9 on it.

To be clear, the DAC itself never ends up in a bad state. I haven’t dug into it extensively myself, but the problem appears to be related to either the new firmware, the buster kernel, the alsa library, or some combination of those when interacting with roonbridge.

There is no reason to reboot the core, although that does also work… i didnt try power cycling the dac… simply resetting the USB bridge using usbreset (or another method) works fine.

Hi @Shawn_Kernes,

Thanks for the test setup info and for clarification on how to exit this state. If you have had a chance to test further and have any new observations, or can send the logs it might be helpful in tracking it down further.

I haven’t had a chance to mess with it anymore. But as i mentioned before, i have been able to replicate with a couple of new SD cards and a fresh install…

as of right now, this issue will prevent anyone who get the new RPi 4B and runs raspbian from having a good experience with roonbridge.

Sounds like the XMOS usb bug to me as this is exactly the same behaviour.

@CrystalGipsy, thanks… I submitted the issue to the raspberry pi firmware group before submitting here, but there has been no movement yet.

the issue affects all RPi 4b’s, as well as older RPi’s with the latest firmware… i figured Roon would have a vested interest driving this forward.

FYI… im still testing, but the issue when toggling on and off volume leveling seems to be gone in this-mornings pre-release firmware update.

Hi @Shawn_Kernes,

Thanks for the update here! Can you please let me know which pre-release firmware you installed on the Rasberry Pi? Has the system still been stable in the past few days following the firmware update?

This topic was automatically closed 365 days after the last reply. New replies are no longer allowed.