Internet Radio: Too Many Dropouts, Killing Stream, Only Happens with Roon

rcrawley · August 5, 2022, 12:15am

Roon Core Machine

MacOS Montery
MacBook Pro (13-inch, 2017, Four Thunderbolt 3 Ports)
3.5 GHz Dual-Core Intel Core i7
16 GB 2133 MHz LPDDR3

DB on MBP SSD, Library on directly connected USB-3 HD

Networking Gear & Setup Details

MBP ethernet to network

Connected Audio Devices

Streaming to a hardwired Cambridge Audio 851N

Number of Tracks in Library

Description of Issue

I routinely have dropouts when streaming internet radio stations through Roon to my Cambridge 851N (see logs below), usually within 15 mins of starting the stream, and I’ve reproduced it with the following radio stations repeatably:

Dash Radio: 80s
Radio Paradise: Mellow Mix
SomaFM: Illinois Street Lounge

The 851N can stream internet radio directly, and using the same endpoint links as Roon uses it never drops the streams. I accidentally left Soma playing overnight the other night and it was still going strong in the morning. This is just an issue with Roon streaming internet radio. I don’t know with which version it started but it’s somewhat recent, causing issues over the past 3 months, never had a problem before that.

Logs from a stopped stream:

08/04 17:06:19 Trace: [Music-Room-851N] [LowQuality, 24/44 MP3 => 32/44] [PLAYING @ 19:40] The Doobie Brothers - One Step Closer
08/04 17:06:20 Trace: [Cambridge Audio 851N @ 192.168.1.250:35201] [raatclient] GOT [17] {"samples":140732,"status":"Dropout"}
08/04 17:06:20 Warn: [Music-Room-851N] [zoneplayer/raat] Too many dropouts (>3s dropped out in the last 30s). Killing stream
08/04 17:06:20 Trace: [Music-Room-851N] [zoneplayer/raat] too many dropouts. stopping stream
08/04 17:06:20 Trace: [Music-Room-851N] [zoneplayer/raat] Endpoint Cambridge Audio 851N State Changed: Playing => Prepared
08/04 17:06:20 Trace: [Cambridge Audio 851N @ 192.168.1.250:35201] [raatclient] SENT [19209]{"request":"end_stream"}
08/04 17:06:20 Warn: [zone Music-Room-851N] Track Stopped Due to Slow Media
08/04 17:06:20 Trace: Attempting to play channel URL: icy://ice55.securenetsystems.net/DASH7
08/04 17:06:20 Debug: [raat/tcpaudiosource] disconnecting
08/04 17:06:20 Info: [zone Music-Room-851N] OnPlayFeedback StoppedEndOfMediaUnnatural
08/04 17:06:20 Info: [zone Music-Room-851N] OnPlayFeedback Stopped
08/04 17:06:20 Info: [zone Music-Room-851N] Canceling Pending Sleep
08/04 17:06:20 Warn: [streammediafile] error reading stream: Unable to read data from the transport connection: interrupted.
08/04 17:06:20 Info: [zone Music-Room-851N] Canceling Pending Sleep
08/04 17:06:20 Trace: [Music-Room-851N] [LowQuality, 24/44 MP3 => 32/44] [STOPPED @ 0:00] The Doobie Brothers - One Step Closer
08/04 17:06:20 Info: [Music-Room-851N] [zoneplayer] advance didn't change the track. returning short read
08/04 17:06:20 Warn: [raat/tcpaudiosource] send failed: Object reference not set to an instance of an object
08/04 17:06:20 Warn: [raat/tcpaudiosource] disconnecting + retrying
08/04 17:06:20 Info: [audio/env] [zoneplayer -> stream] All streams were disposed
08/04 17:06:20 Info: [audio/env] [zoneplayer] All streams were disposed
08/04 17:06:20 Info: [audio/env] [zoneplayer -> stream -> endpoint] All streams were disposed
08/04 17:06:20 Trace: [Cambridge Audio 851N @ 192.168.1.250:35201] [raatclient] GOT [17] {"status":"Ended"}
08/04 17:06:20 Trace: [Cambridge Audio 851N @ 192.168.1.250:35201] [raatclient] GOT [19209] {"status":"Success"}
08/04 17:06:20 Info: sleep 57ms after flush
08/04 17:06:20 Info: [Music-Room-851N] [zoneplayer] Playing: channel://icy%3a%2f%2fice55.securenetsystems.net%2fDASH7
08/04 17:06:20 Trace: [Cambridge Audio 851N @ 192.168.1.250:35201] [raatclient] GOT [15] {"message":{"signal_path":[{"from_sample_rate":44100,"to_sample_rate":384000,"type":"pcm_sample_rate_conversion","quality":"enhanced"},{"method":"analog_digital","type":"output","quality":"lossless"}]},"status":"OutputMessage"}
08/04 17:06:20 Debug: [easyhttp] [56501] POST to https://internetradio.roonlabs.net/2/api/reporting/internetradioplayback/events?format=msgpack& returned after 116 ms, status code: 200
08/04 17:06:20 Trace: [Cambridge Audio 851N @ 192.168.1.250:35201] [raatclient] GOT [15] {"message":{"signal_path":[{"from_sample_rate":-1,"to_sample_rate":384000},{"method":"analog_digital","type":"output","quality":"lossless"}]},"status":"OutputMessage"}
08/04 17:06:20 Warn: [Music-Room-851N] [zoneplayer/raat] invalid signal path element: {"from_sample_rate":-1,"to_sample_rate":384000}
08/04 17:06:20 Warn: [Music-Room-851N] [zoneplayer/raat] Sooloos.JSONExtensions.JSONException: JSON: missing required string field: type
  at Sooloos.JSONExtensions.Extensions.GetString (System.Object o, System.String key) [0x0001a] in <1ccbcb5fed3a40f7a534108821e72cb1>:0 
  at Sooloos.Broker.Transport.RaatZonePlayer.ev_output_message (Sooloos.Broker.Transport.RaatZonePlayer+Endpoint ep, Base.JDictionary msg) [0x0003f] in <fd53df64aac649f186347feb51fef640>:0 
