Issue with Unreliable RTE Radio Streams (ref#1NT23B)

Joe_C · May 15, 2024, 11:50am

What’s happening?

I am experiencing freezes or crashes

Describe the issue

I’ve had ongoing issues with RTE streams when being played over various endpoints (see RTE Radio streams cutting out and RTE Radio streams cutting out.. still :)), especially Sonos and on my iPad. The stream used to work perfectly via Airplay, so that was an acceptable workaround, but this has also recently stopped working.

The various issues that I’m having are:

When using RAAT the stream cuts out after an arbitary amount of time, but usually within a few minutes.

05/15 13:02:26 Trace: [Office] [zoneplayer/sonos] state from device: PLAYING
05/15 13:02:26 Trace: [Office] [zoneplayer/sonos]  zoneplayer state: Playing
05/15 13:02:26 Warn: [Office] [zoneplayer/sonos] position timer reported next url, fix for bug 16980 triggered
05/15 13:02:26 Trace: [Office] [zoneplayer/sonos] position timer, advancing to next stream, reported reltime: 0:00:00, reported path: http://10.10.10.10:30004/24ec7095618e414abe13c77fc5b749a2/Roon7.flac
05/15 13:02:26 Trace: [Office] [zoneplayer/sonos] Switching to next stream path.  position offset: 244, max reported position: 284
05/15 13:02:26 Trace: [client/sonos] av_status
05/15 13:02:26 Trace: [Office] [zoneplayer/sonos] state from device: PLAYING
05/15 13:02:26 Trace: [Office] [zoneplayer/sonos]  zoneplayer state: Playing
05/15 13:02:28 Debug: [easyhttp] [14094] GET to https://liveaudio.rte.ie/hls-radio/ieradio1/chunklist.m3u8 returned after 30 ms, status code: 200, request body size: 0 B
05/15 13:02:31 Debug: [easyhttp] [14095] GET to https://liveaudio.rte.ie/hls-radio/ieradio1/chunklist.m3u8 returned after 28 ms, status code: 200, request body size: 0 B
05/15 13:02:34 Debug: [easyhttp] [14096] GET to https://liveaudio.rte.ie/hls-radio/ieradio1/chunklist.m3u8 returned after 28 ms, status code: 200, request body size: 0 B
05/15 13:02:34 Debug: [easyhttp] [14097] GET to https://liveaudio.rte.ie/hls-radio/ieradio1/media-ucc4gojjp_1027838.aac returned after 28 ms, status code: 200, request body size: 0 B
05/15 13:02:34 Trace: [Office] [LowQuality, 24/44 AAC => 24/44] [100% buf] [PLAYING @ 2:19] The Louise Duffy Show
05/15 13:02:34 Debug: [easyhttp] [14098] GET to https://liveaudio.rte.ie/hls-radio/ieradio1/chunklist.m3u8 returned after 23 ms, status code: 200, request body size: 0 B
05/15 13:02:36 Info: [stats] 16203mb Virtual, 3779mb Physical, 1336mb Managed, 833 Handles, 212 Threads
05/15 13:02:36 Debug: [easyhttp] [14099] GET to https://api.roonlabs.net/internetradio/2/api/stations/c8b60a73-c850-45e2-b91c-bf869c0df71f/metadata?format=msgpack&wait=True&timestamp=-1& returned after 203 ms, status code: 200, request body size: 0 B
05/15 13:02:37 Debug: [easyhttp] [14100] GET to https://liveaudio.rte.ie/hls-radio/ieradio1/chunklist.m3u8 returned after 28 ms, status code: 200, request body size: 0 B
05/15 13:02:40 Trace: [Office] [LowQuality, 24/44 AAC => 24/44] [100% buf] [PLAYING @ 2:29] The Louise Duffy Show
05/15 13:02:40 Debug: [easyhttp] [14101] GET to https://liveaudio.rte.ie/hls-radio/ieradio1/chunklist.m3u8 returned after 29 ms, status code: 200, request body size: 0 B
05/15 13:02:43 Debug: [easyhttp] [14102] GET to https://liveaudio.rte.ie/hls-radio/ieradio1/chunklist.m3u8 returned after 97 ms, status code: 200, request body size: 0 B
05/15 13:02:46 Trace: [client/sonos] av_status
05/15 13:02:46 Trace: [Office] [zoneplayer/sonos] state from device: STOPPED
05/15 13:02:46 Trace: [Office] [zoneplayer/sonos]  zoneplayer state: Playing
05/15 13:02:46 Trace: [Office] [zoneplayer/sonos] device stopped or paused by user, ending stream
05/15 13:02:46 Trace: [Office] [zoneplayer/sonos] State transition Playing => Disconnected
05/15 13:02:46 Trace: [endpoint/sonos/uuid:RINCON_347E5C313F1401400] check zone coordinator, device coordinator: RINCON_347E5C313F1401400, roon coordinator: RINCON_347E5C313F1401400
05/15 13:02:46 Trace: [client/sonos] timers stopped
05/15 13:02:46 Warn: [zone Office] Track Stopped Due to LostEndpoint
05/15 13:02:46 Trace: Attempting to play channel URL: hls://https%3a%2f%2fwww.rte.ie%2fmanifests%2fradio1.m3u8
05/15 13:02:46 Info: [zone Office] OnPlayFeedback StoppedLostEndpoint
05/15 13:02:46 Trace: [zone Office] Suspend
05/15 13:02:46 Info: [zone Office] OnPlayFeedback Stopped
05/15 13:02:46 Info: [zone Office] Canceling Pending Sleep
05/15 13:02:46 Info: [Office] [zoneplayer] Playing: channel://hls%3a%2f%2fhttps%253a%252f%252fwww.rte.ie%252fmanifests%252fradio1.m3u8
05/15 13:02:46 Info: [zone Office] Canceling Pending Sleep
05/15 13:02:46 Trace: [Office] [LowQuality, 24/44 AAC => 24/44] [100% buf] [PLAYING @ 2:29] The Louise Duffy Show
05/15 13:02:46 Trace: [Office] [LowQuality, 24/44 AAC => 24/44] [100% buf] [STOPPED @ 0:00] The Louise Duffy Show
05/15 13:02:46 Info: [Office] [zoneplayer] advance didn't change the track. returning short read
05/15 13:02:46 Trace: [roonapi] [apiclient 10.10.10.10:55478] CONTINUE Changed {"zones_changed":[{"zone_id":"160157fce0867df0bf4787a0b427313fe98c","display_name":"Office","outputs":[{"output_id":"170157fce0867df0bf4787a0b427313fe98c","zone_id":"160157fce0867df0bf4787a0b427313fe98c","can_group_with_output_ids":["1701cee07a64e1de0d7bd9a941d18df41827","170157fce0867df0bf4787a0b427313fe98c","170153b9bd9f118053a5cca8ca03b219e935","17018648ddaba98a8d147f0a577afadae7e3","170152a4b6acd98ae2aadd9b3ec6f8ba5fcf"],"display_name":"Office","volume":{"type":"number","min":0,"max":100,"value":14,"step":1,"is_muted":false,"hard_limit_min":0,"hard_limit_max":100,"soft_limit":100},"source_controls":[{"control_key":"1","display_name":"Office (ISK BOOKSHELF)","supports_standby":false,"status":"indeterminate"}]}],"state":"stopped","is_next_allowed":false,"is_previous_allowed":false,"is_pause_allowed":false,"is_play_allowed":true,"is_seek_allowed":false,"queue_items_remaining":1,"queue_time_remaining":43200,"settings":{"loop":"disabled","shuffle":false,"auto_radio":false},"now_playing":{"seek_position":null,"one_line":{"line1":"The Louise Duffy Show"},"two_line":{"line1":"RTE Radio 1","line2":"The Louise Duffy Show"},"three_line":{"line1":"RTE Radio 1","line2":"The Louise Duffy Show","line3":""},"image_key":"afd611ddf80b5dce68aa13b8e9e99aff8bf23d351d0918d67f032e52c91c6dc24882ed6107bcb78f714d78cf03afae00f38e3b8e823c3c6dd3cb71f675a91481f1c07c9518261b3af42728d0343bff634d98380aad3997c33d35cb0a3bc32763139f6c5db22951dc9ff0e30e822296fd"}}],"zones_seek_changed":[{"zone_id":"160157fce0867df0bf4787a0b427313fe98c","queue_time_remaining":43200,"seek_position":null}]}
05/15 13:02:46 Trace: [Office] [zoneplayer/sonos] reached end of stream, closing connection
05/15 13:02:46 Trace: [Office] [zoneplayer/sonos] transaction canceled, isplaying: False, did stream end: True, tx path: /24ec7095618e414abe13c77fc5b749a2/Roon7.flac, stream path: /24ec7095618e414abe13c77fc5b749a2/Roon7.flac, method: Get
05/15 13:02:46 Trace: [Office] [zoneplayer/sonos] endstream, zp state: Disconnected
05/15 13:02:46 Info: [audio/env] [zoneplayer -> stream] All streams were disposed
05/15 13:02:46 Trace: [Office] [zoneplayer/sonos] endstream, zp state: Disconnected
05/15 13:02:46 Trace: [Office] [zoneplayer/sonos] endstream, zp state: Disconnected
05/15 13:02:46 Trace: [Office] [zoneplayer/sonos] endstream, zp state: Disconnected

