RaspberryPi RoonBridge RAAT Endpoint Stops After Every Track, "StoppedLostEndpoint"

rcrawley · April 10, 2023, 6:47pm

Roon Core Machine

Tested on two different Roon cores on the same network (as I continue to troubleshoot issues with one) but only is ever active/authorized at a time, able to reproduce on either core.

NAS Synology DS218+
10GB RAM
Roon 2.0 (Build 1244)
DB on external SSD, music on NAS drives

MacOS Ventura
3.5 GHz Dual-Core i7
16 GB RAM
DB on internal SSD, music on external USB drive

Networking Gear & Setup Details

Both Roon cores and endpoints connected via ethernet

Connected Audio Devices

Raspberry Pi 4
Rasbian x64 (bullseye)
RoonBridge 1.8 (Build 1125)

Number of Tracks in Library

~60k

Description of Issue

When playing both saved playlists that I’ve created and when Roon auto-plays tracks after finishing a queue, the core routinely loses connectivity to the RoonBridge Pi endpoint when moving to the next track and Roon just stops playback, reporting “StoppedLostEndpoint” in the logs and “Failed to open the Audio device” in the UI. I’m able to restart it every time by pressing play again, although it usually takes a few presses to get past the “Failed to open the Audio device” message in the UI, then it happens to the next track after the new track finishes, rinse, repeat. Rebooting both the core and the endpoint seems to fix this for a few tracks and then it comes back.

I’ve tried adjusting the Resync Delay for this endpoint (schiitstack) up to 1000ms but no luck.

Full logs from when Roon changes to the next track and fails below. I’ve been able to repo this both on the NAS and my MBP core. Nothing has changed on the RoonBridge Pi (beyond keeping it updated with apt) but this has just started recently (maybe w/in a month) so I’m guessing it’s possibly related to a Roon 2.0 build update. Key error seems to be:

04/10 11:18:26 Trace: [Schiit Modi 3E] [raatclient] GOT [24] {"message":"RAAT__OUTPUT_PLUGIN_STATUS_DEVICE_OPEN_FAILED","status":"DeviceOpenFailed"}

04/10 11:18:09 Trace: [schiitstack] [Lossless, 24/96 ALAC => 24/96] [94% buf] [PLAYING @ 4:14/4:28] Gypsy - Fleetwood Mac
04/10 11:18:12 Info: [stats] 14239mb Virtual, 2766mb Physical, 1348mb Managed, 414 Handles, 74 Threads
04/10 11:18:14 Trace: [roonapi] [apiclient 192.168.1.231:45856] CONTINUE Changed {"message":"Running (1872)","is_error":false}
04/10 11:18:14 Trace: [schiitstack] [Lossless, 24/96 ALAC => 24/96] [46% buf] [PLAYING @ 4:19/4:28] Gypsy - Fleetwood Mac
04/10 11:18:19 Trace: [roonapi] [apiclient 192.168.1.26:49806] CONTINUE Changed {"message":"Extension Repository loaded (v1.0.15)","is_error":false}
04/10 11:18:20 Trace: [schiitstack] [Lossless, 24/96 ALAC => 24/96] [4% buf] [PLAYING @ 4:25/4:28] Gypsy - Fleetwood Mac
04/10 11:18:23 Info: 
--[ SignalPath ]---------------------------------------------
SignalPath Quality = Lossless
Elements:
    Source Format=Alac 96000/24/2 BitRate=2887 Quality=Lossless
    Raat Device=Schiit Modi 3E
    Output OutputType=Local_Alsa Quality=Lossless SubType= Model=Schiit Modi 3E
