Many problems with Roon w.r.t networking

Peter_Galvin1 · February 19, 2020, 10:28pm

Over a long time I’ve had problems with Roon w.r.t networking.
On an imac, latest macos, latest Roon.
For example I’ll do a search (including my tracks and tidal), roon won’t find anything in Tidal, but using Tidal directly works fine.
Sometimes Roon will say there is a network problem. Even though no other apps have network problems and tidal works fine directly. Did Roon implement its own network stack? It seems much touchier about networking that my system or other apps.
Some screen shots.
Searching for John Cage within Roon:

The same search within Tidal directly:

Trying to get roon to identify an album - sometimes it shows nothing. Repeating say 10 times finally I get an album match to show.
(upload://asF0gFbGWE2MNZQvfoeBKKBBuVe.jpeg)

Peter_Galvin1 · February 19, 2020, 10:05pm

iMac, running current MacOS and current Roon.

Probably every other search or attempt to play something from Tidal via Roon is failing.

Sometimes it fails a few times and then works if I keep trying it.

Sometimes it fails silently (as in the john cage search image below) while sometimes I get a network error.

There is nothing wrong with my network. No other errors from any other apps, and using tidal directly works without fail. This is a problem of Roon calling out to Tidal.

Would be great if this could be solved. One of my many frustrations with Roon.

noris · February 20, 2020, 4:09am

Hi @Peter_Galvin1,

Is the behavior the same if you reboot your Core and networking gear? We also just updated Roon to build 521, can you please check to see if the same behavior is occurring on the new version of Roon?

Peter_Galvin1 · February 21, 2020, 4:46pm

Restart of Roon and reboot of core doesn’t seem to fix it.
Updating to latest doesn’t seem to fix it.
Today I was listening to Cage the Elephant’s album “Social Cues” via roon, from Tidal.
I paused it for a minute. Clicked play to continue it.
Each track tried to play for a few seconds, then timed, out, then roon gave up:

Then I searched for Dexter Gordon “Homecoming”, roon found it on Tidal, but when I tried to play got errors on each track that it wasn’t available etc:

Meanwhile, I run tidal on the same system, do the same search, hit play, and it plays fine.

noris · February 22, 2020, 3:58am

Hi @Peter_Galvin1,

Which region is your TIDAL account on? I wasn’t able to locate Homecoming on my end as an available TIDAL album.

If you experience this behavior again, can you please check to see if it occurs for multiple endpoints? Or just one in particular?

Peter_Galvin1 · February 26, 2020, 4:15pm

Hmm not sure of the official region but I’m in the Boston USA area.
Confirmed the same problem with multiple endpoints (i.e. it’s a core problem).

noris · February 26, 2020, 5:24pm

Hi @Peter_Galvin1,

Thanks for confirming this is a Core issue. How are your DNS servers set up?

Are you using the default ISP one’s or Google/Cloudflare/Quad9?

I wonder if this could be some bad DNS queries going through your ISP’s server.

Peter_Galvin1 · February 26, 2020, 5:39pm

Using Google: 8.8.8.8 and 8.8.4.4.

noris · February 28, 2020, 6:37am

Hi @Peter_Galvin1,

Thanks for confirming the DNS servers. The errors you are seeing do seem to point to a networking issue somewhere along the line.

Can you provide an overview of your networking setup including model/manufacturer of all your gear? Are you using any switches/powerline adapters/range extenders in this setup?

How is your Core connected, over WiFI or Ethernet? If on WiFi, is there any change in behavior if you connect via Ethernet?

Peter_Galvin1 · February 28, 2020, 8:34pm

Will have a look around my network. Odd nothing else is complaining.

Peter_Galvin1 · March 27, 2020, 4:59pm

Further evidence that the problem is in Roon, not my network.
Same album, found via roon and via tidal on the same system at the same time.
Plays fine in Tidal. Error in Roon.

noris · March 31, 2020, 4:32am

Hi @Peter_Galvin1,

Can you please let me know the exact local time + date you next receive this message in Roon? I can enable diagnostics after receiving the timestamp, thanks.

Peter_Galvin1 · March 31, 2020, 1:35pm

2020-03-27 at 12:50:41PM EDT

noris · April 2, 2020, 1:53am

Hi @Peter_Galvin1,

Thanks for letting me know the timestamp. Is this timestamp is for the Freddie King screenshot you posted above?

Unfortunately, I am not seeing any logs from your iMac being delivered to our servers. Can you please use these instructions to upload a manual set for analysis?

Peter_Galvin1 · April 4, 2020, 7:08pm

I just tried playing W.O.L.D by Harry Chapin via Roon from Tidal. Failed with network error. Retried and got error “This track is currently not available from Tidal”, Then Too many playback errors, etc.
Meanwhile Tidal app on the same system played it without error.
here is the log from around that time:

04/04 15:00:12 Info: 
--[ SignalPath ]---------------------------------------------
SignalPath Quality = Lossless
Elements:
    Source Format=Flac 44100/16/2  Quality=Lossless
    Raat Device=snd_rpi_rpi_dac
    Output OutputType=Local_Alsa Quality=Lossless SubType= Model=snd_rpi_rpi_dac
------------------------------------------------------------
04/04 15:00:12 Trace: [roonapi] [apiclient 192.168.1.53:39534] CONTINUE Changed {"zones_changed":[{"zone_id":"16011c46b181259d2cf5a5b5cbb212f4e5dd","display_name":"Pi","outputs":[{"output_id":"17011c46b181259d2cf5a5b5cbb212f4e5dd","zone_id":"16011c46b181259d2cf5a5b5cbb212f4e5dd","can_group_with_output_ids":["17011c46b181259d2cf5a5b5cbb212f4e5dd"],"display_name":"Pi","source_controls":[{"control_key":"1","display_name":"snd_rpi_rpi_dac","supports_standby":false,"status":"indeterminate"}]}],"state":"stopped","is_next_allowed":false,"is_previous_allowed":true,"is_pause_allowed":false,"is_play_allowed":false,"is_seek_allowed":false,"queue_items_remaining":0,"queue_time_remaining":0,"settings":{"loop":"disabled","shuffle":false,"auto_radio":false}}],"zones_seek_changed":[{"zone_id":"16011c46b181259d2cf5a5b5cbb212f4e5dd","queue_time_remaining":0}]}
04/04 15:00:13 Trace: [streamingmediafile] finished caching http://sp-pr-cf.audio.tidal.com/mediatracks/CAEaKRInOWI3Zjc0YWI1NzhmMzdhYTI4YjZjZTdiOTZkOGQ5MjRfNjEubXA0/0.flac
04/04 15:00:13 Debug: [smc] [zoneplayer:3] Removing ordinal 124
04/04 15:00:13 Debug: [smc] [zoneplayer:3] Destroyed domain
04/04 15:00:15 Trace: [zone Pi] Playing 1 Items
04/04 15:00:15 Trace: [zone Pi] Selecting Source state=Stopped
04/04 15:00:15 Info: [zone Pi] OnPlayFeedback Stopped
04/04 15:00:15 Debug: [smc] [zoneplayer:3] Created domain
04/04 15:00:15 Debug: [smc] [zoneplayer:3] Removing ordinal 124
04/04 15:00:15 Info: [audio/env] [zoneplayer -> stream] All streams were disposed
04/04 15:00:15 Debug: [smc] [zoneplayer:3] Destroyed domain
04/04 15:00:15 Trace: [zone Pi] Playing TransportItem
04/04 15:00:15 Trace: [zone Pi] Selecting Source state=Stopped
04/04 15:00:15 Trace: [zone Pi] queue got oversized. trimming 1 items from start
04/04 15:00:15 Debug: [zone Pi] Remove(1 items, for_replace=False)
04/04 15:00:15 Info: after removeall ordered count 5000 shuffle count 5000
04/04 15:00:15 Info: [audio/env] [zoneplayer] All streams were disposed
04/04 15:00:15 Debug: [raat/tcpaudiosource] disconnecting
04/04 15:00:15 Info: [audio/env] [zoneplayer -> stream -> endpoint] All streams were disposed
04/04 15:00:15 Info: sleep 39ms after flush
04/04 15:00:15 Trace: [Pi] [Lossless, 16/44 TIDAL FLAC => 16/44] [1% buf] [LOADING @ 0:00] W.O.L.D. - The Chapin Family
04/04 15:00:15 Trace: [musicpowerstate] music is playing, preventing idle sleep
04/04 15:00:15 Trace: [roonapi] [apiclient 192.168.1.53:39534] CONTINUE Changed {"zones_changed":[{"zone_id":"16011c46b181259d2cf5a5b5cbb212f4e5dd","display_name":"Pi","outputs":[{"output_id":"17011c46b181259d2cf5a5b5cbb212f4e5dd","zone_id":"16011c46b181259d2cf5a5b5cbb212f4e5dd","can_group_with_output_ids":["17011c46b181259d2cf5a5b5cbb212f4e5dd"],"display_name":"Pi","source_controls":[{"control_key":"1","display_name":"snd_rpi_rpi_dac","supports_standby":false,"status":"indeterminate"}]}],"state":"loading","is_next_allowed":false,"is_previous_allowed":true,"is_pause_allowed":true,"is_play_allowed":false,"is_seek_allowed":false,"queue_items_remaining":1,"queue_time_remaining":321,"settings":{"loop":"disabled","shuffle":false,"auto_radio":false},"now_playing":{"seek_position":null,"length":321,"one_line":{"line1":"W.O.L.D. - The Chapin Family"},"two_line":{"line1":"W.O.L.D.","line2":"The Chapin Family"},"three_line":{"line1":"W.O.L.D.","line2":"The Chapin Family","line3":"Harry Chapin: A Celebration In Song (Volume I)"},"image_key":"4e58d73e0e90052294a1425dbcbc939078ed042d692b685c5497ac5628be8b4728dce89c57a67c6fd1c4aed54461b38520bfb5c5af359d95658b081aae78fb5ccc6f66165d6830fd8f9aa1f74f1adba372aaa53929187f056a1f0c3433db5473da3010fe0f5a8e69fae84b1dfb5c271a"}}],"zones_seek_changed":[{"zone_id":"16011c46b181259d2cf5a5b5cbb212f4e5dd","queue_time_remaining":321,"seek_position":null}]}
04/04 15:00:15 Trace: [dbperf] flush 0 bytes, 0 ops in 9 ms (cumulative 1516473877 bytes, 757531 ops in 646100 ms)
04/04 15:00:15 Warn: [easyhttp] [539] web exception without response: Error: SecureChannelFailure (Unable to write data to the transport connection: The socket is not connected.)
04/04 15:00:15 Warn: [easyhttp] [542] web exception without response: Error: SecureChannelFailure (Unable to write data to the transport connection: The socket is not connected.)
04/04 15:00:15 Warn: [easyhttp] [543] web exception without response: Error: SecureChannelFailure (Unable to write data to the transport connection: The socket is not connected.)
04/04 15:00:15 Warn: [easyhttp] [544] web exception without response: Error: SecureChannelFailure (Unable to write data to the transport connection: The socket is not connected.)
04/04 15:00:15 Warn: [easyhttp] [545] web exception without response: Error: SecureChannelFailure (Unable to write data to the transport connection: The socket is not connected.)
04/04 15:00:15 Warn: [easyhttp] [546] web exception without response: Error: SecureChannelFailure (Unable to write data to the transport connection: The socket is not connected.)
04/04 15:00:15 Warn: [easyhttp] [547] web exception without response: Error: SecureChannelFailure (Unable to write data to the transport connection: The socket is not connected.)
04/04 15:00:15 Warn: [easyhttp] [549] web exception without response: Error: SecureChannelFailure (Unable to write data to the transport connection: The socket is not connected.)
04/04 15:00:15 Warn: [easyhttp] [550] web exception without response: Error: SecureChannelFailure (Unable to write data to the transport connection: The socket is not connected.)
04/04 15:00:15 Warn: [easyhttp] [551] web exception without response: Error: SecureChannelFailure (Unable to write data to the transport connection: The socket is not connected.)
04/04 15:00:15 Warn: [easyhttp] [553] web exception without response: Error: SecureChannelFailure (Unable to write data to the transport connection: The socket is not connected.)
04/04 15:00:15 Warn: [easyhttp] [552] web exception without response: Error: SecureChannelFailure (Unable to write data to the transport connection: The socket is not connected.)
04/04 15:00:15 Trace: [tidal/http] GET https://api.tidal.com/v1/tracks/46250560/playbackinfopostpaywall?countryCode=US&audioquality=HI_RES&assetpresentation=FULL&playbackmode=STREAM => Success
04/04 15:00:15 Trace: [tidal/http] GET https://api.tidal.com/v1/tracks/46250560?countryCode=US => Success
04/04 15:00:15 Info: [Pi] [zoneplayer] Playing: http://sp-pr-cf.audio.tidal.com/mediatracks/CAEaKRInZDM3MjU1ZjU1MDNkYmQ5MDA4YjFjOTFhMTBjYzhkN2JfNjEubXA0/0.flac
04/04 15:00:15 Debug: [smc] [zoneplayer:3] Created domain
04/04 15:00:15 Debug: [smc] [zoneplayer:3] Adding ordinal 125
04/04 15:00:15 Debug: [easyhttp] [548] GET to https://metadata.roonlabs.net/1/performers/122:0:MN0002331031/refs?c=tidal-us returned after 129 ms, status code: 200
04/04 15:00:15 Debug: GMS: saving nav stack
04/04 15:00:15 Debug: GMS: trying to save nav stack, but nav stack stuff was in progress
04/04 15:00:15 Debug: GMS: done saving nav stack
04/04 15:00:16 Trace: [streamingmediafile] retrying request due to Error writing headers
04/04 15:00:16 Debug: [easyhttp] [541] GET to https://imagecache.roonlabs.net/im/1/albums/a6003436323530353538/cover/402.jpg returned after 361 ms, status code: 200
04/04 15:00:16 Debug: [easyhttp] [540] GET to https://imagecache.roonlabs.net/im/1/albums/a6003436323530353538/cover/402.jpg returned after 600 ms, status code: 200
04/04 15:00:16 Trace: [streamingmediafile] retrying request due to Error writing headers
04/04 15:00:16 Trace: [streamingmediafile] retrying request due to Error writing headers
04/04 15:00:17 Trace: [streamingmediafile] retrying request due to Error writing headers
04/04 15:00:17 Warn: [streamingmediafile] caching http://sp-pr-cf.audio.tidal.com/mediatracks/CAEaKRInZDM3MjU1ZjU1MDNkYmQ5MDA4YjFjOTFhMTBjYzhkN2JfNjEubXA0/0.flac failed: System.Net.WebException: Error writing headers ---> System.IO.IOException: Unable to write data to the transport connection: The socket is not connected. ---> System.Net.Sockets.SocketException: The socket is not connected
  at System.Net.Sockets.Socket.EndSend (System.IAsyncResult asyncResult) [0x00012] in <bc69ad8632744cfba18f9705e53c6302>:0 
  at System.Net.Sockets.NetworkStream.EndWrite (System.IAsyncResult asyncResult) [0x00057] in <bc69ad8632744cfba18f9705e53c6302>:0 
   --- End of inner exception stack trace ---
  at System.Net.Sockets.NetworkStream.EndWrite (System.IAsyncResult asyncResult) [0x0009b] in <bc69ad8632744cfba18f9705e53c6302>:0 
  at System.IO.Stream+<>c.<BeginEndWriteAsync>b__58_1 (System.IO.Stream stream, System.IAsyncResult asyncResult) [0x00000] in <ba70b91736bd40cb990a357097dba9c3>:0 
  at (wrapper delegate-invoke) System.Func`3[System.IO.Stream,System.IAsyncResult,System.Threading.Tasks.VoidTaskResult].invoke_TResult_T1_T2(System.IO.Stream,System.IAsyncResult)
  at System.Threading.Tasks.TaskFactory`1+FromAsyncTrimPromise`1[TResult,TInstance].Complete (TInstance thisRef, System.Func`3[T1,T2,TResult] endMethod, System.IAsyncResult asyncResult, System.Boolean requiresSynchronization) [0x00000] in <ba70b91736bd40cb990a357097dba9c3>:0 