The same thing seems to happen whether it’s a Sonos or the iPad that I’m using.

I’m able to play the BBC 6 music stream on both devices for several hours without interruption.

Up until it cuts out, there are “stutters” every minute or so and the following is shown in the log

05/15 12:44:00 Warn: [Office] [zoneplayer/sonos] position timer reported next url, fix for bug 16980 triggered
05/15 12:44:00 Trace: [Office] [zoneplayer/sonos] position timer, advancing to next stream, reported reltime: 0:00:00, reported path: http://10.10.10.10:30004/f3240dc361c54f54a949a9ed0cbfa365/Roon3.flac
05/15 12:44:00 Trace: [Office] [zoneplayer/sonos] Switching to next stream path.  position offset: 101, max reported position: 151

Again, this doesn’t seem to occur with the BBC 6 Music stream.

The stream no longer works at all over Airplay, with the following shown in the log

Edit: I’ve just tried a different Sonos device of the same make/model and the Airplay works fine, so I suspect it’s something specific to the one in the kitchen. I’ll park this aspect for now as I can probably troubleshoot this myself.

Describe your network setup

Unifi Dream Machine Pro, Switches, wired network (apart from the iPad), 1GB internet, Roon Core running on an Intel Nuc.

benjamin · May 15, 2024, 9:56pm

