Allo USBridge, used to work great, now Roonbridge stream dies all the time

As the title says, I’ve been using a USBridge with DietPi for 2 years now, for the first 18 months it was great, would stream for days at a time from Roon, but the last six months no dice.

After a software update at some point, everything got super flaky. Flaky as in stream will always die within about 30mins to 5 hours. Roon core is a Mac Mini on ethernet, USBridge is ethernet as well. Already tried wiping the USBridge and starting fresh, but didn’t help.

Not sure where to look to troubleshoot, but I did check the /var/log/roon folder and the RAATServer_log.txt file had this after a recent stoppage. Started playback at timestamp 02/12 02:52:03, then it died at 02/12 03:21:51. Roon core is 192.168.1.20. Is there a log on the Roon core side I can check as well, or another log that would be better in DietPi? Thanks!

02/12 02:51:52 Trace: [jsonserver] [192.168.1.20:49358] accepted connection
02/12 02:51:52 Trace: [jsonserver] [192.168.1.20:49358] GOT[LL] [1] {"request":"enumerate_devices","subscription_id":"0"}
02/12 02:51:52 Trace: [jsonserver] [192.168.1.20:49358] SENT [1] [nonfinal] {"status": "Success", "devices": [{"device_id": "hw:CARD=atm7059link,DEV=0", "name": "atm7059_link", "type": "alsa"}, {"device_id": "hw:CARD=atm7059link,DEV=1", "name": "atm7059_link", "type": "alsa"},
02/12 02:51:52 Trace: [jsonserver] [192.168.1.20:49358] GOT[LL] [2] {"request":"enable_device","device_id":"hw:CARD=AUDIO,DEV=0","subscription_id":"1"}
02/12 02:51:52 Trace: [jsonserver] [192.168.1.20:49358] SENT [2] [nonfinal] {"status": "Success"}
02/12 02:51:52 Trace: [RAAT::SMSL USB AUDIO] [server] [192.168.1.20:49361] accepted connection
02/12 02:51:52 Trace: [RAAT::SMSL USB AUDIO] [session] [192.168.1.20:49361] created: 0xb3600548 (0xb3603fb0)
02/12 02:51:52 Trace: [RAAT::SMSL USB AUDIO] [server] new script with name=raat.dat:base.lua module=base
02/12 02:51:52 Trace: [RAAT::SMSL USB AUDIO] [session] [192.168.1.20:49361] pre-loading lua module base
02/12 02:51:52 Trace: [RAAT::SMSL USB AUDIO] [server] [192.168.1.20:49361] SENT[LL] [1] {"status": "Success"}
02/12 02:51:52 Trace: [RAAT::SMSL USB AUDIO] [server] new script with name=raat.dat:dkjson.lua module=dkjson
02/12 02:51:52 Trace: [RAAT::SMSL USB AUDIO] [session] [192.168.1.20:49361] pre-loading lua module dkjson
02/12 02:51:52 Trace: [RAAT::SMSL USB AUDIO] [server] new script with name=raat.dat:protocol.lua module=protocol
02/12 02:51:52 Trace: [RAAT::SMSL USB AUDIO] [session] [192.168.1.20:49361] pre-loading lua module protocol
02/12 02:51:52 Trace: [RAAT::SMSL USB AUDIO] [server] new script with name=raat.dat:roon_tcp.lua module=(null)
02/12 02:51:52 Trace: [RAAT::SMSL USB AUDIO] [session] [192.168.1.20:49361] executing lua script
02/12 02:51:52 Trace: [RAAT::SMSL USB AUDIO] [server] [192.168.1.20:49361] SENT[LL] [2] {"status": "Success"}
02/12 02:51:52 Trace: [RAAT::SMSL USB AUDIO] [server] [192.168.1.20:49361] SENT[LL] [3] {"status": "Success"}
02/12 02:51:52 Trace: [RAAT::SMSL USB AUDIO] [lua@0xb3608c6c] [192.168.1.20:49361]  [roon] clock socket listening on udp 0.0.0.0:57732
02/12 02:51:52 Trace: [RAAT::SMSL USB AUDIO] [lua@0xb3608c6c] [192.168.1.20:49361]  [roon] audio socket listening on tcp 0.0.0.0:34572
02/12 02:51:52 Trace: [RAAT::SMSL USB AUDIO] [lua@0xb3608c6c] [192.168.1.20:49361]  [roon] output info {"config": {"name": "SMSL USB AUDIO", "type": "alsa", "device": "hw:CARD=AUDIO,DEV=0", "dsd_mode": "native"}, "alsa_device": {"id": "AUDIO", "components": "AUDIO", "name": "S
02/12 02:51:52 Trace: [RAAT::SMSL USB AUDIO] [server] [192.168.1.20:49361] SENT[LL] [4] {"status": "Success"}
02/12 02:51:52 Trace: [RAAT::SMSL USB AUDIO] [lua@0xb3608c6c] [192.168.1.20:49361]  GOT [2] {"request":"info"}
02/12 02:51:52 Trace: [RAAT::SMSL USB AUDIO] [lua@0xb3608c6c] [192.168.1.20:49361]  SENT [2] {"flags":{"has_write_chmap":true},"info":{"unique_id":"8b256487-ed44-9315-a1f6-8d79d9e1c7de"},"transport":{"info":[],"is_supported":false},"status":"Success","volume":{"info":[],"is_su
02/12 02:51:52 Trace: [RAAT::SMSL USB AUDIO] [lua@0xb3608c6c] [192.168.1.20:49361]  GOT [3] {"request":"set_client_type","client_type":"Roon"}
02/12 02:51:52 Trace: [RAAT::SMSL USB AUDIO] [lua@0xb3608c6c] [192.168.1.20:49361]  SENT [3] {"status":"Success"}
02/12 02:51:52 Trace: [RAAT::SMSL USB AUDIO] [lua@0xb3608c6c] [192.168.1.20:49361]  GOT [4] {"request":"subscribe_transport"}
02/12 02:51:52 Trace: [RAAT::SMSL USB AUDIO] [lua@0xb3608c6c] [192.168.1.20:49361]  GOT [5] {"request":"subscribe_controls","controller_id":"c95fc2e4-1edf-404b-902f-bb9c7f2b5b6f"}
02/12 02:51:52 Trace: [RAAT::SMSL USB AUDIO] [lua@0xb3608c6c] [192.168.1.20:49361]  SENT [5] {"controls":[],"action":"Changed","status":"Success"}
02/12 02:52:02 Trace: [RAAT::SMSL USB AUDIO] [lua@0xb3608c6c] [192.168.1.20:49361]  GOT [6] {"request":"setup","format":{"sample_type":"pcm","sample_rate":768000,"bits_per_sample":32,"channels":2,"sample_subtype":"none"}}
02/12 02:52:02 Trace: [RAAT::SMSL USB AUDIO] alsa output setup: format is pcm 768000/32/2
02/12 02:52:02 Trace: [RAAT::SMSL USB AUDIO] opening [hw:CARD=AUDIO,DEV=0] 768000/32/2
02/12 02:52:02 Trace: [RAAT::SMSL USB AUDIO] prefer larger samples = 0
02/12 02:52:02 Trace: [RAAT::SMSL USB AUDIO] [ALSA] [hw:CARD=AUDIO,DEV=0] using hw pcmformat S32_LE bitspersample 32
02/12 02:52:02 Trace: [RAAT::SMSL USB AUDIO] [ALSA] [hw:CARD=AUDIO,DEV=0] Requesting 2 periods
02/12 02:52:02 Trace: [RAAT::SMSL USB AUDIO] [ALSA] [hw:CARD=AUDIO,DEV=0] Requesting 30720 frames/buffer (15360 frames/period)
02/12 02:52:02 Trace: [RAAT::SMSL USB AUDIO] [ALSA] [hw:CARD=AUDIO,DEV=0] Initialized with 2 periods with 15360 frames/period and 30720 frames/buffer
02/12 02:52:02 Trace: [RAAT::SMSL USB AUDIO] sched_setscheduler succeeded
02/12 02:52:02 Trace: [RAAT::SMSL USB AUDIO] samples per buf 15360 ns per buf 20000000 samplerate 768000
02/12 02:52:02 Trace: [RAAT::SMSL USB AUDIO] 15360 samples per buf, 122880 bytes per buf, 122880 bytes per hwbuf
02/12 02:52:02 Trace: [RAAT::SMSL USB AUDIO] [output/alsa] [hw:CARD=AUDIO,DEV=0] waiting for device to be ready
02/12 02:52:02 Trace: [RAAT::SMSL USB AUDIO] [output/alsa] [hw:CARD=AUDIO,DEV=0] device is ready
02/12 02:52:02 Trace: [RAAT::SMSL USB AUDIO] [lua@0xb3608c6c] [192.168.1.20:49361]  got output message {"signal_path": [{"quality": "lossless", "alsa_device": {"id": "AUDIO", "components": "AUDIO", "name": "SMSL USB AUDIO", "longname": "SMSL SMSL USB AUDIO at usb-aotg_hcd.1-1.
02/12 02:52:02 Trace: [RAAT::SMSL USB AUDIO] [lua@0xb3608c6c] [192.168.1.20:49361]  SENT [6] {"message":{"signal_path":[{"method":"alsa","alsa_device":{"longname":"SMSL SMSL USB AUDIO at usb-aotg_hcd.1-1.1, high speed","usbid":"152a:85dd","driver":"USB-Audio","components":"AUD
02/12 02:52:02 Trace: [RAAT::SMSL USB AUDIO] [lua@0xb3608c6c] [192.168.1.20:49361]  SENT [6] {"clock_port":57732,"audio_port_tcp":34572,"audio_port":0,"status":"Success"}
02/12 02:52:02 Trace: [RAAT::SMSL USB AUDIO] [lua@0xb3608c6c] [192.168.1.20:49361]  GOT [7] {"request":"stream","stream_id":2025483677,"first_seq":-1,"nak_port":-1,"buffer_size":10,"ready_threshold":0.2}
02/12 02:52:02 Trace: [RAAT::SMSL USB AUDIO] [lua@0xb3608c6c] [192.168.1.20:49361]  SENT [7] {"status":"Buffering"}
02/12 02:52:03 Trace: [RAAT::SMSL USB AUDIO] [lua@0xb3608c6c] [192.168.1.20:49361]  SENT [7] {"status":"Ready"}
02/12 02:52:03 Trace: [RAAT::SMSL USB AUDIO] [lua@0xb3608c6c] [192.168.1.20:49361]  GOT [8] {"request":"start","min_offset":60001302,"stream_sample":0}
02/12 02:52:03 Trace: [RAAT::SMSL USB AUDIO] [lua@0xb3608c6c] [192.168.1.20:49361]  Doing ASAP start based on current device clock (min_offset=60001302)
02/12 02:52:03 Trace: [RAAT::SMSL USB AUDIO] [lua@0xb3608c6c] [192.168.1.20:49361]  SENT [7] {"status":"Playing"}
02/12 02:52:03 Trace: [RAAT::SMSL USB AUDIO] [lua@0xb3608c6c] [192.168.1.20:49361]  SENT [8] {"time":17002665302,"status":"Success"}
02/12 02:52:03 Trace: [RAAT::SMSL USB AUDIO] starting playback: now (17000000000ns) + ns_per_buf(20000000ns) = 17020000000ns > 17002665302ns streamsample=0
02/12 03:20:50 Error: [RAAT::SMSL USB AUDIO] error in snd_pcm_recover: Input/output error (-5)
02/12 03:20:50 Error: [RAAT::SMSL USB AUDIO] error in snd_pcm_recover: Input/output error (-5)
02/12 03:20:51 Error: [RAAT::SMSL USB AUDIO] error in snd_pcm_recover: Input/output error (-5)
02/12 03:20:51 Error: [RAAT::SMSL USB AUDIO] error in snd_pcm_recover: Input/output error (-5)
02/12 03:20:52 Error: [RAAT::SMSL USB AUDIO] error in snd_pcm_recover: Input/output error (-5)
02/12 03:20:52 Error: [RAAT::SMSL USB AUDIO] error in snd_pcm_recover: Input/output error (-5)
02/12 03:20:53 Error: [RAAT::SMSL USB AUDIO] error in snd_pcm_recover: Input/output error (-5)
02/12 03:20:53 Error: [RAAT::SMSL USB AUDIO] error in snd_pcm_recover: Input/output error (-5)
***[REMOVED FOR BREVITY]***
02/12 03:21:48 Error: [RAAT::SMSL USB AUDIO] error in snd_pcm_recover: Input/output error (-5)
02/12 03:21:48 Error: [RAAT::SMSL USB AUDIO] error in snd_pcm_recover: Input/output error (-5)
02/12 03:21:49 Error: [RAAT::SMSL USB AUDIO] error in snd_pcm_recover: Input/output error (-5)
02/12 03:21:49 Error: [RAAT::SMSL USB AUDIO] error in snd_pcm_recover: Input/output error (-5)
02/12 03:21:50 Error: [RAAT::SMSL USB AUDIO] error in snd_pcm_recover: Input/output error (-5)
02/12 03:21:50 Error: [RAAT::SMSL USB AUDIO] error in snd_pcm_recover: Input/output error (-5)
02/12 03:21:51 Error: [RAAT::SMSL USB AUDIO] error in snd_pcm_recover: Input/output error (-5)
02/12 03:21:51 Trace: [RAAT::SMSL USB AUDIO] [lua@0xb3608c6c] [192.168.1.20:49361]  GOT [9] {"request":"end_stream"}
02/12 03:21:51 Trace: [RAAT::SMSL USB AUDIO] [lua@0xb3608c6c] [192.168.1.20:49361]  SENT [7] {"status":"Ended"}
02/12 03:21:51 Trace: [RAAT::SMSL USB AUDIO] [lua@0xb3608c6c] [192.168.1.20:49361]  SENT [9] {"status":"Success"}
02/12 03:21:51 Trace: [RAAT::SMSL USB AUDIO] [lua@0xb3608c6c] [192.168.1.20:49361]  GOT [10] {"request":"teardown"}
02/12 03:21:51 Trace: [RAAT::SMSL USB AUDIO] [alsa] teardown
02/12 03:21:51 Error: [RAAT::SMSL USB AUDIO] error in snd_pcm_recover: Input/output error (-5)
2 Likes

Having similar issues. Seeing a lot of

ALSA lib pcm.c:8427:(snd_pcm_recover) cannot recovery from underrun prepare failed: Input/output error

Unsure as to why. Using the latest available version of DietPi, roonbridge service on highest CPU priority, nothing else running on the system (except for defaults like cron and dropbear). Running the latest version of DietPi (v6.34.3), all apt packages updated, latest version of Roon Remote and Core - 1.8 (build 763), and Roon Bridge at 1.7 (build 571).

As far as hardware goes, this is RPi 4 Model B (armv7l) connected to Wi-Fi 5 GHz (no issues there), with an USB DAC (connected via USB 3 port). The issue happens once every hour or so, but only when connected via Raspberry, if I go Laptop > DAC over an USB cable directly, Roon doesn’t have any problem. My Roon core is not running on the same machine as my Remote, so it shouldn’t be that either.

How do we troubleshoot? Any other reports of this happening? Thanks!

It just happened again, but this time I caught it in the logs:

02/24 00:31:35 Error: [RAAT::Hugo2] error in snd_pcm_recover: No such device (-19)
02/24 00:31:35 Trace: [RAAT::Hugo2] [alsa] [hw:CARD=Hugo2,DEV=0] kicking off old output in force teardown
02/24 00:31:35 Trace: [RAAT::Hugo2] [alsa] [hw:CARD=Hugo2,DEV=0] joining thread in force teardown
02/24 00:31:35 Trace: [RAAT::Hugo2] [lua@0xb39a76d4] [192.168.0.237:36634]  output lost
02/24 00:31:35 Trace: [RAAT::Hugo2] [lua@0xb39a76d4] [192.168.0.237:36634]  SENT [97] {"status":"Lost","reason":{"reason":"device_not_available"}}

Managed to resolve the issue by using a different USB cable. The one that was causing this issue was a cheap USB cable that I had and chose it for its size, but I guess there was some crosstalk? Since changing the USB cable to (unfortunately longer) but better quality (the one my DAC came with) I have encouraged no dropouts.