08/04 17:06:20 Debug: [easyhttp] [56503] POST to https://internetradio.roonlabs.net/2/api/reporting/internetradioplayback/plays?format=msgpack& returned after 116 ms, status code: 200
08/04 17:06:20 Trace: Got ICY Stream Title [The Doobie Brothers - One Step Closer]
08/04 17:06:20 Warn: [Music-Room-851N] [zoneplayer/raat] long rtt sync Cambridge Audio 851N: realtime=1182368726333 rtt=199500us offset=-53022716273us delta=173503us drift=298067us in 1181.4045s (252.299ppm, 908.277ms/hr)
08/04 17:06:20 Info: [Music-Room-851N] [zoneplayer]     Open Result (Playing):Result[Status=Success]
08/04 17:06:20 Info: [Music-Room-851N] [zoneplayer] Aborting play because track changed
08/04 17:06:20 Warn: [streammediafile] error reading stream: Unable to read data from the transport connection: interrupted.
08/04 17:06:20 Info: [audio/env] [zoneplayer] All streams were disposed
08/04 17:06:20 Debug: [easyhttp] [56502] POST to https://internetradio.roonlabs.net/2/api/reporting/internetradioplayback/events?format=msgpack& returned after 413 ms, status code: 200
08/04 17:06:20 Debug: [easyhttp] [56504] POST to https://internetradio.roonlabs.net/2/api/reporting/internetradioplayback/plays?format=msgpack& returned after 109 ms, status code: 400

rcrawley · August 13, 2022, 7:14pm

I was able to reproduce this on another RoonCore (NAS) on a Dash stream with the same behavior but slightly different error messages (see below). While I was testing I was also streaming the same Dash channel directly via a Chromecast device (which has been streaming all morning) with no issue, it continued to play.

Other things I’ve tested:

Disabling DSP for the Cambridge, same result
Changing the stream from HTTP to HTTPS, which seems to make things more stable on the NAS (although that doesn’t make sense to me b/c the resulting icy stream is the same:

08/13 12:06:55 Debug: [easyhttp] [4480] GET to https://ice55.securenetsystems.net/DASH7 returned after 959 ms, status code: 200
08/13 12:06:55 Trace: Attempting to play channel URL: icy://ice55.securenetsystems.net/DASH7

Error from NAS logs on HTTP failure:

08/13 11:52:27 Info: [Music-Room-851N] [zoneplayer] advance didn't change the track. returning short read
08/13 11:52:27 Warn: [streammediafile] error reading stream: Unable to read data from the transport connection: Software caused connection abort.
08/13 11:52:27 Warn: [zone Music-Room-851N] Track Stopped Due to Slow Media
08/13 11:52:27 Trace: Attempting to play channel URL: icy://ice55.securenetsystems.net/DASH7
08/13 11:52:27 Trace: [Cambridge Audio 851N @ 192.168.1.250:40561] [raatclient] SENT [16682]{"request":"end_stream"}
08/13 11:52:27 Debug: [raat/tcpaudiosource] disconnecting
08/13 11:52:27 Warn: [raat/tcpaudiosource] send failed: Object reference not set to an instance of an object.
08/13 11:52:27 Warn: [raat/tcpaudiosource] disconnecting + retrying
08/13 11:52:27 Info: [zone Music-Room-851N] OnPlayFeedback StoppedEndOfMediaUnnatural
08/13 11:52:27 Info: [zone Music-Room-851N] OnPlayFeedback Stopped
08/13 11:52:27 Info: [zone Music-Room-851N] Canceling Pending Sleep
08/13 11:52:27 Info: [zone Music-Room-851N] Canceling Pending Sleep
08/13 11:52:27 Trace: [Music-Room-851N] [LowQuality, 24/44 MP3 => 32/44] [100% buf] [STOPPED @ 0:00] Mark Moseley - Jewels Of Denial
08/13 11:52:27 Info: [audio/env] [zoneplayer -> stream] All streams were disposed
08/13 11:52:27 Info: [audio/env] [zoneplayer -> stream -> endpoint] All streams were disposed
08/13 11:52:27 Info: [audio/env] [zoneplayer] All streams were disposed
08/13 11:52:27 Trace: [Cambridge Audio 851N @ 192.168.1.250:40561] [raatclient] GOT [14463] {"status":"Ended"}

Wes · August 16, 2022, 9:28pm

Hi @rcrawley,

I took an independent look at your logs and found the exact same thing. I don’t have an immediate answer for your woes but will check with our teams to see what they think could be going on.

In the meantime, please give restarting your router and core (in that order) a shot. I will hopefully have an answer as to what else could be going on here in the next day or two.

Thanks,
Wes

rcrawley · August 18, 2022, 5:11pm

Thanks @Wes. I ran another test overnight and this morning by streaming Dash7 (80s) overnight to a hardwired Pi running RoonBridge and it was still streaming this morning when I woke up, it never stopped and ran completely fine.

In contrast, I started a new stream to the Cambridge this morning and it died after 20 mins (started at 9:44 AM, died at 10:04 AM). And as previously mentioned, I did a similar test streaming from the Cambridge directly without Roon (using Soma.fm) overnight and it, too, was still playing the next morning. So it’s pointing to something between RoonServer and Cambridge’s Roon support IMO. I also verified I’m running the latest firmware on the 851N (and Early Update is disabled).

Hope that helps, and thanks again for looking into this.

Wes · August 19, 2022, 6:40pm

Hi @rcrawley,

You have somewhat stumped us. We’re looking in logs and not seeing a culprit here. Can you please verify with me how the 851N is connected to your network? Also, can you please try connecting it via USB to see if the situation is still the same?

Thanks,
Wes

rcrawley · August 20, 2022, 8:09pm

Hi @Wes. The 851N is hardwired via ethernet directly into a network switch. The two Roon cores I’ve tested (never on at the same time), along with the Pi I use for testing, are all also hardwired into the same network switch, so the path between either Roon core and the Roon clients are always ethernet.

I’ve been successfully streaming to the 851N from either core by changing the Dash URL to HTTPS, and can reliably see the stream die when using HTTP, FWIW. The working URL is https://ice55.securenetsystems.net/DASH7

I don’t follow the USB ask. What do you want me to connect via USB?

Thanks!

Wes · August 23, 2022, 4:13pm

@rcrawley,

Sorry for the slow response. I’ve been out of the office so far this week.

RE USB functionality: Yes, please. It will tell us a lot about what’s happening by using a completely different connectivity method.

Wes

rcrawley · September 1, 2022, 3:12pm

@Wes I tested the 851N’s USB connection this weekend and it worked flawlessly, no issues at all with USB into the 851N. I also streamed Dash7 for a full day through Roon after changing the URL from HTTP to HTTPS (had to create a manual version of that station b/c I can’t edit the source of one that ships with Roon, as this one does).

Hope that helps.

system · October 16, 2022, 3:13pm

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