Hi @Joe_C,

Thanks for writing in, and I’m sorry to hear you’re running into streaming issues! Based on your prior post:

Roon is actually not officially supported in a docker environment. While we’re not able to provide support for this setup, there is still a dedicated community over in Tinkering that can likely offer additional guidance. You do have my apologies about this!

Joe_C · May 16, 2024, 10:38am

Hi Benjamin,

By means of a test, I’ve moved the core onto my Macbook Pro and the same thing is occuring.

Stuttering:


05/16 11:34:19 Trace: [Office] [LowQuality, 24/22 AAC => 24/44] [PLAYING @ 3:12] Today with Claire Byrne
05/16 11:34:19 Debug: [easyhttp] [635] GET to https://liveaudio.rte.ie/hls-radio/ieradio1/chunklist.m3u8 returned after 45 ms, status code: 200, request body size: 0 B
05/16 11:34:20 Trace: [client/sonos] av_status
05/16 11:34:20 Trace: [Office] [zoneplayer/sonos] state from device: PLAYING
05/16 11:34:20 Trace: [Office] [zoneplayer/sonos]  zoneplayer state: Playing
05/16 11:34:20 Trace: [client/sonos] av_status
05/16 11:34:20 Trace: [Office] [zoneplayer/sonos] state from device: PLAYING
05/16 11:34:20 Trace: [Office] [zoneplayer/sonos]  zoneplayer state: Playing
05/16 11:34:20 Warn: [Office] [zoneplayer/sonos] position timer reported next url, fix for bug 16980 triggered
05/16 11:34:20 Trace: [Office] [zoneplayer/sonos] position timer, advancing to next stream, reported reltime: 0:00:00, reported path: http://10.10.10.222:30001/780c3d019d934a13a444fa372620463e/Roon2.flac
05/16 11:34:20 Trace: [Office] [zoneplayer/sonos] Switching to next stream path.  position offset: 142, max reported position: 194
05/16 11:34:22 Debug: [easyhttp] [636] GET to https://liveaudio.rte.ie/hls-radio/ieradio1/chunklist.m3u8 returned after 37 ms, status code: 200, request body size: 0 B
05/16 11:34:24 Trace: [Office] [LowQuality, 24/22 AAC => 24/44] [PLAYING @ 3:17] Today with Claire Byrne
05/16 11:34:25 Debug: [easyhttp] [637] GET to https://liveaudio.rte.ie/hls-radio/ieradio1/chunklist.m3u8 returned after 53 ms, status code: 200, request body size: 0 B
05/16 11:34:25 Debug: [easyhttp] [638] GET to https://liveaudio.rte.ie/hls-radio/ieradio1/media-ucc4gojjp_1035949.aac returned after 33 ms, status code: 200, request body size: 0 B
05/16 11:34:26 Debug: [easyhttp] [639] GET to https://liveaudio.rte.ie/hls-radio/ieradio1/chunklist.m3u8 returned after 41 ms, status code: 200, request body size: 0 B
05/16 11:34:29 Debug: [easyhttp] [640] GET to https://liveaudio.rte.ie/hls-radio/ieradio1/chunklist.m3u8 returned after 53 ms, status code: 200, request body size: 0 B
05/16 11:34:30 Trace: [Office] [LowQuality, 24/22 AAC => 24/44] [PLAYING @ 3:22] Today with Claire Byrne
05/16 11:34:30 Info: [stats] 404074mb Virtual, 415mb Physical, 276mb Managed