------------------------------------------------------------
04/10 11:18:23 Info: [library] recorded play for profile 53e786ce-de2b-480b-b7f1-3537ad6ed2e0: mediaid=50:1:44d58007-fff1-4fde-b3bf-7abcc3db42a9 metadataid=123:0:MT0053624555 contentid= libraryid=50:1:44d58007-fff1-4fde-b3bf-7abcc3db42a9 isfromradio=False isfrommix=False isfrommobile=
04/10 11:18:23 Trace: [schiitstack] [zoneplayer/raat] Endpoint Schiit Modi 3E State Changed: Playing => Prepared
04/10 11:18:23 Trace: [Schiit Modi 3E] [raatclient] SENT [22]{"request":"end_stream"}
04/10 11:18:23 Info: [zone schiitstack] OnPlayFeedback StoppedEndOfMediaNatural
04/10 11:18:23 Debug: [zone schiitstack] _Advance (Track)
04/10 11:18:23 Trace: [Schiit Modi 3E] [raatclient] GOT [20] {"status":"Ended"}
04/10 11:18:23 Trace: [Schiit Modi 3E] [raatclient] GOT [22] {"status":"Success"}
04/10 11:18:23 Trace: [schiitstack] [Lossless, 24/96 ALAC => 24/96] [4% buf] [LOADING @ 0:00] The Figurehead - The Cure
04/10 11:18:23 Trace: [roonapi] [apiclient 192.168.1.207:33656] CONTINUE Changed {"zones_changed":[{"zone_id":"1601c691b5d8f0276072873d046e4bea8f3d","display_name":"schiitstack","outputs":[{"output_id":"1701c691b5d8f0276072873d046e4bea8f3d","zone_id":"1601c691b5d8f0276072873d046e4bea8f3d","can_group_with_output_ids":["1701d3b103237f124aa570b3d7fa6d4f8a01","17014d33e63ab8a2c2198854fc4ef5b6057c","17013791edc9ca3bc5489ce518e0d78cf858","1701c691b5d8f0276072873d046e4bea8f3d","1701d64ab0e348271e2951a3b61f81177f2a"],"display_name":"schiitstack","source_controls":[{"control_key":"1","display_name":"Schiit Modi 3E","supports_standby":false,"status":"indeterminate"}]}],"state":"loading","is_next_allowed":true,"is_previous_allowed":true,"is_pause_allowed":true,"is_play_allowed":false,"is_seek_allowed":false,"queue_items_remaining":388,"queue_time_remaining":106538,"settings":{"loop":"loop","shuffle":false,"auto_radio":true},"now_playing":{"seek_position":null,"length":375,"one_line":{"line1":"The Figurehead - The Cure"},"two_line":{"line1":"The Figurehead","line2":"The Cure"},"three_line":{"line1":"The Figurehead","line2":"The Cure","line3":"Pornography [Deluxe Edition]"},"image_key":"d3b6e6822ad907fff22a95e86e946836","artist_image_keys":["b568f7f1c6bff24af67bb68776d7b6af"]}}],"zones_seek_changed":[{"zone_id":"1601c691b5d8f0276072873d046e4bea8f3d","queue_time_remaining":106538,"seek_position":null}]}
04/10 11:18:23 Trace: [roonapi] [apiclient 192.168.1.231:45856] CONTINUE Changed {"zones_changed":[{"zone_id":"1601c691b5d8f0276072873d046e4bea8f3d","display_name":"schiitstack","outputs":[{"output_id":"1701c691b5d8f0276072873d046e4bea8f3d","zone_id":"1601c691b5d8f0276072873d046e4bea8f3d","can_group_with_output_ids":["1701d3b103237f124aa570b3d7fa6d4f8a01","17014d33e63ab8a2c2198854fc4ef5b6057c","17013791edc9ca3bc5489ce518e0d78cf858","1701c691b5d8f0276072873d046e4bea8f3d","1701d64ab0e348271e2951a3b61f81177f2a"],"display_name":"schiitstack","source_controls":[{"control_key":"1","display_name":"Schiit Modi 3E","supports_standby":false,"status":"indeterminate"}]}],"state":"loading","is_next_allowed":true,"is_previous_allowed":true,"is_pause_allowed":true,"is_play_allowed":false,"is_seek_allowed":false,"queue_items_remaining":388,"queue_time_remaining":106538,"settings":{"loop":"loop","shuffle":false,"auto_radio":true},"now_playing":{"seek_position":null,"length":375,"one_line":{"line1":"The Figurehead - The Cure"},"two_line":{"line1":"The Figurehead","line2":"The Cure"},"three_line":{"line1":"The Figurehead","line2":"The Cure","line3":"Pornography [Deluxe Edition]"},"image_key":"d3b6e6822ad907fff22a95e86e946836","artist_image_keys":["b568f7f1c6bff24af67bb68776d7b6af"]}}],"zones_seek_changed":[{"zone_id":"1601c691b5d8f0276072873d046e4bea8f3d","queue_time_remaining":106538,"seek_position":null}]}
04/10 11:18:23 Trace: [roonapi] [apiclient 192.168.1.26:45608] CONTINUE Changed {"zones_changed":[{"zone_id":"1601c691b5d8f0276072873d046e4bea8f3d","display_name":"schiitstack","outputs":[{"output_id":"1701c691b5d8f0276072873d046e4bea8f3d","zone_id":"1601c691b5d8f0276072873d046e4bea8f3d","can_group_with_output_ids":["1701d3b103237f124aa570b3d7fa6d4f8a01","17014d33e63ab8a2c2198854fc4ef5b6057c","17013791edc9ca3bc5489ce518e0d78cf858","1701c691b5d8f0276072873d046e4bea8f3d","1701d64ab0e348271e2951a3b61f81177f2a"],"display_name":"schiitstack","source_controls":[{"control_key":"1","display_name":"Schiit Modi 3E","supports_standby":false,"status":"indeterminate"}]}],"state":"loading","is_next_allowed":true,"is_previous_allowed":true,"is_pause_allowed":true,"is_play_allowed":false,"is_seek_allowed":false,"queue_items_remaining":388,"queue_time_remaining":106538,"settings":{"loop":"loop","shuffle":false,"auto_radio":true},"now_playing":{"seek_position":null,"length":375,"one_line":{"line1":"The Figurehead - The Cure"},"two_line":{"line1":"The Figurehead","line2":"The Cure"},"three_line":{"line1":"The Figurehead","line2":"The Cure","line3":"Pornography [Deluxe Edition]"},"image_key":"d3b6e6822ad907fff22a95e86e946836","artist_image_keys":["b568f7f1c6bff24af67bb68776d7b6af"]}}],"zones_seek_changed":[{"zone_id":"1601c691b5d8f0276072873d046e4bea8f3d","queue_time_remaining":106538,"seek_position":null}]}
04/10 11:18:23 Trace: [library] finished with 410 dirty tracks 23 dirty albums 32 dirty performers 161 dirty works 314 dirty performances 0 clumping tracks, 0 clumping auxfiles 0 compute tracks, 0 deleted tracks, 0 tracks to (re)load, 0 tracks to retain, 0 auxfiles to (re)load, 0 auxfiles to retain, and 531 changed objects
04/10 11:18:23 Trace: [roonapi] [apiclient 192.168.1.26:45608] GOT com.roonlabs.image:1/get_image {"image_key":"d3b6e6822ad907fff22a95e86e946836","scale":"fit","width":1080,"height":1080,"format":"image/jpeg"}
04/10 11:18:23 Trace: GetImageData[Local](id=10175 spec=1080 key=jbpaaaaa) => gotfromcache=False missinglocalimage=False didscale=True scaletime=39), overalltime=39ms
04/10 11:18:23 Trace: GetImageData[Local](id=10175 spec=1080 key=jbpaaaaa) => gotfromcache=False missinglocalimage=False didscale=True scaletime=39), overalltime=39ms
04/10 11:18:23 Debug: [easyhttp] [6725] GET to http://127.0.0.1:9330/image/jbpaaaaa.1080.jpg returned after 41 ms, status code: 200, request body size: 0 B
04/10 11:18:23 Trace: [roonapi] [apiclient 192.168.1.26:45608] COMPLETE Success <135386 bytes>
04/10 11:18:24 Info: [library/albumdetails] found 1 ingroup alternates, 0 other alternates
04/10 11:18:24 Trace: [music/searchindex] [search-index]  removed in 0ms: 1 albums, 1 tracks, 0 works, 1 performers, 0 labels, 0 genres
04/10 11:18:24 Trace: [music/searchindex] [search-index] added in 2ms: 1 albums, 1 tracks, 0 works, 1 performers, 0 labels, 0 genres
04/10 11:18:24 Debug: [music/profilestats] Computed stats in 332ms, got 50 top albums, 50 top performers, 44 genres
04/10 11:18:24 Debug: [music/profilestats] Computed stats in 245ms, got 50 top albums, 50 top performers, 44 genres
04/10 11:18:24 Debug: [music/profilestats] Computed stats in 174ms, got 50 top albums, 50 top performers, 32 genres
04/10 11:18:25 Debug: [music/profilestats] Computed stats in 244ms, got 50 top albums, 50 top performers, 32 genres
04/10 11:18:25 Debug: [music/profilestats] Computed stats in 171ms, got 50 top albums, 50 top performers, 32 genres
04/10 11:18:25 Trace: [dbperf] flush 0 bytes, 0 ops in 12 ms (cumulative 665646857 bytes, 290892 ops in 609009 ms)
04/10 11:18:25 Trace: [library] endmutation in 1916ms
04/10 11:18:25 Trace: [dbperf] flush 0 bytes, 0 ops in 2 ms (cumulative 665646857 bytes, 290892 ops in 609011 ms)
04/10 11:18:25 Info: [library/albumdetails] found 1 ingroup alternates, 0 other alternates
04/10 11:18:26 Info: [library/albumdetails] Created album details screen for LibraryAlbum[807983, The Cure - Pornography [Deluxe Edition]]
04/10 11:18:26 Info: [library/albumdetails] 79004d5730303030313939303232, 79004d5230303033303930393630, 79004d5230303030383138363035, 79004d5230303030343930303930, 79004d5230303031353939323034, 79004d5230303035363532373337, 79004d5230303034353939373032, 79004d5230303034353436373236, 79004d5230303033373230333939, 79004d5230303031353933333038, 79004d5230303031333234323038, 79004d5230303030393834323835, 79004d5230303030343830383934, 79004d5230303035343935303234, 79004d5230303031353938343639, 79004d5230303033393731313839, 79004d5230303033333434373635, 79004d5230303031353933393039, 79004d5230303033383835363333, 79004d5230303033303837383730, 79004d5230303030393830383233, 3e0196a643d4571a633ea8ede08d89b79001, 3e0157c29b9c3ff1284ea01722c1b1189389, 3e01ee685582a2f0c24db809fcacdc67ed9b, 3e012da0f779e0e3933fa2e58eb128171040, 3e01faf65f66d046d33e9c7eec508e850946, 3e01e4c00355a654e237882c50e0fa690468, 3e01ace89827c670fb3984abad226d4ed6a0, 3e01add8d6b0d702083f912847c734c2c446, 3e018d69e3ecd7d7c73aa6ab11630e120f38, 79004d5230303031363134373038, 79004d5230303031363133353834, 79004d5230303031353932363938, 79004d5230303031363037353837, 79004d5230303031363133333434, 3e01e2a00eccf3b2234da229003952eab96c, 3e018097abc00c6b7d37b6f70dc38344f282, 3e014d2219a814c6e24aa89847f191b48bdd, 3e01fbc33e87b460e449b90df93af926fb6a, 3e0142834e7f012e034ba9bec8849822d65c, 3e012b84456f3ecc974db3861118495a4c48, 3e01a62aee3dbbcc51458922b152d43c40fc, 3e01c19a5f394044524987eabb4726943ef5, 3e01edc2b0a14dbe0f4c9e3f564af338713b, 3e0171cf6377ac5eb2439477df8e2558f57a, 3e018230f2fb1313194bbd0ab876e868cd07, a6003334343533393432, a60031313938333932, a600313937303234383234, a6003334393534313237, c80030303034323238323736383832, c80030303630323439383231383338, c80030363033343937393738343033, c80030303831323237373837373639, c8007771353677366b7a3669706262, cd0050584a4d574b505851376d727a50466c4c4f, cd0035594a3769427048734c70507a7a6d394975, cd00386b375f3432702d475469434a794e52334b, cd00477334374d47357a47314c33474e414c6f4a
04/10 11:18:26 Trace: [dbperf] flush 0 bytes, 0 ops in 15 ms (cumulative 665646857 bytes, 290892 ops in 609026 ms)
04/10 11:18:26 Info: [schiitstack] [zoneplayer] Playing: /var/packages/RoonServer/target/roonmnt/nas-music/iTunes/iTunes Media/Music/The Cure/Pornography [Deluxe Edition]/1-05 The Figurehead.m4a
04/10 11:18:26 Debug: [raat/tcpaudiosource] disconnecting
04/10 11:18:26 Info: [audio/env] [zoneplayer -> stream] All streams were disposed
04/10 11:18:26 Info: [audio/env] [zoneplayer -> stream -> endpoint] All streams were disposed
04/10 11:18:26 Info: [audio/env] [zoneplayer] All streams were disposed
04/10 11:18:26 Trace: [dbperf] flush 0 bytes, 0 ops in 3 ms (cumulative 665646857 bytes, 290892 ops in 609029 ms)
04/10 11:18:26 Info: sleep 50ms after flush
04/10 11:18:26 Info: [schiitstack] [zoneplayer] Queueing: /var/packages/RoonServer/target/roonmnt/nas-music/iTunes/iTunes Media/Music/Elton John/The Very Best Of Elton John/2-06 Blue Eyes.m4a
04/10 11:18:26 Info: [schiitstack] [zoneplayer]     Open Result (Playing):Result[Status=Success]
04/10 11:18:26 Info: [schiitstack] [zoneplayer] Starting playback
04/10 11:18:26 Trace: [schiitstack] [zoneplayer/raat] StartStream Sooloos.Broker.Transport.RaatZonePlayer+Endpoint: StreamFormat(channels=2, bitspersample=16, samplerate=44100, isdts=False) => StreamFormat(channels=2, bitspersample=16, samplerate=44100, isdts=False) streamid=69151376
04/10 11:18:26 Trace: [Schiit Modi 3E] [raatclient] SENT [23]{"request":"teardown"}
04/10 11:18:26 Trace: [schiitstack] [zoneplayer/raat] Endpoint Schiit Modi 3E State Changed: Prepared => Idle
04/10 11:18:26 Trace: [Schiit Modi 3E] [raatclient] SENT [24]{"request":"setup","format":{"sample_type":"pcm","sample_rate":44100,"bits_per_sample":16,"channels":2,"sample_subtype":"none"}}
04/10 11:18:26 Info: [zone schiitstack] OnPlayFeedback Playing
04/10 11:18:26 Trace: [schiitstack] [Lossless, 16/44 ALAC => 16/44] [4% buf] [PLAYING @ 0:00] The Figurehead - The Cure
04/10 11:18:26 Trace: [roonapi] [apiclient 192.168.1.207:33656] CONTINUE Changed {"zones_changed":[{"zone_id":"1601c691b5d8f0276072873d046e4bea8f3d","display_name":"schiitstack","outputs":[{"output_id":"1701c691b5d8f0276072873d046e4bea8f3d","zone_id":"1601c691b5d8f0276072873d046e4bea8f3d","can_group_with_output_ids":["1701d3b103237f124aa570b3d7fa6d4f8a01","17014d33e63ab8a2c2198854fc4ef5b6057c","17013791edc9ca3bc5489ce518e0d78cf858","1701c691b5d8f0276072873d046e4bea8f3d","1701d64ab0e348271e2951a3b61f81177f2a"],"display_name":"schiitstack","source_controls":[{"control_key":"1","display_name":"Schiit Modi 3E","supports_standby":false,"status":"indeterminate"}]}],"state":"playing","is_next_allowed":true,"is_previous_allowed":true,"is_pause_allowed":true,"is_play_allowed":false,"is_seek_allowed":true,"queue_items_remaining":388,"queue_time_remaining":106538,"settings":{"loop":"loop","shuffle":false,"auto_radio":true},"now_playing":{"seek_position":null,"length":375,"one_line":{"line1":"The Figurehead - The Cure"},"two_line":{"line1":"The Figurehead","line2":"The Cure"},"three_line":{"line1":"The Figurehead","line2":"The Cure","line3":"Pornography [Deluxe Edition]"},"image_key":"d3b6e6822ad907fff22a95e86e946836","artist_image_keys":["b568f7f1c6bff24af67bb68776d7b6af"]}}]}
04/10 11:18:26 Trace: [roonapi] [apiclient 192.168.1.231:45856] CONTINUE Changed {"zones_changed":[{"zone_id":"1601c691b5d8f0276072873d046e4bea8f3d","display_name":"schiitstack","outputs":[{"output_id":"1701c691b5d8f0276072873d046e4bea8f3d","zone_id":"1601c691b5d8f0276072873d046e4bea8f3d","can_group_with_output_ids":["1701d3b103237f124aa570b3d7fa6d4f8a01","17014d33e63ab8a2c2198854fc4ef5b6057c","17013791edc9ca3bc5489ce518e0d78cf858","1701c691b5d8f0276072873d046e4bea8f3d","1701d64ab0e348271e2951a3b61f81177f2a"],"display_name":"schiitstack","source_controls":[{"control_key":"1","display_name":"Schiit Modi 3E","supports_standby":false,"status":"indeterminate"}]}],"state":"playing","is_next_allowed":true,"is_previous_allowed":true,"is_pause_allowed":true,"is_play_allowed":false,"is_seek_allowed":true,"queue_items_remaining":388,"queue_time_remaining":106538,"settings":{"loop":"loop","shuffle":false,"auto_radio":true},"now_playing":{"seek_position":null,"length":375,"one_line":{"line1":"The Figurehead - The Cure"},"two_line":{"line1":"The Figurehead","line2":"The Cure"},"three_line":{"line1":"The Figurehead","line2":"The Cure","line3":"Pornography [Deluxe Edition]"},"image_key":"d3b6e6822ad907fff22a95e86e946836","artist_image_keys":["b568f7f1c6bff24af67bb68776d7b6af"]}}]}
04/10 11:18:26 Trace: [roonapi] [apiclient 192.168.1.26:45608] CONTINUE Changed {"zones_changed":[{"zone_id":"1601c691b5d8f0276072873d046e4bea8f3d","display_name":"schiitstack","outputs":[{"output_id":"1701c691b5d8f0276072873d046e4bea8f3d","zone_id":"1601c691b5d8f0276072873d046e4bea8f3d","can_group_with_output_ids":["1701d3b103237f124aa570b3d7fa6d4f8a01","17014d33e63ab8a2c2198854fc4ef5b6057c","17013791edc9ca3bc5489ce518e0d78cf858","1701c691b5d8f0276072873d046e4bea8f3d","1701d64ab0e348271e2951a3b61f81177f2a"],"display_name":"schiitstack","source_controls":[{"control_key":"1","display_name":"Schiit Modi 3E","supports_standby":false,"status":"indeterminate"}]}],"state":"playing","is_next_allowed":true,"is_previous_allowed":true,"is_pause_allowed":true,"is_play_allowed":false,"is_seek_allowed":true,"queue_items_remaining":388,"queue_time_remaining":106538,"settings":{"loop":"loop","shuffle":false,"auto_radio":true},"now_playing":{"seek_position":null,"length":375,"one_line":{"line1":"The Figurehead - The Cure"},"two_line":{"line1":"The Figurehead","line2":"The Cure"},"three_line":{"line1":"The Figurehead","line2":"The Cure","line3":"Pornography [Deluxe Edition]"},"image_key":"d3b6e6822ad907fff22a95e86e946836","artist_image_keys":["b568f7f1c6bff24af67bb68776d7b6af"]}}]}
04/10 11:18:26 Trace: [prebuffer] ready 149940/441000 (34%) @ 0/375 sec
04/10 11:18:26 Info: [schiitstack] [zoneplayer] Open result (Queueing): Result[Status=Success]
04/10 11:18:26 Trace: [Schiit Modi 3E] [raatclient] GOT [19] {"status":"Teardown"}
04/10 11:18:26 Trace: [Schiit Modi 3E] [raatclient] GOT [24] {"message":"RAAT__OUTPUT_PLUGIN_STATUS_DEVICE_OPEN_FAILED","status":"DeviceOpenFailed"}
04/10 11:18:26 Trace: [schiitstack] [zoneplayer/raat] device open failed. stopping stream
04/10 11:18:26 Info: [audio/env] [zoneplayer -> stream] All streams were disposed
04/10 11:18:26 Info: [audio/env] [zoneplayer -> stream -> endpoint] All streams were disposed
04/10 11:18:26 Warn: [zone schiitstack] Track Stopped Due to DeviceOpenFailed
04/10 11:18:26 Info: [zone schiitstack] OnPlayFeedback StoppedLostEndpoint
04/10 11:18:26 Trace: [zone schiitstack] Suspend
04/10 11:18:26 Info: [zone schiitstack] OnPlayFeedback Stopped
04/10 11:18:26 Info: [zone schiitstack] Canceling Pending Sleep
04/10 11:18:26 Trace: [schiitstack] [Lossless, 16/44 ALAC => 16/44] [4% buf] [STOPPED @ 0:00] The Figurehead - The Cure
04/10 11:18:26 Info: sleep 50ms after flush
04/10 11:18:26 Info: [audio/env] [zoneplayer] All streams were disposed