--- End of stack trace from previous location where exception was thrown ---

  at System.Net.WebRequestStream.SetHeadersAsync (System.Boolean setInternalLength, System.Threading.CancellationToken cancellationToken) [0x001d4] in <bc69ad8632744cfba18f9705e53c6302>:0 
   --- End of inner exception stack trace ---
  at System.Net.WebRequestStream.SetHeadersAsync (System.Boolean setInternalLength, System.Threading.CancellationToken cancellationToken) [0x00221] in <bc69ad8632744cfba18f9705e53c6302>:0 
  at System.Net.WebRequestStream.Initialize (System.Threading.CancellationToken cancellationToken) [0x000d5] in <bc69ad8632744cfba18f9705e53c6302>:0 
  at System.Net.WebOperation.Run () [0x0012c] in <bc69ad8632744cfba18f9705e53c6302>:0 
  at System.Net.WebCompletionSource`1[T].WaitForCompletion () [0x00094] in <bc69ad8632744cfba18f9705e53c6302>:0 
  at System.Net.HttpWebRequest.RunWithTimeoutWorker[T] (System.Threading.Tasks.Task`1[TResult] workerTask, System.Int32 timeout, System.Action abort, System.Func`1[TResult] aborted, System.Threading.CancellationTokenSource cts) [0x000f8] in <bc69ad8632744cfba18f9705e53c6302>:0 
  at System.Net.HttpWebRequest.EndGetResponse (System.IAsyncResult asyncResult) [0x00020] in <bc69ad8632744cfba18f9705e53c6302>:0 
  at Sooloos.Media.StreamingMediaFileImpl+<>c__DisplayClass11_1.<_StartBuffering>b__1 (System.IAsyncResult resp_ar) [0x00002] in <8061a44bcbb94e199a23491d999d3f88>:0 
04/04 15:00:17 Error: [seekableurimediafile] while determining length: System.IO.IOException: streaming media failed due to network
  at Sooloos.Media.StreamingMediaFileImpl.get_Length () [0x00038] in <8061a44bcbb94e199a23491d999d3f88>:0 
  at Sooloos.Media.StreamingMediaFile.get_Length () [0x00000] in <8061a44bcbb94e199a23491d999d3f88>:0 
  at Sooloos.Media.CachingSeekableUriMediaFile.LengthCallback (System.IntPtr userdata, System.Int64& out_length) [0x00017] in <8061a44bcbb94e199a23491d999d3f88>:0 
04/04 15:00:17 Debug: [smc] [zoneplayer:3] Removing ordinal 125
04/04 15:00:17 Debug: [smc] [zoneplayer:3] Destroyed domain
04/04 15:00:17 Warn: [zoneplayer] Corrupt Media Detected
04/04 15:00:17 Info: [Pi] [zoneplayer]     Open Result (Playing):Result[Status=CorruptMedia]
04/04 15:00:17 Warn: [zoneplayer] couldn't play URL http://sp-pr-cf.audio.tidal.com/mediatracks/CAEaKRInZDM3MjU1ZjU1MDNkYmQ5MDA4YjFjOTFhMTBjYzhkN2JfNjEubXA0/0.flac?Expires=1586030415&Signature=OlglDjZKViIzEAT9A~rFVkO5PvtrMbH-cKYbHE-WvcdX95XoS5UGJgsQlkxvDpFVFbq9-AtMJge6NKrM2tVsQVAnfdHcOhsuJALmaFdWvLrWAz8ZKuQ26Hw~fpfTKnkpTpGUSOgoB-FMWuAbStpQlO696Z00vRNxDWpOlb3gtfjeC2iTNJtxlqkSwjxW9G-7aorjaO47r7V2hjzSLoIPEdaCXqPEQEgAEaBCaHG2dy4MfARlZwIEN0gzBUn8SSQHtlZyplP~wbk~-Ar7xFiUw665j3uMECv~8a260CACbJuxA8lI-8WkvGxXBVVDIXab0pAG3yTHho~w9GWOCf5aFg__&Key-Pair-Id=APKAIZ3WPBE4R6SP555A: corrupt media
04/04 15:00:17 Warn: Track Stopped Due to Bad Media
04/04 15:00:17 Info: [zone Pi] OnPlayFeedback StoppedEndOfMediaUnnatural
04/04 15:00:17 Debug: [zone Pi] _Advance
04/04 15:00:17 Trace: [Pi] [Lossless, 16/44 TIDAL FLAC => 16/44] [1% buf] [STOPPED @ 0:00] 
04/04 15:00:17 Trace: [roonapi] [apiclient 192.168.1.53:39534] CONTINUE Changed {"zones_changed":[{"zone_id":"16011c46b181259d2cf5a5b5cbb212f4e5dd","display_name":"Pi","outputs":[{"output_id":"17011c46b181259d2cf5a5b5cbb212f4e5dd","zone_id":"16011c46b181259d2cf5a5b5cbb212f4e5dd","can_group_with_output_ids":["17011c46b181259d2cf5a5b5cbb212f4e5dd"],"display_name":"Pi","source_controls":[{"control_key":"1","display_name":"snd_rpi_rpi_dac","supports_standby":false,"status":"indeterminate"}]}],"state":"stopped","is_next_allowed":false,"is_previous_allowed":true,"is_pause_allowed":false,"is_play_allowed":false,"is_seek_allowed":false,"queue_items_remaining":0,"queue_time_remaining":0,"settings":{"loop":"disabled","shuffle":false,"auto_radio":false}}],"zones_seek_changed":[{"zone_id":"16011c46b181259d2cf5a5b5cbb212f4e5dd","queue_time_remaining":0}]}
04/04 15:00:17 Debug: GMS: saving nav stack
04/04 15:00:17 Debug: GMS: done saving nav stack
04/04 15:00:19 Trace: [zone Pi] Playing 1 Items
04/04 15:00:19 Trace: [zone Pi] Selecting Source state=Stopped
04/04 15:00:19 Info: [zone Pi] OnPlayFeedback Stopped
04/04 15:00:19 Trace: [zone Pi] Playing TransportItem
04/04 15:00:19 Trace: [zone Pi] Selecting Source state=Stopped
04/04 15:00:19 Trace: [zone Pi] queue got oversized. trimming 1 items from start
04/04 15:00:19 Debug: [zone Pi] Remove(1 items, for_replace=False)
04/04 15:00:19 Info: after removeall ordered count 5000 shuffle count 5000
04/04 15:00:19 Trace: [Pi] [Lossless, 16/44 TIDAL FLAC => 16/44] [1% buf] [LOADING @ 0:00] W.O.L.D. - Harry Chapin
04/04 15:00:19 Trace: [musicpowerstate] music is playing, preventing idle sleep
04/04 15:00:19 Trace: [roonapi] [apiclient 192.168.1.53:39534] CONTINUE Changed {"zones_changed":[{"zone_id":"16011c46b181259d2cf5a5b5cbb212f4e5dd","display_name":"Pi","outputs":[{"output_id":"17011c46b181259d2cf5a5b5cbb212f4e5dd","zone_id":"16011c46b181259d2cf5a5b5cbb212f4e5dd","can_group_with_output_ids":["17011c46b181259d2cf5a5b5cbb212f4e5dd"],"display_name":"Pi","source_controls":[{"control_key":"1","display_name":"snd_rpi_rpi_dac","supports_standby":false,"status":"indeterminate"}]}],"state":"loading","is_next_allowed":false,"is_previous_allowed":true,"is_pause_allowed":true,"is_play_allowed":false,"is_seek_allowed":false,"queue_items_remaining":1,"queue_time_remaining":312,"settings":{"loop":"disabled","shuffle":false,"auto_radio":false},"now_playing":{"seek_position":null,"length":312,"one_line":{"line1":"W.O.L.D. - Harry Chapin"},"two_line":{"line1":"W.O.L.D.","line2":"Harry Chapin"},"three_line":{"line1":"W.O.L.D.","line2":"Harry Chapin","line3":"Some More Stories"},"image_key":"4e58d73e0e90052294a1425dbcbc939078ed042d692b685c5497ac5628be8b4728dce89c57a67c6fd1c4aed54461b3855a6b4b4f0c2e9a866c32cfb176ce6517f2667968ab3c51e8e2889b620e16da17a1a4328ff8ed79457884317a1512612f7b482775f251c3dce26db36a17ff23a1","artist_image_keys":["4e58d73e0e90052294a1425dbcbc939078ed042d692b685c5497ac5628be8b4794fab8f5b705d380d5942fd6b87d02d19623299361ca3e2313368d44331d36fbfd70a099ed0d62e9ba9bd22eeea558fd53384f00f57641de27978be7c1d7f64ed34718c0e760f939d06cec15f8bac48d"]}}],"zones_seek_changed":[{"zone_id":"16011c46b181259d2cf5a5b5cbb212f4e5dd","queue_time_remaining":312,"seek_position":null}]}
04/04 15:00:19 Warn: [easyhttp] [555] web exception without response: Error: SecureChannelFailure (Unable to write data to the transport connection: The socket is not connected.)
04/04 15:00:19 Warn: [easyhttp] [556] web exception without response: Error: SecureChannelFailure (Unable to write data to the transport connection: The socket is not connected.)
04/04 15:00:19 Warn: [easyhttp] [559] web exception without response: Error: SecureChannelFailure (Unable to write data to the transport connection: The socket is not connected.)
04/04 15:00:19 Warn: [easyhttp] [560] web exception without response: Error: SecureChannelFailure (Unable to write data to the transport connection: The socket is not connected.)
04/04 15:00:19 Trace: [tidal/http] GET https://api.tidal.com/v1/tracks/130325542/playbackinfopostpaywall?countryCode=US&audioquality=HI_RES&assetpresentation=FULL&playbackmode=STREAM => Success
04/04 15:00:19 Debug: GMS: saving nav stack
04/04 15:00:19 Debug: GMS: trying to save nav stack, but nav stack stuff was in progress
04/04 15:00:19 Debug: GMS: done saving nav stack
04/04 15:00:19 Trace: [tidal/http] GET https://api.tidal.com/v1/tracks/130325542?countryCode=US => Success
04/04 15:00:19 Info: [Pi] [zoneplayer] Playing: http://sp-pr-cf.audio.tidal.com/mediatracks/CAEaKRInMmE5NzYyYTA1ZTIxZTZlYmRhYTE0ZTkyYzZmNjJlMDJfNjEubXA0/0.flac
04/04 15:00:19 Debug: [smc] [zoneplayer:3] Created domain
04/04 15:00:19 Debug: [smc] [zoneplayer:3] Adding ordinal 126
04/04 15:00:19 Debug: [easyhttp] [554] GET to https://metadata.roonlabs.net/1/tracks/168:0:130325542/lyrics returned after 138 ms, status code: 404
04/04 15:00:19 Trace: [streamingmediafile] retrying request due to Error writing headers
04/04 15:00:19 Debug: [easyhttp] [558] GET to https://imagecache.roonlabs.net/im/1/albums/a600313330333235353430/cover/402.jpg returned after 436 ms, status code: 200
04/04 15:00:20 Trace: [streamingmediafile] retrying request due to Error writing headers
04/04 15:00:20 Debug: [easyhttp] [557] GET to https://imagecache.roonlabs.net/im/1/albums/a600313330333235353430/cover/402.jpg returned after 578 ms, status code: 200
04/04 15:00:20 Trace: [streamingmediafile] retrying request due to Error writing headers
04/04 15:00:21 Trace: [streamingmediafile] retrying request due to Error writing headers
04/04 15:00:21 Warn: [streamingmediafile] caching http://sp-pr-cf.audio.tidal.com/mediatracks/CAEaKRInMmE5NzYyYTA1ZTIxZTZlYmRhYTE0ZTkyYzZmNjJlMDJfNjEubXA0/0.flac failed: System.Net.WebException: Error writing headers ---> System.IO.IOException: Unable to write data to the transport connection: The socket is not connected. ---> System.Net.Sockets.SocketException: The socket is not connected
  at System.Net.Sockets.Socket.EndSend (System.IAsyncResult asyncResult) [0x00012] in <bc69ad8632744cfba18f9705e53c6302>:0 
  at System.Net.Sockets.NetworkStream.EndWrite (System.IAsyncResult asyncResult) [0x00057] in <bc69ad8632744cfba18f9705e53c6302>:0 
   --- End of inner exception stack trace ---
  at System.Net.Sockets.NetworkStream.EndWrite (System.IAsyncResult asyncResult) [0x0009b] in <bc69ad8632744cfba18f9705e53c6302>:0 
  at System.IO.Stream+<>c.<BeginEndWriteAsync>b__58_1 (System.IO.Stream stream, System.IAsyncResult asyncResult) [0x00000] in <ba70b91736bd40cb990a357097dba9c3>:0 
  at (wrapper delegate-invoke) System.Func`3[System.IO.Stream,System.IAsyncResult,System.Threading.Tasks.VoidTaskResult].invoke_TResult_T1_T2(System.IO.Stream,System.IAsyncResult)
  at System.Threading.Tasks.TaskFactory`1+FromAsyncTrimPromise`1[TResult,TInstance].Complete (TInstance thisRef, System.Func`3[T1,T2,TResult] endMethod, System.IAsyncResult asyncResult, System.Boolean requiresSynchronization) [0x00000] in <ba70b91736bd40cb990a357097dba9c3>:0 
--- End of stack trace from previous location where exception was thrown ---

  at System.Net.WebRequestStream.SetHeadersAsync (System.Boolean setInternalLength, System.Threading.CancellationToken cancellationToken) [0x001d4] in <bc69ad8632744cfba18f9705e53c6302>:0 
   --- End of inner exception stack trace ---
  at System.Net.WebRequestStream.SetHeadersAsync (System.Boolean setInternalLength, System.Threading.CancellationToken cancellationToken) [0x00221] in <bc69ad8632744cfba18f9705e53c6302>:0 
  at System.Net.WebRequestStream.Initialize (System.Threading.CancellationToken cancellationToken) [0x000d5] in <bc69ad8632744cfba18f9705e53c6302>:0 
  at System.Net.WebOperation.Run () [0x0012c] in <bc69ad8632744cfba18f9705e53c6302>:0 
  at System.Net.WebCompletionSource`1[T].WaitForCompletion () [0x00094] in <bc69ad8632744cfba18f9705e53c6302>:0 
  at System.Net.HttpWebRequest.RunWithTimeoutWorker[T] (System.Threading.Tasks.Task`1[TResult] workerTask, System.Int32 timeout, System.Action abort, System.Func`1[TResult] aborted, System.Threading.CancellationTokenSource cts) [0x000f8] in <bc69ad8632744cfba18f9705e53c6302>:0 
  at System.Net.HttpWebRequest.EndGetResponse (System.IAsyncResult asyncResult) [0x00020] in <bc69ad8632744cfba18f9705e53c6302>:0 
  at Sooloos.Media.StreamingMediaFileImpl+<>c__DisplayClass11_1.<_StartBuffering>b__1 (System.IAsyncResult resp_ar) [0x00002] in <8061a44bcbb94e199a23491d999d3f88>:0 
04/04 15:00:21 Error: [seekableurimediafile] while determining length: System.IO.IOException: streaming media failed due to network
  at Sooloos.Media.StreamingMediaFileImpl.get_Length () [0x00038] in <8061a44bcbb94e199a23491d999d3f88>:0 
  at Sooloos.Media.StreamingMediaFile.get_Length () [0x00000] in <8061a44bcbb94e199a23491d999d3f88>:0 
  at Sooloos.Media.CachingSeekableUriMediaFile.LengthCallback (System.IntPtr userdata, System.Int64& out_length) [0x00017] in <8061a44bcbb94e199a23491d999d3f88>:0 
04/04 15:00:21 Debug: [smc] [zoneplayer:3] Removing ordinal 126
04/04 15:00:21 Debug: [smc] [zoneplayer:3] Destroyed domain
04/04 15:00:21 Warn: [zoneplayer] Corrupt Media Detected
04/04 15:00:21 Info: [Pi] [zoneplayer]     Open Result (Playing):Result[Status=CorruptMedia]
04/04 15:00:21 Warn: [zoneplayer] couldn't play URL http://sp-pr-cf.audio.tidal.com/mediatracks/CAEaKRInMmE5NzYyYTA1ZTIxZTZlYmRhYTE0ZTkyYzZmNjJlMDJfNjEubXA0/0.flac?Expires=1586030419&Signature=baR9zTJNkCbV6CViPYfjPMtNYMF88cyYUoSKi-q0tNLojOVhLPpWJSgh-24qFWmH~WhRqq5agBpyZ0-mHshdhZlUJe1VtkOK8L-A4qxlAQzvs31PfUzOkdiUVm~zGUpJvkoqf2-LN4FFFNuIAb9DUoSVoNZ~ntncnNJL2SbRL2p0KwtZmtW21EJnPNb7F5WV7aj1uaL7SYUSTcMVLBAkARDd2tavkZKHRNqbLWw6uUE6OUpqdq6N3F2ebahJW0aKAksgojCHZ3Qebxujv9YfLzwX95u72D~U1i1aSbkHDrvJv0W9ZJp9AVzCj-zbKOZ9wq~HqZTsVb1FO1ydm4unoA__&Key-Pair-Id=APKAIZ3WPBE4R6SP555A: corrupt media
04/04 15:00:21 Warn: Track Stopped Due to Bad Media
04/04 15:00:21 Info: [zone Pi] OnPlayFeedback StoppedEndOfMediaUnnatural
04/04 15:00:21 Debug: [zone Pi] _Advance
04/04 15:00:21 Trace: [Pi] [Lossless, 16/44 TIDAL FLAC => 16/44] [1% buf] [STOPPED @ 0:00] 
04/04 15:00:21 Trace: [roonapi] [apiclient 192.168.1.53:39534] CONTINUE Changed {"zones_changed":[{"zone_id":"16011c46b181259d2cf5a5b5cbb212f4e5dd","display_name":"Pi","outputs":[{"output_id":"17011c46b181259d2cf5a5b5cbb212f4e5dd","zone_id":"16011c46b181259d2cf5a5b5cbb212f4e5dd","can_group_with_output_ids":["17011c46b181259d2cf5a5b5cbb212f4e5dd"],"display_name":"Pi","source_controls":[{"control_key":"1","display_name":"snd_rpi_rpi_dac","supports_standby":false,"status":"indeterminate"}]}],"state":"stopped","is_next_allowed":false,"is_previous_allowed":true,"is_pause_allowed":false,"is_play_allowed":false,"is_seek_allowed":false,"queue_items_remaining":0,"queue_time_remaining":0,"settings":{"loop":"disabled","shuffle":false,"auto_radio":false}}],"zones_seek_changed":[{"zone_id":"16011c46b181259d2cf5a5b5cbb212f4e5dd","queue_time_remaining":0}]}
04/04 15:00:21 Debug: GMS: saving nav stack
04/04 15:00:21 Debug: GMS: done saving nav stack
04/04 15:00:23 Debug: UI-FORCE-LAZY: mode: viewall
04/04 15:00:23 Debug: UI-FORCE-LAZY: mode: albumdetails
04/04 15:00:23 Debug: UI-FWD: mode: albumdetails
04/04 15:00:23 Debug: GMS: saving nav stack
04/04 15:00:23 Debug: UI-NAV: album details / album: [object Sooloos.Broker.Metadata.MetadataAlbumLite] / bookmarkdata: 
04/04 15:00:23 Warn: [easyhttp] [561] web exception without response: Error: SecureChannelFailure (Unable to write data to the transport connection: The socket is not connected.)
04/04 15:00:23 Warn: [easyhttp] [562] web exception without response: Error: SecureChannelFailure (Unable to write data to the transport connection: The socket is not connected.)
04/04 15:00:23 Warn: [easyhttp] [563] web exception without response: Error: SecureChannelFailure (Unable to write data to the transport connection: The socket is not connected.)
04/04 15:00:23 Warn: [easyhttp] [564] web exception without response: Error: SecureChannelFailure (Unable to write data to the transport connection: The socket is not connected.)
04/04 15:00:23 Debug: GMS: done saving nav stack
04/04 15:00:25 Info: [stats] 18027mb Virtual, 5120mb Physical, 3035mb Managed, 105 Threads,  FDs 
04/04 15:00:26 Trace: [zone] no playback for 5s, suspending to release audio device
04/04 15:00:26 Trace: [zone Pi] Suspend
04/04 15:00:26 Trace: [zone Pi] Stop
04/04 15:00:26 Info: [zone Pi] OnPlayFeedback Stopped
04/04 15:00:37 Trace: [library] endmutation in 31ms
04/04 15:00:40 Info: [stats] 18014mb Virtual, 5129mb Physical, 3050mb Managed, 98 Threads,  FDs 
04/04 15:00:47 Trace: [roonapi] [apiclient 192.168.1.53:39534] CONTINUE Changed {"message":"Running (17)","is_error":false}
04/04 15:00:56 Info: [stats] 18004mb Virtual, 5130mb Physical, 3052mb Managed, 93 Threads,  FDs 
04/04 15:01:11 Info: [stats] 18008mb Virtual, 5137mb Physical, 3064mb Managed, 95 Threads,  FDs 
04/04 15:01:22 Debug: UI-BACK: mode: unifiedsearch
04/04 15:01:22 Debug: GMS: saving nav stack
04/04 15:01:23 Debug: GMS: done saving nav stack
04/04 15:01:23 Trace:  [broker/accounts]   doing auth refresh in EnsureAuthReady, next=4/4/2020 8:01:23 PM
04/04 15:01:23 Trace: [broker/accounts] refreshing account info for email='pbgalvin@gmail.com' userid=6fbfe46f-171c-4fb5-9a49-74c86cf998fd
04/04 15:01:23 Trace: [fiveaccountserver] POST https://accounts5.roonlabs.com/accounts/3/login
04/04 15:01:23 Trace: [fiveaccountserver] BODY token=ee8e1139-aecd-4de8-bf08-ac56b6bf19c0
04/04 15:01:23 Trace: Successful POST response from https://accounts5.roonlabs.com/accounts/3/login
04/04 15:01:23 Trace: [fiveaccountserver] GOT {"status":"Success","userid":"6fbfe46f-171c-4fb5-9a49-74c86cf998fd","token":"ee8e1139-aecd-4de8-bf08-ac56b6bf19c0","expiration":30,"email":"pbgalvin@gmail.com","groups":[]}
04/04 15:01:23 Warn: [broker/accounts] failed to auth: Result[Status=NetworkError]
04/04 15:01:26 Info: [stats] 18006mb Virtual, 5141mb Physical, 3071mb Managed, 94 Threads,  FDs 
04/04 15:01:28 Trace: [broker/accounts] refreshing account info for email='pbgalvin@gmail.com' userid=6fbfe46f-171c-4fb5-9a49-74c86cf998fd
04/04 15:01:28 Trace: [fiveaccountserver] POST https://accounts5.roonlabs.com/accounts/3/login
04/04 15:01:28 Trace: [fiveaccountserver] BODY token=ee8e1139-aecd-4de8-bf08-ac56b6bf19c0
04/04 15:01:28 Trace: Successful POST response from https://accounts5.roonlabs.com/accounts/3/login
04/04 15:01:28 Trace: [fiveaccountserver] GOT {"status":"Success","userid":"6fbfe46f-171c-4fb5-9a49-74c86cf998fd","token":"ee8e1139-aecd-4de8-bf08-ac56b6bf19c0","expiration":30,"email":"pbgalvin@gmail.com","groups":[]}
04/04 15:01:29 Trace: [fiveaccountserver] GET https://accounts5.roonlabs.com/accounts/3/profileslist?token=ee8e1139-aecd-4de8-bf08-ac56b6bf19c0
04/04 15:01:29 Trace: [fiveaccountserver] GET https://accounts5.roonlabs.com/accounts/3/userinfo?token=ee8e1139-aecd-4de8-bf08-ac56b6bf19c0
04/04 15:01:29 Trace: [broker/accounts] updated token. New expiration is 5/4/2020 3:01:29 PM
04/04 15:01:29 Trace: [push] restarting connection (Unable to read data from the transport connection: interrupted.)
04/04 15:01:29 Trace: [push] retrying connection in 62961ms
04/04 15:01:29 Trace: [broker/accounts] Data updated. AccountStatus=LoggedIn MachineStatus=Licensed UserId=6fbfe46f-171c-4fb5-9a49-74c86cf998fd
04/04 15:01:29 Debug: [easyhttp] [567] POST to https://bits.roonlabs.net/1/q/roon.childprocess.,roon.debug.,roon.broker.,roon.dsp.,roon.client.,roon.sood.?roon_auth_token=ee8e1139-aecd-4de8-bf08-ac56b6bf19c0
04/04 15:01:29 Trace: [fiveaccountserver] GOT {"status":"Success","profiles":[{"id":"52d3a902-e9ad-497e-b360-6cb19625acf9","name":"Peter","photo":"https://sooloos-profileimages.s3.amazonaws.com/five-6fbfe46f-171c-4fb5-9a49-74c86cf998fd--52d3a902-e9ad-497e-b360-6cb19625acf9.jpg","birthdate":"19620000","facebook_auth":"{ \"accesstoken\": \"EAADeu8DcOV8BAANjhs46yaYXE6Xc9rmLoGYNHZCRWgq3EefC6P3bk4xnYO05sFkEuJ4ZCeHNuIpyqDsvDDKZC5YlupuZC88XlWTmZC2ZB2JhRYobQtIE5lLMXh37JzTpzUdiVwk1Rg0AWTeG25aAIrTAYfyDaTpdpTkO1Rp64QIQZDZD\" }","twitter_auth":"{ \"oauth_token\": \"12846222-yTFUmYszuH7H2aUt7VTCHQGBWozpJ6AoWgWy8vVdM\", \"oauth_token_secret\": \"NCUpiAaNztNqli22cB8ELnXkeuJ1XTGMntTplxjw9uAYx\" }"}]}
04/04 15:01:29 Trace: [broker/accounts] Data updated. AccountStatus=LoggedIn MachineStatus=Licensed UserId=6fbfe46f-171c-4fb5-9a49-74c86cf998fd

noris · April 10, 2020, 8:37pm

Hi @Peter_Galvin1,

Thanks for sending the log over. I have been discussing it with QA and it looks like you might be trying look up an album which does not exist on Roon yet. It is possible that this album was added to the TIDAL native app, but not to Roon’s metadata services yet. I have a few questions to help clarify:

Does this behavior occur for multiple albums or just one in particular?
When this issue occurs, are you able to still load other TIDAL content properly? To clarify, if you click on the Roon Menu -> TIDAL in the side bar, does that work as expected?
Can you provide more exact reproduction steps or a short video of how you get into this state in Roon? Where are you navigating to the album from? A playlist on TIDAL?

Peter_Galvin1 · April 10, 2020, 8:57pm

Not sure what you mean about adding an album to the tidal native app. I just use Tidal to stream albums Tidal has. (I don’t add anything to Tidal.). I imagine Roon doesn’t add every album Tidal has its service to the Roon DB. Rather I search in Roon to find something I don’t have -> it finds it in Tidal, and it plays it. But frequently on my system it doesn’t play it. Instead I get errors like that.
Meanwhile running the tidal app itself on the same computer the album plays fine.
Seems like a network problem with Roon talking to Tidal…

noris · April 17, 2020, 2:42am

Hi @Peter_Galvin1,

Let me clarify my previous message. The way that the TIDAL sync works is that first tracks are added directly to the TIDAL native app and then after couple of days, Roon’s Metadata servers are updated with the new tracks that were just released.

When I discussed this issue with QA, they mentioned that the log trace looks like you’re trying to look up an album which was just released (and not added to Roon’s metadata services yet).

Could you please let me know the above information I requested so that we can look into this further? Thanks!

Peter_Galvin1 · April 18, 2020, 7:12pm

Ah. It happens very frequently, for new and old album tracks.
Just happened today at 3:09 pm.
I searched Roon for “satchmo plays king oliver”
It shows the album but no art etc. I click on the album and get a network error. I go to tidal and it finds it and plays it fine on the same system.

noris · April 21, 2020, 7:39pm

Hi @Peter_Galvin1,

I’ve enabled diagnostics mode for this search attempt and what this action does is automatically upload a log set to our servers for analysis. I am looking over the log and this is what I see at this timestamp:

04/18 15:10:24 Debug: [easyhttp] [426] GET to https://search.roonlabs.net/1/search?q=satchmo plays king oliver&count=50&c=tidal-us returned after 354 ms, status code: 200
04/18 15:10:24 Warn: [easyhttp] [427] web exception without response: Error: SecureChannelFailure (Unable to write data to the transport connection: The socket is not connected.)
04/18 15:10:24 Debug: GMS: done saving nav stack
04/18 15:10:24 Trace: [music/search] computing search results
04/18 15:10:24 Trace: [music/search] [performance] ComputeTopResult took 25ms
04/18 15:10:24 Trace: [music/search] [performance] end-to-end search took 488ms
04/18 15:10:24 Error: Error loading image (immediate): Error: SecureChannelFailure (Unable to write data to the transport connection: The socket is not connected.) (https://imagecache.roonlabs.net/im/1/albums/a600313331363337313533/cover/256sq.jpg)
04/18 15:10:24 Error: Error loading image (immediate): Error: SecureChannelFailure (Unable to write data to the transport connection: The socket is not connected.) (https://imagecache.roonlabs.net/im/1/albums/a600313135303535363539/cover/256sq.jpg)
04/18 15:10:24 Error: Error loading image (immediate): Error: SecureChannelFailure (Unable to write data to the transport connection: The socket is not connected.) (https://imagecache.roonlabs.net/im/1/albums/a6003830383339313934/cover/256sq.jpg)
04/18 15:10:24 Error: Error loading image (immediate): Error: SecureChannelFailure (Unable to write data to the transport connection: The socket is not connected.) (https://imagecache.roonlabs.net/im/1/albums/a600313130353132383739/cover/256sq.jpg)
04/18 15:10:24 Error: Error loading image (immediate): Error: SecureChannelFailure (Unable to write data to the transport connection: The socket is not connected.) (https://imagecache.roonlabs.net/im/1/albums/a60031393937343634/cover/256sq.jpg)

The above trace suggests networking issues and that Roon cannot properly communicate with even our image cache servers, so I still suspect that this issue is networking related.

Are you by any chance running a VPN at the same time as Roon on this machine? Do you have multiple network interfaces that are active at the same time on this machine?

What is the model/manufacturer of your networking gear, is the Core connected directly to the router? If you’re going through a switch, could you try connecting directly to the router via Ethernet instead?