I’m just looking at the difference in times between how often the stuttering occurs:

11:33:28 to 11:34:20: 52 seconds
11:34:20 to 11:35:29: 69 seconds
11:35:29 to 11:36:38: 69 seconds
11:36:38 to 11:38:47: 129 seconds

I’ll leave it running to collect a larger sample of data in case that gives us any clues.

And eventually cuts out:

05/16 11:40:14 Debug: [easyhttp] [830] GET to https://liveaudio.rte.ie/hls-radio/ieradio1/chunklist.m3u8 returned after 39 ms, status code: 200, request body size: 0 B
05/16 11:40:15 Info: [stats] 404081mb Virtual, 426mb Physical, 286mb Managed
05/16 11:40:16 Trace: [Office] [LowQuality, 24/22 AAC => 24/44] [PLAYING @ 9:07] Today with Claire Byrne
05/16 11:40:17 Debug: [easyhttp] [831] GET to https://liveaudio.rte.ie/hls-radio/ieradio1/chunklist.m3u8 returned after 45 ms, status code: 200, request body size: 0 B
05/16 11:40:21 Debug: [easyhttp] [832] GET to https://liveaudio.rte.ie/hls-radio/ieradio1/chunklist.m3u8 returned after 51 ms, status code: 200, request body size: 0 B
05/16 11:40:22 Trace: [Office] [LowQuality, 24/22 AAC => 24/44] [PLAYING @ 9:13] Today with Claire Byrne
05/16 11:40:24 Debug: [easyhttp] [833] GET to https://liveaudio.rte.ie/hls-radio/ieradio1/chunklist.m3u8 returned after 46 ms, status code: 200, request body size: 0 B
05/16 11:40:26 Trace: [client/sonos] av_status
05/16 11:40:26 Trace: [Office] [zoneplayer/sonos] state from device: STOPPED
05/16 11:40:26 Trace: [Office] [zoneplayer/sonos]  zoneplayer state: Playing
05/16 11:40:26 Trace: [Office] [zoneplayer/sonos] device stopped or paused by user, ending stream
05/16 11:40:26 Trace: [Office] [zoneplayer/sonos] State transition Playing => Disconnected
05/16 11:40:26 Trace: [endpoint/sonos/uuid:RINCON_347E5C313F1401400] check zone coordinator, device coordinator: RINCON_347E5C313F1401400, roon coordinator: RINCON_347E5C313F1401400
05/16 11:40:26 Trace: [client/sonos] timers stopped
05/16 11:40:26 Warn: [zone Office] Track Stopped Due to LostEndpoint
05/16 11:40:26 Trace: Attempting to play channel URL: hls://https%3a%2f%2fwww.rte.ie%2fmanifests%2fradio1.m3u8
05/16 11:40:26 Info: [Office] [zoneplayer] Playing: channel://hls%3a%2f%2fhttps%253a%252f%252fwww.rte.ie%252fmanifests%252fradio1.m3u8
05/16 11:40:26 Info: [zone Office] OnPlayFeedback StoppedLostEndpoint
05/16 11:40:26 Trace: [zone Office] Suspend
05/16 11:40:26 Info: [zone Office] OnPlayFeedback Stopped
05/16 11:40:26 Info: [zone Office] Canceling Pending Sleep
05/16 11:40:26 Info: [zone Office] Canceling Pending Sleep
05/16 11:40:26 Trace: [Office] [zoneplayer/sonos] endstream, zp state: Disconnected
05/16 11:40:26 Trace: [Office] [LowQuality, 24/22 AAC => 24/44] [STOPPED @ 0:00] Today with Claire Byrne
05/16 11:40:26 Info: [audio/env] [zoneplayer -> stream] All streams were disposed
05/16 11:40:26 Trace: [Office] [zoneplayer/sonos] endstream, zp state: Disconnected
05/16 11:40:26 Trace: [Office] [zoneplayer/sonos] endstream, zp state: Disconnected
05/16 11:40:26 Trace: [Office] [zoneplayer/sonos] endstream, zp state: Disconnected
05/16 11:40:26 Trace: [Office] [zoneplayer/sonos] got http request while zoneplayer was in non-playing state, closing connnection
05/16 11:40:26 Trace: [Office] [zoneplayer/sonos] transaction canceled, isplaying: False, did stream end: False, tx path: /535d120699df4b92a2e0f9003b80f4a8/Roon5.flac, stream path: /535d120699df4b92a2e0f9003b80f4a8/Roon5.flac, method: Get
05/16 11:40:26 Trace: [roondns] flushed 8 last-known-good entries
05/16 11:40:26 Debug: [easyhttp] [836] GET to https://www.rte.ie/manifests/radio1.m3u8 returned after 161 ms, status code: 200, request body size: 0 B
05/16 11:40:26 Debug: [easyhttp] [837] GET to https://liveaudio.rte.ie/hls-radio/ieradio1/chunklist.m3u8 returned after 37 ms, status code: 200, request body size: 0 B
05/16 11:40:26 Debug: [easyhttp] [838] GET to https://liveaudio.rte.ie/hls-radio/ieradio1/media-ucc4gojjp_1035983.aac returned after 45 ms, status code: 200, request body size: 0 B
05/16 11:40:26 Info: [Office] [zoneplayer]     Open Result (Playing):Result[Status=Success]
05/16 11:40:26 Info: [Office] [zoneplayer] Aborting play because track changed
05/16 11:40:27 Debug: [easyhttp] [835] POST to https://api.roonlabs.net/internetradio/2/api/reporting/internetradioplayback/events?format=msgpack& returned after 449 ms, status code: 200, request body size: 171 B
05/16 11:40:27 Warn: [streammediafile] error reading stream: ObjectDisposed_StreamClosed
05/16 11:40:27 Debug: [easyhttp] [839] POST to https://api.roonlabs.net/internetradio/2/api/reporting/internetradioplayback/plays?format=msgpack& returned after 224 ms, status code: 400
05/16 11:40:27 Debug: [easyhttp] [834] POST to https://api.roonlabs.net/internetradio/2/api/reporting/internetradioplayback/events?format=msgpack& returned after 850 ms, status code: 200, request body size: 172 B
05/16 11:40:27 Debug: [easyhttp] [840] POST to https://api.roonlabs.net/internetradio/2/api/reporting/internetradioplayback/plays?format=msgpack& returned after 405 ms, status code: 200, request body size: 176 B
05/16 11:40:30 Info: [stats] 404077mb Virtual, 426mb Physical, 290mb Managed
cat: -n1000: No such file or directory

So, just to confirm, this is not due to using Docker.

Thanks,

Joe

system · May 30, 2024, 10:39am

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