rcrawley · April 28, 2023, 3:04pm

Keeping this one open with new details. On a brand new Core install (with no library migrated, just straight out of the box installation) on a different machine, I’m also seeing this when playing new content via Tidal directly and/or when listening to Roon Radio, and it seems to happen when going between local content and Tidal content (although that’s just a best guess). I will get the Failed to Load Audio Device error in Roon when selecting a new Tidal track or album, or sometimes when I go from Tidal to local. I keep pressing play and will continue to see this error until I wait about 10 seconds then try again, after that Tidal plays fine until I stop, wait (either playing nothing or playing local files), and then it will repeat.

Roon Core Machine

LinuxMint
Linux roonmint 5.15.0-69-generic #76-Ubuntu SMP Fri Mar 17 17:19:29 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux
3.5 GHz Dual-Core i7
16 GB RAM

Core: Roon 2.0 (1259)

Connected Audio Devices

Raspberry Pi 4
Rasbian x64 (bullseye)
RoonBridge 1.8 (Build 1125)

Logs During Failure

What seems to be most interesting is that in one of the failures, Roon Radio starts by choosing a local track but then moves to the Tidal version of the same track before failing, but why? I’m not finding a setting to tell Roon not to do this.

04/28 07:40:42 Debug: [zone schiitstack] _Advance (Track)
04/28 07:40:42 Trace: [schiitstack] [Lossless, 24/96 ALAC => 24/96] [1% buf] [LOADING @ 0:00] Let's Dance - David Bowie
...
04/28 07:40:43 Info: [library/albumdetails] Created album details screen for LibraryAlbum[1213743, David Bowie - Let's Dance (2018 Remaster)]
04/28 07:40:43 Info: [library/albumdetails] 79004d5730303030363439393135, 79004d5230303035313036363831, 79004d5230303035303031373736, 79004d5230303035303031373631, 79004d5230303033303739393839, 79004d5230303031333736333739, 79004d5230303031333634373238, 79004d5230303030353935363639, 79004d5230303030333137363531, 79004d5230303030353735353933, 79004d5230303033303635303933, 79004d5230303035303031373734, 79004d5230303035303031373733, 79004d5230303035303031373635, 79004d5230303031373138363034, 79004d5230303031373135383830, 79004d5230303034333535323637, 79004d5230303034303637313136, 79004d5230303032383534363537, 79004d5230303031373136363631, 79004d5230303031333638363533, 79004d5230303030383935343939, 3e01c3e11b10177875458d2bdc387cbfa0dc, 3e0136b975003110644499c573b3ebea6e04, 3e01c692a70ac9a319468668a346282bbf3d, 3e013b65f1e9822007348d3c9e00f3bf2ba8, 3e01685f91f4d61e954baca5f98ca92cc614, 3e0108e3eee96096b8389de4b83ca7fe7b08, 3e0177607fe88560b43f97bb284ca3de6e51, 3e01c09581dcc126c33a83dd8f22bb9dc565, 3e0147cfbed825e2b244a4c46bad569b9656, 3e01deb157cceeea764c862160b49c4d9ada, 3e01faa3d7bbb1c0c64ead61c3ca9a8df550, 3e012e4befbad001ec4dad1db9b26d85a7e1, 3e01097115b3dd5eaf4e85fd3b8eeea01864, 3e011d3d64adc649984b80c250348f827523, 3e01962410a9fa59a1399fbcbcc1332211e3, 3e017fbc81a04e2e904ca1b68120f3debb21, 3e0170fcf87cad607d44bbce783e0135266e, 3e0181d87673762f96479ca6f9a57aca1213, 3e0184b39d707634034fa9b788b92f738ce8, 3e0157229b625d6acd4b8d044c748e2b5d82, 3e019598bd43cdfd1a40b281c7ed86467698, 3e017ac0d43f22eb264ea20752b5e58a18ad, 3e01a02df83bf3cdd646aaa90a7fc858d43c, 3e012cbb15dab714044db38f80f16f897765, 3e013d7a3c308d20723e85ac11ae2dc0c189, 79004d5230303030343937363832, 3e01ceef87bec13f954fb6f65d3b04343caf, 3e01eea791913aa06a4fb99fbffad4e3a3c9, 3e01198e103ff81c56489f0351988359046e, a600313134343633383433, a600313033333938363433, a600313033333938303537, c80030373234333532313839363536, c800716c716b306f63347832777161, c8006c706c647231616a707a683861, c800696e746e6c7776386268787861, cd004c6147305251557352354a6c6e6462704661, cd003071454d53705941573068466e75414e6569, cd003071417243705941573068466c6f686b6b64
04/28 07:40:43 Trace: [dbperf] flush 0 bytes, 0 ops in 2 ms (cumulative 2528129930 bytes, 2143682 ops in 756980 ms)
04/28 07:40:43 Trace: [dbperf] flush 0 bytes, 0 ops in 7 ms (cumulative 2528129930 bytes, 2143682 ops in 756987 ms)
04/28 07:40:43 Debug: [easyhttp] [72356] POST to https://api.roonlabs.net/swim/1/session/8e2fb9ec697e48bca735f7bb4d4a94b2/feedback returned after 248 ms, status code: 200, request body size: 172 B
04/28 07:40:44 Debug: [easyhttp] [72357] POST to https://api.roonlabs.net/metadata/1/albums/translate?c=tidal-us returned after 199 ms, status code: 200, request body size: 1 KB
04/28 07:40:44 Trace: GetImageData[Remote](id=103580 spec=256 key=wfxfaaaa uri=https://imagecache.roonlabs.net/im/1/albums/a600313033333938303537/cover/256.jpg) => fetched in 168ms status=200 size=31642 overalltime=174ms
04/28 07:40:44 Trace: GetImageData[Remote](id=6175 spec=16by7_2048 key=ndjaaaaa uri=https://imagecache.roonlabs.net/im/1/artists/7a004d4e30303030353331393836/photo/16by7_2048.jpg) => fetched in 177ms status=304 size=0 overalltime=181ms
04/28 07:40:44 Debug: [easyhttp] [72359] GET to https://api.tidal.com/v1/tracks/103398060/playbackinfopostpaywall?countryCode=US&audioquality=HI_RES&assetpresentation=FULL&playbackmode=STREAM returned after 234 ms, status code: 200, request body size: 0 B
04/28 07:40:44 Trace: [tidal/http] GET https://api.tidal.com/v1/tracks/103398060/playbackinfopostpaywall?countryCode=US&audioquality=HI_RES&assetpresentation=FULL&playbackmode=STREAM => Success
04/28 07:40:44 Trace: GetImageData[Remote](id=103580 spec=256 key=wfxfaaaa uri=https://imagecache.roonlabs.net/im/1/albums/a600313033333938303537/cover/256.jpg) => fetched in 222ms status=200 size=31642 overalltime=228ms
04/28 07:40:44 Debug: [easyhttp] [72358] GET to https://api.tidal.com/v1/tracks/81214950/playbackinfopostpaywall?countryCode=US&audioquality=HI_RES&assetpresentation=FULL&playbackmode=STREAM returned after 265 ms, status code: 200, request body size: 0 B
04/28 07:40:44 Info: [library/albumdetails] found 3 streaming service alternates

...

These look interesting:

04/28 07:46:46 Warn: [cast/discovery] unexpected KeyNotFoundException error in device data: System.Collections.Generic.KeyNotFoundException: The given key 'md' was not present in the dictionary.
   at System.Collections.Concurrent.ConcurrentDictionary`2.ThrowKeyNotFoundException(TKey key)
   at Sooloos.Audio.Cast.CastDeviceData.ParseProperties(ConcurrentDictionary`2 props)
04/28 07:46:46 Warn: [cast/discovery] prop '' => ''
04/28 07:46:46 Warn: [cast/discovery] unexpected KeyNotFoundException error in device data: System.Collections.Generic.KeyNotFoundException: The given key 'md' was not present in the dictionary.
   at System.Collections.Concurrent.ConcurrentDictionary`2.ThrowKeyNotFoundException(TKey key)
   at Sooloos.Audio.Cast.CastDeviceData.ParseProperties(ConcurrentDictionary`2 props)
04/28 07:46:46 Warn: [cast/discovery] prop '' => ''

connor · April 28, 2023, 3:59pm

Hi @rcrawley,

Roon Radio will always feature the highest-quality version of a track in your Library. The above - switching to Tidal when local is available - will happen under two circumstances:

for whatever reason, Roon can’t access the local file. The filepath is temporarily or permanently invalid, permissions are rejecting Roon’s access, or the track has been corrupted. If on a network share, the network reachability changes may temporarily block the Core’s access to the content. Tidal content would then fail for the same reason, temporary network loss.
your endpoint or Device Setup settings are restricting playback of the Zone to a certain file type only available in Tidal.

Recent diagnostics indicate Roon is struggling to mount a storage location upon startup. I recommend verifying whether or not this Mac’s ability to access stored content may be fluctuating, as it would underpin the playlist wipeout behavior you previously experienced and many of the errors in current logs.

Having reviewed your situation more broadly as a team, you’ve more than likely been encountering a known/ticketed issue with Remote discovery after Backup Restore that you’ve since resolved with the new out-of-the-box installation (new DB). If you encounter this problem again, a known workaround that should relieve symptoms is to reboot the Core twice or more.

Otherwise, the endpoint loss and dropouts with the RoonBridge are the result of the networking conditions discussed separately in this thread: Network Reachability Changed, Immediate Out of Memory Crash

The team will follow up there accordingly in that thread, but as a first step, try verifying that multicast is enabled in any routers to which you are connecting endpoints and Remotes. Multicast failures are persistent throughout diagnostics. Thank you!

rcrawley · April 28, 2023, 4:51pm

Thanks @connor. Good point on the local music store; it’s a USB drive and does go to sleep when not in use, so I could see Roon thinking local storage was unavailable when linux is waking up the drive on first access after a while. Also jives with me seeing this more frequently after not playing anything for a while. I’ve configured linux to not let the USB drive sleep and will test over the next few days. Thanks for the pointer!

And thanks for looking at all of the issues together, much appreciated.

system · June 12, 2023, 4:51pm

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