Roon stops responding for multiple minutes between tracks

lyroon · July 8, 2020, 9:28pm

Hi @support - I’m having whole system freezes a few times an hour: can you please advise? (Apologies for formatting of log snippets - I can’t seem to fix it).

Core Machine (Operating system/System info/Roon build number)

Rock Version 1.7 (build 571) stable on NUC

Network Details (Including networking gear model/manufacturer and if on WiFi/Ethernet)

Core connected by ethernet to Synology NAS.
Router: “Freebox Delta”

Audio Devices (Specify what device you’re using and its connection type - USB/HDMI/etc.)

A few Sonos and Devialet devices over wifi or powerline adaptor

Description Of Issue

Not very reproducible, but very common. If playing one local album, things are ok. But if at the end of the album it goes to Roon radio (local + Tidal), it will very frequently stop playing between songs. But also be unresponsive if I try to cue up a new song. I’ll attach a log snippet below: I hit play on an album and it started playing audibly maybe 5 minutes later.

**log example**:
    07/08 20:22:50 Critical: [easyhttp] Post https://metadata.roonlabs.net/1/works/translate?c=tidal-fr exception: : System.ObjectDisposedException: Cannot access a disposed object.
Object name: 'System.Net.Sockets.NetworkStream'.
  at System.Net.WebConnection.BeginWrite (System.Net.HttpWebRequest request, System.Byte[] buffer, System.Int32 offset, System.Int32 size, System.AsyncCallback cb, System.Object state) [0x0002b] in <69f8661c94644655a06862d3e6b439f6>:0 
  at System.Net.WebConnectionStream.BeginWrite (System.Byte[] buffer, System.Int32 offset, System.Int32 size, System.AsyncCallback cb, System.Object state) [0x00270] in <69f8661c94644655a06862d3e6b439f6>:0 
  at System.IO.Stream+<>c.<BeginEndWriteAsync>b__53_0 (System.IO.Stream stream, System.IO.Stream+ReadWriteParameters args, System.AsyncCallback callback, System.Object state) [0x00000] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Threading.Tasks.TaskFactory`1[TResult].FromAsyncTrim[TInstance,TArgs] (TInstance thisRef, TArgs args, System.Func`5[T1,T2,T3,T4,TResult] beginMethod, System.Func`3[T1,T2,TResult] endMethod) [0x00008] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.IO.Stream.BeginEndWriteAsync (System.Byte[] buffer, System.Int32 offset, System.Int32 count) [0x00000] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.IO.Stream.WriteAsync (System.Byte[] buffer, System.Int32 offset, System.Int32 count, System.Threading.CancellationToken cancellationToken) [0x00009] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.IO.Stream.WriteAsync (System.Byte[] buffer, System.Int32 offset, System.Int32 count) [0x00009] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at (wrapper remoting-invoke-with-check) System.IO.Stream.WriteAsync(byte[],int,int)
  at Sooloos.EasyHttp+BytesContent+<CopyToStreamAsync>d__5.MoveNext () [0x00011] in <bfa2ce817f344d24a09cb6ca0aa79686>:0 
--- End of stack trace from previous location where exception was thrown ---
  at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw () [0x0000c] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Threading.Tasks.Task task) [0x0003e] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Threading.Tasks.Task task) [0x00028] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Runtime.CompilerServices.TaskAwaiter.ValidateEnd (System.Threading.Tasks.Task task) [0x00008] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Runtime.CompilerServices.TaskAwaiter.GetResult () [0x00000] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at Sooloos.EasyHttp+<QueryAsync>d__2.MoveNext () [0x0066b] in <bfa2ce817f344d24a09cb6ca0aa79686>:0 
07/08 20:22:50

**log example 2** (there is a whole 8.5 mb log file of this):
    07/08 20:40:28 Warn: [airplay/client] packet with seq 64410 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64411 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64412 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64413 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64414 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64415 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64416 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64417 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64418 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64419 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64420 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64421 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64422 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64423 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64424 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64425 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64426 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64427 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64428 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64429 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64430 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64431 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64432 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64433 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64434 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64435 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64436 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64437 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64438 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64439 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64440 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64441 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64442 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64443 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64444 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64445 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64446 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64447 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64448 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64449 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64450 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64451 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64452 not found for retransmit
07/08 20:40:28 Warn: [airplay/client] packet with seq 64453 not found for retransmit

**log example 3**: (hit play and nothing happens for 60 seconds)
    07/08 21:19:25 Trace: [Front Room freebox] [HighQuality, 16/44 FLAC => 16/44] [4% buf] [LOADING @ 0:00] You Always Hang Around - The Breeders
07/08 21:19:25 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5001 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
07/08 21:19:25 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5001 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
07/08 21:19:25 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5001 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
07/08 21:19:25 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5001 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
07/08 21:19:26 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5000 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
07/08 21:19:26 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5000 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
07/08 21:19:26 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5000 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
07/08 21:19:26 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5000 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
07/08 21:19:28 Trace: [radio] [24] done in 3176ms
07/08 21:19:28 Trace: [radio] [24] get next items nitems=1 flushed_trackids=
07/08 21:19:28 Trace: [radio] [24]     Track MC Solaar - Temps Mort
07/08 21:19:28 Trace: [radio] [24] done in 3176ms
07/08 21:19:28 Info: ComputeSwimType(LimitToSeed=True, PerformerIds.Count=0, ComposerIds.Count=0)
07/08 21:19:28 Trace: [radio] [24] notify picked 56180530 tracks
07/08 21:19:28 Trace: [radio] [24]     Various Artists - Cherry Pie
07/08 21:19:28 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5001 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
07/08 21:19:28 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5001 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
07/08 21:19:28 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5001 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
07/08 21:19:28 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5001 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
07/08 21:19:29 Debug: [ByteBuffer] large alloc of 16384k
07/08 21:19:29 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5000 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
07/08 21:19:29 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5000 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
07/08 21:19:29 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5000 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
07/08 21:19:29 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5000 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
07/08 21:19:31 Trace: [Front Room freebox] [HighQuality, 16/44 FLAC => 16/44] [4% buf] [LOADING @ 0:00] You Always Hang Around - The Breeders
07/08 21:19:31 Trace: [radio] [24] done in 3585ms
07/08 21:19:31 Trace: [radio] [24] get next items nitems=1 flushed_trackids=
07/08 21:19:31 Trace: [radio] [24]     Track Liz Phair - Strange Loop
07/08 21:19:31 Trace: [radio] [24] done in 3585ms
07/08 21:19:31 Info: ComputeSwimType(LimitToSeed=True, PerformerIds.Count=0, ComposerIds.Count=0)
07/08 21:19:31 Debug: [easyhttp] [4851] POST to https://metadata.roonlabs.net/1/albums/translate?c=tidal-fr timed out after 77920 ms
07/08 21:19:31 Trace: [metadatasvc] REQ [6053] https://metadataserver.roonlabs.net/md/4/updatemetadata?uid=8514a146-b150-462b-ba13-1c7fb19d07a2&lid=&token=f878f4d6-c26c-46ef-8ff2-bb4c3192d557&metadataid[]=6100363430323338323339&metadataid[]=6100363430323338323435&metadataid[]=6100313831303636333231313239343639&metadataid[]=6100313831303636333231313239343633&metadataid[]=6100313831303636333231313239343634&metadataid[]=6100313831303636333231313239343636&metadataid[]=6100313831303636333231313239343637&metadataid[]=6100313831303636333231313239343638&metadataid[]=6100313831303636333231313239343730&metadataid[]=6100313831303636333231313239343731&metadataid[]=6100313831303636333231313239343733&metadataid[]=6100353433323339313932383034&metadataid[]=6100353433323339313932373932&metadataid[]=6100353433323339313932373934&metadataid[]=6100353433323339313932383030&metadataid[]=6100353433323339313932383031&metadataid[]=6100353433323339313932383032&metadataid[]=6100353433323339313932383035&metadataid[]=6100353433323339313932383036&metadataid[]=7b004d5430303037323135353538&metadataid[]=7b004d5430303037323432363139&metadataid[]=7b004d5430303036393230313832&metadataid[]=7b004d5430303037303534363839&metadataid[]=7b004d5430303036383933393435&metadataid[]=7b004d5430303036393234353230&metadataid[]=7b004d5430303037323338353434&metadataid[]=7b004d5430303036393138333737&metadataid[]=7b004d5430303037323435313932&metadataid[]=7b004d5430303036383839373935&metadataid[]=610035363930373335343031353239&metadataid[]=610035363930373335343031353236&metadataid[]=610035363930373335343031353237&metadataid[]=610035363930373335343031353238&metadataid[]=610032383136363833393434373235&metadataid[]=610032383136363833393434373233&metadataid[]=610032383136363833393434373234&metadataid[]=610032383136363833393434373236&metadataid[]=610032383136363833393434373237&metadataid[]=610032383136363833393434373238&metadataid[]=610032383136363833393434373239&metadataid[]=610032383136363833393434373330&metadataid[]=610032383136363833393434373331&metadataid[]=610032383136363833393434373332&metadataid[]=610032383136363833393434373333&metadataid[]=610032383136363833393434373334&metadataid[]=610032383136363833393434373335&metadataid[]=610032383136363833393434373336&metadataid[]=610032383136363833393434373337&metadataid[]=610032383136363833393434373338&metadataid[]=610032383136363833393434373339&metadataid[]=79004d5730303030313734343837&metadataid[]=79004d5730303032393435333736&metadataid[]=79004d5730303030313839313438&metadataid[]=79004d5730303030303933303538&metadataid[]=79004d5730303031313836343037&metadataid[]=3e01affa8a36e1937c409db7e71bc0bd85de
07/08 21:19:31 Debug: [identification] <2204719> status: CouldNotIdentify
07/08 21:19:31 Trace: [identification] <5742639> Identifying album [Orla Wren with Jessica Constable, Various Artists - Explorer's Club: 11. Montreal - Nuuk] with 3 tracks
07/08 21:19:31 Debug: [metadata http post req]: https://identifier.roonlabs.net/identifier/2/album?uid=8514a146-b150-462b-ba13-1c7fb19d07a2&lid=&token=f878f4d6-c26c-46ef-8ff2-bb4c3192d557
07/08 21:19:31 Debug: [identification] <5742639> identifier request id: 78421081
07/08 21:19:31 Trace: [library] finished with 2 dirty tracks 1 dirty albums 2 dirty performers 1 dirty works 1 dirty performances 0 clumping tracks, 0 clumping auxfiles 0 compute tracks, 0 deleted tracks, 2 tracks to (re)load, 0 tracks to retain, 0 auxfiles to (re)load, 0 auxfiles to retain, and 7 changed objects
07/08 21:19:31 Trace: updated recents in 1ms
07/08 21:19:31 Trace: updated recents in 260ms
07/08 21:19:31 Trace: updated recents in 1ms
07/08 21:19:31 Trace: updated recents in 0ms
07/08 21:19:31 Trace: updated recents in 0ms
07/08 21:19:31 Trace: updated recents in 0ms
07/08 21:19:31 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5001 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
07/08 21:19:31 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5001 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
07/08 21:19:31 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5001 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
07/08 21:19:31 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5001 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
07/08 21:19:33 Trace: [dbperf] flush 10647 bytes, 6 ops in 1 ms (cumulative 1620952105 bytes, 869075 ops in 361460 ms)
07/08 21:19:39 Info: [stats] 11205mb Virtual, 6908mb Physical, 3989mb Managed, 0 Handles, 102 Threads
07/08 21:19:46 Trace: [Front Room freebox] [HighQuality, 16/44 FLAC => 16/44] [4% buf] [LOADING @ 0:00] You Always Hang Around - The Breeders
07/08 21:19:48 Trace: [library] endmutation in 17066ms
07/08 21:19:48 Debug: [identification] <5612079> status: CouldNotIdentify
07/08 21:19:48 Trace: [identification] <5816879> Identifying album [Various Artists - Odd Nosdam's Music to Psychic Drive by] with 4 tracks
07/08 21:19:48 Debug: [metadata http post req]: https://identifier.roonlabs.net/identifier/2/album?uid=8514a146-b150-462b-ba13-1c7fb19d07a2&lid=&token=f878f4d6-c26c-46ef-8ff2-bb4c3192d557
07/08 21:19:48 Debug: [identification] <5816879> identifier request id: 919154f8
07/08 21:19:48 Trace: [library] finished with 55 dirty tracks 1 dirty albums 1 dirty performers 0 clumping tracks, 0 clumping auxfiles 0 compute tracks, 0 deleted tracks, 55 tracks to (re)load, 0 tracks to retain, 0 auxfiles to (re)load, 0 auxfiles to retain, and 57 changed objects
07/08 21:19:49 Trace: updated recents in 5ms
07/08 21:19:49 Trace: updated recents in 0ms
07/08 21:19:49 Trace: updated recents in 1ms
07/08 21:19:49 Trace: updated recents in 0ms
07/08 21:19:49 Trace: updated recents in 0ms
07/08 21:19:49 Trace: updated recents in 0ms
07/08 21:19:52 Trace: [dbperf] flush 288835 bytes, 112 ops in 15 ms (cumulative 1621240940 bytes, 869187 ops in 361475 ms)
07/08 21:19:54 Info: [stats] 11419mb Virtual, 7117mb Physical, 4212mb Managed, 0 Handles, 100 Threads
07/08 21:20:00 Trace: [Front Room freebox] [HighQuality, 16/44 FLAC => 16/44] [4% buf] [LOADING @ 0:00] You Always Hang Around - The Breeders
07/08 21:20:06 Trace: [Front Room freebox] [HighQuality, 16/44 FLAC => 16/44] [4% buf] [LOADING @ 0:00] You Always Hang Around - The Breeders
07/08 21:20:09 Trace: [library] endmutation in 20697ms
07/08 21:20:09 Trace: [dbperf] flush 0 bytes, 0 ops in 1 ms (cumulative 1621240940 bytes, 869187 ops in 361476 ms)
07/08 21:20:09 Info: [Front Room freebox] [zoneplayer] Playing: /roon/sys/storage/smbmounts/RoonStorage_14fdf0691aee07be6e51cdb4b5d8022e4850bdc4/Audio/Music/Untagged/Breeders/EPs/The Breeders - (rare Pod demo) You Always Hang Around.mp3
07/08 21:20:09 Info: [Front Room freebox] [zoneplayer] Queueing: /roon/sys/storage/smbmounts/RoonStorage_14fdf0691aee07be6e51cdb4b5d8022e4850bdc4/Audio/Music/Untagged/Essential Electro - The Business (1984) V0/LP 8/O4 - Forevereaction - U People.mp3
07/08 21:20:09 Debug: [easyhttp] [4853] POST to https://swim.roonlabs.net/1/session/ac7f7ddb72ea457782fd02364c500ae4/ping
07/08 21:20:09 Trace: [metadatasvc] GOT [6053] (38038ms) Sooloos.Msg.Metadata.UpdateMetadataResponse: 
07/08 21:20:09 Trace: [metadatasvc] REQ [6054] https://metadataserver.roonlabs.net/md/4/getmetadata?uid=8514a146-b150-462b-ba13-1c7fb19d07a2&lid=&token=f878f4d6-c26c-46ef-8ff2-bb4c3192d557&metadataid[]=6100363430323338323339&metadataid[]=7a004d4e30303030363130333436&metadataid[]=7a004d4e30303030343938393631&metadataid[]=7a004d4e30303033323232303938&metadataid[]=64016b15a070bd74a679b7bf94524b218e9e&metadataid[]=a3003030322d323635393436&metadataid[]=3e01330a68793c310443a9b57124ef4f4d9e&metadataid[]=7a004d4e30303030323537313630&metadataid[]=5e010678f2064a67f74da74ff146eda26aa1&metadataid[]=7a004d4e30303030383437303232&metadataid[]=7a004d4e30303030353533323038&metadataid[]=7a004d4e30303031323033323633&metadataid[]=7a004d4e30303030313131313531&metadataid[]=7a004d4e30303030333239343431&metadataid[]=7a004d4e30303030373732313931&metadataid[]=7a004d4e30303031343137303636&metadataid[]=5e0107e4f8339d996844a63fb487a98444bd&metadataid[]=5e0108fb8e012b224548931c3a0cdfac3bb2&metadataid[]=7a004d4e30303030343637333832&metadataid[]=5e01d5762af60f1a6e4f83469519fbdb0b9f&metadataid[]=5e01dd73ac53e2b1c749aead76b1702d2c92&metadataid[]=5e012b4d008fe3fa9f499d7bebc7218b032d&metadataid[]=7a004d4e30303030393533343330&metadataid[]=5e012fd41d088100464287e5df45acca0fae&metadataid[]=5e019331a632ba7274418949fa05a1a3d9db&metadataid[]=6100363430323338323435&metadataid[]=64010deebcb60c9c748aed14e536ee207102&metadataid[]=6100313831303636333231313239343639&metadataid[]=7a004d4e30303033303134323531&metadataid[]=5e01e04b65707854844896f1ef5869201ff5&metadataid[]=7a004d4e30303033323032383131&metadataid[]=7a004d4e30303033303134323532&metadataid[]=7a004d4e30303033323430333638&metadataid[]=6401fed604d6ee8258a63fb83e16c5157900&metadataid[]=3e01768103758883da4097f23c0873a38542&metadataid[]=5e01e090f11a3b8ab24da315f3ef2f4e6e02&metadataid[]=7a004d4e30303033353136393633&metadataid[]=7a004d4e30303033333036393435&metadataid[]=5e018b9b5e9dad6c9b4095823415e8c7d907&metadataid[]=7a004d4e30303033343835323532&metadataid[]=7a004d4e30303031373732343338&metadataid[]=7a004d4e30303033333135393039&metadataid[]=6100313831303636333231313239343633&metadataid[]=6401537b48b2b93c83a6833fefb86550429d&metadataid[]=6100313831303636333231313239343634&metadataid[]=6401ab81a07e71eb7f2ed79310621ddad327&metadataid[]=6100313831303636333231313239343636&metadataid[]=640191e4fa56ada116ffe5e7b4d904022434&metadataid[]=6100313831303636333231313239343637&metadataid[]=6601d6f26144c62330275c5f56839e34f49f&metadataid[]=6401be5aa0a6239f9e3d1b8144648d5cad67&metadataid[]=6100313831303636333231313239343638&metadataid[]=6401cdb9b05daecc9f7add8f22554b78a69d&metadataid[]=6100313831303636333231313239343730&metadataid[]=7a004d4e30303033333135383832&metadataid[]=64014bd875896ad96d6bb70ba0cd947049e6&metadataid[]=6100313831303636333231313239343731&metadataid[]=64016093fe4febc3b8be8071990d41728c8f&metadataid[]=6100313831303636333231313239343733&metadataid[]=7a004d4e30303033343830353633&metadataid[]=640144745390c0c8a374e13834ec2be2e872&metadataid[]=6100353433323339313932383034&metadataid[]=5e018514ba97ba3ea44aa7c3b6311043ed1e&metadataid[]=7a004d4e30303030363230313535&metadataid[]=7a004d4e30303030363234353034&metadataid[]=5e01b6014c8cca7ffe48adf06d2007023635&metadataid[]=660139149572c57d6608d759957d414c2598&metadataid[]=6401744220d4c811dd74edffd8f569c8a70d&metadataid[]=3e019fd482328635b733a2ae62d3452a13bb&metadataid[]=7a004d4e30303030353732393335&metadataid[]=7a004d4e30303030333537363030&metadataid[]=7a004d4e30303030323130323632&metadataid[]=7a004d4e30303030313035383435&metadataid[]=7a004d4e30303030383331393039&metadataid[]=6100353433323339313932373932&metadataid[]=6401d82fa3ce8a1cf9c0451aef4aef07d094&metadataid[]=6100353433323339313932373934&metadataid[]=7a004d4e30303030313732353432&metadataid[]=5e017a3aa59b83d34f40b72807a589e2e62b&metadataid[]=6601737bbae641858d31c572e79d32acd049&metadataid[]=64012ecfdbacd4b3e026bcdd898184e6bcbd&metadataid[]=7a004d4e30303031303931333438&metadataid[]=6100353433323339313932383030&metadataid[]=6401184a7756358fa8191952bc3dcca5ca2a&metadataid[]=6100353433323339313932383031&metadataid[]=6100353433323339313932383032&metadataid[]=64016d8e6044a621e33507d1bda40c6fe7b2&metadataid[]=6100353433323339313932383035&metadataid[]=660195b85c7199105dc618d8f8f740027a5f&metadataid[]=6401063296baeda4f57c9b74ec9e1fcd6e53&metadataid[]=6100353433323339313932383036&metadataid[]=640165caf300a9292119901e140333086292&metadataid[]=7b004d5430303037323135353538&metadataid[]=5e0134dfcce2e2f1764fb741cc0129824ce5&metadataid[]=6401cc05b2a065c1b94e6af8ced73f854bb8&metadataid[]=79004d5730303030303933303538&metadataid[]=5e01a083fb500ef1364683d9bed9188becc0&metadataid[]=7a004d4e30303032303434313633&metadataid[]=7b004d5430303037323432363139&metadataid[]=640126c53492f42d336a082e6f6646a81acd
07/08 21:20:09 Trace: [metadatasvc] REQ [6055] https://metadataserver.roonlabs.net/md/4/getmetadata?uid=8514a146-b150-462b-ba13-1c7fb19d07a2&lid=&token=f878f4d6-c26c-46ef-8ff2-bb4c3192d557&metadataid[]=7b004d5430303036393230313832&metadataid[]=64014da62a9172d665c49fcdb198440a196b&metadataid[]=7b004d5430303037303534363839&metadataid[]=640118956a0452ac068903f55a1977223e3e&metadataid[]=7b004d5430303036383933393435&metadataid[]=6401c5dc57e8708f8a02059ef192e918d1ea&metadataid[]=7b004d5430303036393234353230&metadataid[]=6401dca7aee26e506fd591768fb5d63932ab&metadataid[]=7b004d5430303037323338353434&metadataid[]=6401121be855a500a30986f987a317d99af0&metadataid[]=7b004d5430303036393138333737&metadataid[]=6401b2c1eef7efbf50504a2aa66270748f41&metadataid[]=7b004d5430303037323435313932&metadataid[]=64018395f1ff0a3ac4657221ff6b01302f1c&metadataid[]=7b004d5430303036383839373935&metadataid[]=640161ce25a6e94dc5e9381bc8eca1dae768&metadataid[]=610035363930373335343031353239&metadataid[]=640105b47dbafa0b521e116df2bf129c287d&metadataid[]=3e0193772f61baa7263baf39c246689453ff&metadataid[]=610035363930373335343031353236&metadataid[]=6401c96d261ecdaf2ffd8aa7520cd03faa7a&metadataid[]=610035363930373335343031353237&metadataid[]=6401ee07a60112be2d4ad0965aac7589ad19&metadataid[]=610035363930373335343031353238&metadataid[]=64017d1305ca9ccd3775f904beccaf7cce81&metadataid[]=610032383136363833393434373235&metadataid[]=3e01affa8a36e1937c409db7e71bc0bd85de&metadataid[]=610032383136363833393434373233&metadataid[]=610032383136363833393434373234&metadataid[]=610032383136363833393434373236&metadataid[]=610032383136363833393434373237&metadataid[]=610032383136363833393434373238&metadataid[]=610032383136363833393434373239&metadataid[]=610032383136363833393434373330&metadataid[]=610032383136363833393434373331&metadataid[]=610032383136363833393434373332&metadataid[]=610032383136363833393434373333&metadataid[]=610032383136363833393434373334&metadataid[]=610032383136363833393434373335&metadataid[]=610032383136363833393434373336&metadataid[]=610032383136363833393434373337&metadataid[]=610032383136363833393434373338&metadataid[]=610032383136363833393434373339&metadataid[]=79004d5730303030313734343837&metadataid[]=79004d5730303032393435333736&metadataid[]=79004d5730303030313839313438&metadataid[]=79004d5730303031313836343037
07/08 21:20:09 Trace: [dbperf] flush 0 bytes, 0 ops in 19 ms (cumulative 1621240940 bytes, 869187 ops in 361495 ms)
07/08 21:20:09 Debug: [identification] <5742639> status: CouldNotIdentify
07/08 21:20:09 Trace: [identification] <5675567> Identifying album [Various Artists - 0-60 In Five Years: The Complete Shifty Disco Singles Club Collection (Volume 5)] with 12 tracks
07/08 21:20:09 Debug: [metadata http post req]: https://identifier.roonlabs.net/identifier/2/album?uid=8514a146-b150-462b-ba13-1c7fb19d07a2&lid=&token=f878f4d6-c26c-46ef-8ff2-bb4c3192d557
07/08 21:20:09 Debug: [identification] <5675567> identifier request id: 22ce5fc8
07/08 21:20:09 Info: [Front Room freebox] [zoneplayer]     Open Result (Playing):Result[Status=Success]
07/08 21:20:09 Trace: [zoneplayer/signal] resampling low-quality audio from 22050 to 44100
07/08 21:20:09 Info: [Front Room freebox] [zoneplayer] Starting playback
07/08 21:20:09 Trace: [airplay/client] Connecting to airplay server
07/08 21:20:09 Info: [Front Room freebox] [zoneplayer] Open result (Queueing): Result[Status=Success]
07/08 21:20:09 Info: [zone Front Room freebox] OnPlayFeedback Playing
07/08 21:20:09 Debug: Lastfm 'xvgQyyspgtgB8Rh4yAXSO7EoUPkriT7D' START: The Breeders - You Always Hang Around 
07/08 21:20:09 Trace: [Front Room freebox] [LowQuality, 16/22 MP3 => 16/44] [4% buf] [PLAYING @ 0:00] You Always Hang Around - The Breeders
07/08 21:20:09 Trace: [library] finished with 3 dirty tracks 1 dirty albums 2 dirty performers 0 clumping tracks, 0 clumping auxfiles 0 compute tracks, 0 deleted tracks, 3 tracks to (re)load, 0 tracks to retain, 0 auxfiles to (re)load, 0 auxfiles to retain, and 6 changed objects
07/08 21:20:09 Trace: [airplay/client] Requesting OPTIONS
07/08 21:20:09 Info: [airplay/client] REQUESTING OPTIONS *
07/08 21:20:09 Trace: [airplay/client] Got good OPTIONS: OPTIONS, ANNOUNCE, SETUP, RECORD, SET_PARAMETER, GET_PARAMETER, FLUSH, TEARDOWN, POST, GET
07/08 21:20:09 Info: [airplay] AirPlay device connected: AirPlayDevice[DeviceId=3427929498D4@Freebox Player._raop._tcp.local, Name=Freebox-Player.local, Model=AppleTV3,2, IPEndPoint=192.168.1.43:5000]
07/08 21:20:09 Trace: [airplay] connected
07/08 21:20:09 Trace: [airplay/client] Sending ANNOUNCE
07/08 21:20:09 Trace: updated recents in 6ms
07/08 21:20:09 Trace: updated recents in 0ms
07/08 21:20:09 Trace: [prebuffer] ready 74970/220500 (34%) @ 0/165 sec
07/08 21:20:09 Trace: [airplay/client] ANNOUNCE Succeeded
07/08 21:20:09 Trace: [airplay/client] Sending SETUP
07/08 21:20:09 Info: [stats] 10631mb Virtual, 6333mb Physical, 3221mb Managed, 0 Handles, 105 Threads
07/08 21:20:09 Trace: [airplay/client] SETUP was successful
07/08 21:20:09 Trace: [airplay/client] Sending RECORD
07/08 21:20:09 Trace: updated recents in 35ms
07/08 21:20:09 Trace: updated recents in 0ms
07/08 21:20:09 Trace: updated recents in 0ms
07/08 21:20:09 Trace: updated recents in 0ms
07/08 21:20:09 Trace: [airplay/client] Record Succeeded
07/08 21:20:09 Trace: [airplay/client] Sending SET_PARAMETER volume -22.5db
07/08 21:20:09 Trace: [airplay/client] Sending first sync packet rtptime=423011818 synctime=423100018
07/08 21:20:10 Info: 
--[ SignalPath ]---------------------------------------------
SignalPath Quality = LowQuality
Elements:
    Source Format=Mp3 22050/16/2 BitRate=64 Quality=LowQuality
    SampleRateConversion FromSampleRate=22050 ToSampleRate=44100 Algorithm=HighQuality Quality=Enhanced
    Truncate FromBitsPerSample=64 ToBitsPerSample=16 Quality=HighQuality
    Output OutputType=AirPlay Quality=HighQuality SubType= Model=AppleTV3,2
------------------------------------------------------------
07/08 21:20:11 Trace: [dbperf] flush 15904 bytes, 8 ops in 4 ms (cumulative 1621256844 bytes, 869195 ops in 361499 ms)
07/08 21:20:14 Trace: [Front Room freebox] [LowQuality 10.2x, 16/22 MP3 => 16/44] [100% buf] [PLAYING @ 0:04/2:45] You Always Hang Around - The Breeders
07/08 21:20:20 Trace: [Front Room freebox] [LowQuality 22.1x, 16/22 MP3 => 16/44] [100% buf] [PLAYING @ 0:10/2:45] You Always Hang Around - The Breeders
07/08 21:20:25 Info: [stats] 10806mb Virtual, 6503mb Physical, 3420mb Managed, 0 Handles, 106 Threads
07/08 21:20:25 Trace: [Front Room freebox] [LowQuality 32.3x, 16/22 MP3 => 16/44] [100% buf] [PLAYING @ 0:15/2:45] You Always Hang Around - The Breeders
07/08 21:20:26 Trace: [library] endmutation in 16611ms
07/08 21:20:26 Trace: [dbperf] flush 0 bytes, 0 ops in 1 ms (cumulative 1621256844 bytes, 869195 ops in 361500 ms)
07/08 21:20:26 Debug: [identification] <5816879> status: CouldNotIdentify
07/08 21:20:26 Trace: [identification] <5443375> Identifying album [Various Artists - Vacation Spirit: A Hearing Gold Compilation] with 15 tracks
07/08 21:20:26 Debug: [metadata http post req]: https://identifier.roonlabs.net/identifier/2/album?uid=8514a146-b150-462b-ba13-1c7fb19d07a2&lid=&token=f878f4d6-c26c-46ef-8ff2-bb4c3192d557
07/08 21:20:26 Debug: [identification] <5443375> identifier request id: 57f99cd9
07/08 21:20:26 Trace: [library] finished with 4 dirty tracks 1 dirty albums 1 dirty performers 0 clumping tracks, 0 clumping auxfiles 0 compute tracks, 0 deleted tracks, 4 tracks to (re)load, 0 tracks to retain, 0 auxfiles to (re)load, 0 auxfiles to retain, and 6 changed objects
07/08 21:20:26 Trace: updated recents in 6ms
07/08 21:20:26 Trace: updated recents in 0ms
07/08 21:20:26 Trace: updated recents in 2ms
07/08 21:20:26 Trace: updated recents in 0ms
07/08 21:20:26 Trace: updated recents in 0ms
07/08 21:20:26 Trace: updated recents in 0ms
07/08 21:20:28 Trace: [dbperf] flush 20845 bytes, 10 ops in 5 ms (cumulative 1621277689 bytes, 869205 ops in 361505 ms)
07/08 21:20:30 Trace: [Front Room freebox] [LowQuality 23.0x, 16/22 MP3 => 16/44] [100% buf] [PLAYING @ 0:20/2:45] You Always Hang Around - The Breeders

noris · July 8, 2020, 10:08pm

Hi @William_Lyons,

Just for reference you can use a set of three ``` signs at the start and the finish to create a code block, I applied it to your post.

As for the issue, I have a few thoughts:

Does the issue primarily impact the Front Room Freebox? Are your Sonos zones working as expected?

I noticed here that you were playing a strange bit-depth MP3, does the issue only occur when you play MP3s with this sample rate?

Is there any change in behavior if you try plugging the devices in via Ethernet to the primary router? You should be aware that we have often seen issues surrounding Powerline adapters, as we mention in our Networking Best Practices Guide.

wizardofoz · July 9, 2020, 1:01am

How hot is the Nuc getting…wonder if the fan blades are perhaps clogged with dust and the Nuc is throttling way down to cool off?

lyroon · July 9, 2020, 6:44pm

Hi @noris

Thanks for getting back to me. It is quite a strange thing: it is very common, in clusters, but hard to reproduce.

To answer your three suggestions/ questions:

No, it equally impacts the Sonos players, and appears to be server-related.

No, although my library is large and diverse and has some very old nonstandard files that can cause issues. In this case the same thing happens with Flacs, Tidal tracks, most things.

The way the freebox router / freebox delta works is designed to be over powerline. I do not think it is possible to connect them via ethernet. Although it is not ideal, everything has worked fine for a year or two with pretty much this setup, so I doubt it is the primary cause.

Here are some more datapoints. after I hit play, and it takes 3 to 5 minutes to play, if I check the log I see a critical exception, though I don’t understand it.

07/09 18:25:53 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5001 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
07/09 18:25:53 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5001 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
07/09 18:25:53 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5001 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
07/09 18:25:53 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5001 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
07/09 18:25:53 Trace: [musicpowerstate] music is playing, preventing idle sleep
07/09 18:25:54 Debug: GET /image/qttaaaaa.1024.jpg
07/09 18:25:54 Trace: [library] endmutation in 19859ms
07/09 18:25:54 Info: [library/albumdetails] Created album details screen for LibraryAlbum[1514799, Diplo - California]
07/09 18:25:54 Info: [library/albumdetails] 79004d5730303033313635343939, 79004d5230303034393134313832, 79004d5230303035313438343138, 79004d5230303035303330373538, 3e015b693e3356e2d54ca1b18e74ac59ff37, 3e01a9fcce83364faf4eb25f64be3cb3fc1d, 3e014ebe3153e1469146bdce87e867b7b7fc, a6003931313035363230, a6003835373837343933, a6003931313036353037, a6003930393530393334, a6003836313637383739, a6003835393232343536, c800706967716d7678613778346b62, c8006a6c7664397a6172676d787062, be0032313438383933, be0032313438393637, be003136323738393638
07/09 18:25:54 Trace: [dbperf] flush 0 bytes, 0 ops in 3 ms (cumulative 1878720812 bytes, 1007165 ops in 418580 ms)
07/09 18:25:54 Trace: [dbperf] flush 0 bytes, 0 ops in 2 ms (cumulative 1878720812 bytes, 1007165 ops in 418582 ms)
07/09 18:25:54 Trace: [dbperf] flush 0 bytes, 0 ops in 1 ms (cumulative 1878720812 bytes, 1007165 ops in 418583 ms)
07/09 18:25:54 Trace: [dbperf] flush 0 bytes, 0 ops in 1 ms (cumulative 1878720812 bytes, 1007165 ops in 418584 ms)
07/09 18:25:54 Debug: [easyhttp] [6098] POST to https://metadata.roonlabs.net/1/albums/translate?c=tidal-fr
07/09 18:25:54 Critical: scx: System.Exception: /session/ping failed: 999
  at Sooloos.Broker.Music.Radio.SwimProxy+<Ping>d__12.MoveNext () [0x001b7] in <43b9abb83ae042d28df03d1833a902b3>:0 
--- End of stack trace from previous location where exception was thrown ---
  at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw () [0x0000c] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Threading.Tasks.Task task) [0x0003e] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Threading.Tasks.Task task) [0x00028] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Runtime.CompilerServices.TaskAwaiter.ValidateEnd (System.Threading.Tasks.Task task) [0x00008] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Runtime.CompilerServices.TaskAwaiter`1[TResult].GetResult () [0x00000] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at Sooloos.Broker.Music.Radio.MLRadioSession+<<Init>b__36_3>d.MoveNext () [0x00070] in <43b9abb83ae042d28df03d1833a902b3>:0 
--- End of stack trace from previous location where exception was thrown ---
  at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw () [0x0000c] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Runtime.CompilerServices.AsyncMethodBuilderCore+<>c.<ThrowAsync>b__6_0 (System.Object state) [0x00000] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at Sooloos.SynchronizationContextThread._Dispatch (Sooloos.SynchronizationContextThread+SendOrPostWrapper& ret) [0x00012] in <bfa2ce817f344d24a09cb6ca0aa79686>:0 ```

and

``` 07/09 18:21:26 Trace: [Front Room freebox] [HighQuality, 16/44 TIDAL FLAC => 16/44] [1% buf] [LOADING @ 0:00] Travailler [Orgasmic Remix] - TTC
07/09 18:21:26 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5001 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
07/09 18:21:26 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5001 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
07/09 18:21:26 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5001 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
07/09 18:21:26 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5001 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
07/09 18:21:26 Trace: [musicpowerstate] music is playing, preventing idle sleep
07/09 18:21:28 Debug: GET /image/xllcaaaa.1024.jpg
07/09 18:21:30 Trace: [library] endmutation in 17158ms
07/09 18:21:30 Trace: [dbperf] flush 0 bytes, 0 ops in 1 ms (cumulative 1875428108 bytes, 1005598 ops in 417769 ms)
07/09 18:21:30 Info: [library/albumdetails] Created album details screen for LibraryAlbum[5508655, Various Artists - You Don't Know: Ninja Cuts]
07/09 18:21:30 Info: [library/albumdetails] 79004d5730303030373839333935, 79004d5230303033333336313130, 79004d5230303032373638343039, 3e01f33d2e24d6dd464088b0dc43a04cc3ed, 79004d5230303031363434383138, 79004d5230303032373638323938, 3e0110f1365061462d429b5a9bdd7f10f1cf, 3e014d8caa41a28962428137398357f0e99d, 79004d5230303031333433363738, be00343539383031, be00343539383731, be00343539383735, be00343539383834, be003136343038303133, be00343539393132
07/09 18:21:30 Debug: [easyhttp] [6084] POST to https://metadata.roonlabs.net/1/albums/translate?c=tidal-fr
07/09 18:21:30 Critical: scx: System.Exception: /session/ping failed: 998
  at Sooloos.Broker.Music.Radio.SwimProxy+<Ping>d__12.MoveNext () [0x001b7] in <43b9abb83ae042d28df03d1833a902b3>:0 
--- End of stack trace from previous location where exception was thrown ---
  at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw () [0x0000c] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Threading.Tasks.Task task) [0x0003e] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Threading.Tasks.Task task) [0x00028] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Runtime.CompilerServices.TaskAwaiter.ValidateEnd (System.Threading.Tasks.Task task) [0x00008] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Runtime.CompilerServices.TaskAwaiter`1[TResult].GetResult () [0x00000] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at Sooloos.Broker.Music.Radio.MLRadioSession+<<Init>b__36_3>d.MoveNext () [0x00070] in <43b9abb83ae042d28df03d1833a902b3>:0 
--- End of stack trace from previous location where exception was thrown ---
  at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw () [0x0000c] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Runtime.CompilerServices.AsyncMethodBuilderCore+<>c.<ThrowAsync>b__6_0 (System.Object state) [0x00000] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at Sooloos.SynchronizationContextThread._Dispatch (Sooloos.SynchronizationContextThread+SendOrPostWrapper& ret) [0x00012] in <bfa2ce817f344d24a09cb6ca0aa79686>:0 
07/09 18:21:30 Debug: [easyhttp] [6085] POST to https://swim.roonlabs.net/1/session/1cbd6e1e102743deb7e12fd408b89d9f/ping
07/09 18:21:30 Debug: [easyhttp] [6086] POST to https://swim.roonlabs.net/1/session/1cbd6e1e102743deb7e12fd408b89d9f/ping
07/09 18:21:30 Critical: scx: System.Exception: /session/ping failed: 998
  at Sooloos.Broker.Music.Radio.SwimProxy+<Ping>d__12.MoveNext () [0x001b7] in <43b9abb83ae042d28df03d1833a902b3>:0 
--- End of stack trace from previous location where exception was thrown ---
  at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw () [0x0000c] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Threading.Tasks.Task task) [0x0003e] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Threading.Tasks.Task task) [0x00028] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Runtime.CompilerServices.TaskAwaiter.ValidateEnd (System.Threading.Tasks.Task task) [0x00008] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Runtime.CompilerServices.TaskAwaiter`1[TResult].GetResult () [0x00000] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at Sooloos.Broker.Music.Radio.MLRadioSession+<<Init>b__36_3>d.MoveNext () [0x00070] in <43b9abb83ae042d28df03d1833a902b3>:0 
--- End of stack trace from previous location where exception was thrown ---
  at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw () [0x0000c] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Runtime.CompilerServices.AsyncMethodBuilderCore+<>c.<ThrowAsync>b__6_0 (System.Object state) [0x00000] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at Sooloos.SynchronizationContextThread._Dispatch (Sooloos.SynchronizationContextThread+SendOrPostWrapper& ret) [0x00012] in <bfa2ce817f344d24a09cb6ca0aa79686>:0 
07/09 18:21:30 Critical: [easyhttp] Post https://swim.roonlabs.net/1/session/1cbd6e1e102743deb7e12fd408b89d9f/ping exception: : System.ObjectDisposedException: Cannot access a disposed object.
Object name: 'System.Net.Sockets.NetworkStream'.
  at System.Net.WebConnection.BeginWrite (System.Net.HttpWebRequest request, System.Byte[] buffer, System.Int32 offset, System.Int32 size, System.AsyncCallback cb, System.Object state) [0x0002b] in <69f8661c94644655a06862d3e6b439f6>:0 
  at System.Net.WebConnectionStream.BeginWrite (System.Byte[] buffer, System.Int32 offset, System.Int32 size, System.AsyncCallback cb, System.Object state) [0x00270] in <69f8661c94644655a06862d3e6b439f6>:0 
  at System.IO.Stream+<>c.<BeginEndWriteAsync>b__53_0 (System.IO.Stream stream, System.IO.Stream+ReadWriteParameters args, System.AsyncCallback callback, System.Object state) [0x00000] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Threading.Tasks.TaskFactory`1[TResult].FromAsyncTrim[TInstance,TArgs] (TInstance thisRef, TArgs args, System.Func`5[T1,T2,T3,T4,TResult] beginMethod, System.Func`3[T1,T2,TResult] endMethod) [0x00008] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.IO.Stream.BeginEndWriteAsync (System.Byte[] buffer, System.Int32 offset, System.Int32 count) [0x00000] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.IO.Stream.WriteAsync (System.Byte[] buffer, System.Int32 offset, System.Int32 count, System.Threading.CancellationToken cancellationToken) [0x00009] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.IO.Stream.WriteAsync (System.Byte[] buffer, System.Int32 offset, System.Int32 count) [0x00009] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at (wrapper remoting-invoke-with-check) System.IO.Stream.WriteAsync(byte[],int,int)
  at Sooloos.EasyHttp+BytesContent+<CopyToStreamAsync>d__5.MoveNext () [0x00011] in <bfa2ce817f344d24a09cb6ca0aa79686>:0 
--- End of stack trace from previous location where exception was thrown ---
  at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw () [0x0000c] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Threading.Tasks.Task task) [0x0003e] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Threading.Tasks.Task task) [0x00028] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Runtime.CompilerServices.TaskAwaiter.ValidateEnd (System.Threading.Tasks.Task task) [0x00008] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Runtime.CompilerServices.TaskAwaiter.GetResult () [0x00000] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at Sooloos.EasyHttp+<QueryAsync>d__2.MoveNext () [0x0066b] in <bfa2ce817f344d24a09cb6ca0aa79686>:0 
07/09 18:21:30 Critical: [easyhttp] Post https://swim.roonlabs.net/1/session/1cbd6e1e102743deb7e12fd408b89d9f/ping exception: : System.ObjectDisposedException: Cannot access a disposed object.
Object name: 'System.Net.Sockets.NetworkStream'.
  at System.Net.WebConnection.BeginWrite (System.Net.HttpWebRequest request, System.Byte[] buffer, System.Int32 offset, System.Int32 size, System.AsyncCallback cb, System.Object state) [0x0002b] in <69f8661c94644655a06862d3e6b439f6>:0 
  at System.Net.WebConnectionStream.BeginWrite (System.Byte[] buffer, System.Int32 offset, System.Int32 size, System.AsyncCallback cb, System.Object state) [0x00270] in <69f8661c94644655a06862d3e6b439f6>:0 
  at System.IO.Stream+<>c.<BeginEndWriteAsync>b__53_0 (System.IO.Stream stream, System.IO.Stream+ReadWriteParameters args, System.AsyncCallback callback, System.Object state) [0x00000] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Threading.Tasks.TaskFactory`1[TResult].FromAsyncTrim[TInstance,TArgs] (TInstance thisRef, TArgs args, System.Func`5[T1,T2,T3,T4,TResult] beginMethod, System.Func`3[T1,T2,TResult] endMethod) [0x00008] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.IO.Stream.BeginEndWriteAsync (System.Byte[] buffer, System.Int32 offset, System.Int32 count) [0x00000] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.IO.Stream.WriteAsync (System.Byte[] buffer, System.Int32 offset, System.Int32 count, System.Threading.CancellationToken cancellationToken) [0x00009] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.IO.Stream.WriteAsync (System.Byte[] buffer, System.Int32 offset, System.Int32 count) [0x00009] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at (wrapper remoting-invoke-with-check) System.IO.Stream.WriteAsync(byte[],int,int)
  at Sooloos.EasyHttp+BytesContent+<CopyToStreamAsync>d__5.MoveNext () [0x00011] in <bfa2ce817f344d24a09cb6ca0aa79686>:0 
--- End of stack trace from previous location where exception was thrown ---
  at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw () [0x0000c] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Threading.Tasks.Task task) [0x0003e] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Threading.Tasks.Task task) [0x00028] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Runtime.CompilerServices.TaskAwaiter.ValidateEnd (System.Threading.Tasks.Task task) [0x00008] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Runtime.CompilerServices.TaskAwaiter.GetResult () [0x00000] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at Sooloos.EasyHttp+<QueryAsync>d__2.MoveNext () [0x0066b] in <bfa2ce817f344d24a09cb6ca0aa79686>:0 
07/09 18:21:30 Debug: [easyhttp] [6087] POST to https://swim.roonlabs.net/1/session/1cbd6e1e102743deb7e12fd408b89d9f/ping
07/09 18:21:30 Critical: scx: System.Exception: /session/ping failed: 998
  at Sooloos.Broker.Music.Radio.SwimProxy+<Ping>d__12.MoveNext () [0x001b7] in <43b9abb83ae042d28df03d1833a902b3>:0 
--- End of stack trace from previous location where exception was thrown ---
  at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw () [0x0000c] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Threading.Tasks.Task task) [0x0003e] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Threading.Tasks.Task task) [0x00028] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Runtime.CompilerServices.TaskAwaiter.ValidateEnd (System.Threading.Tasks.Task task) [0x00008] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Runtime.CompilerServices.TaskAwaiter`1[TResult].GetResult () [0x00000] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at Sooloos.Broker.Music.Radio.MLRadioSession+<<Init>b__36_3>d.MoveNext () [0x00070] in <43b9abb83ae042d28df03d1833a902b3>:0 
--- End of stack trace from previous location where exception was thrown ---
  at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw () [0x0000c] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at System.Runtime.CompilerServices.AsyncMethodBuilderCore+<>c.<ThrowAsync>b__6_0 (System.Object state) [0x00000] in <cdba38a34a8b4bec95234c86d633b1ff>:0 
  at Sooloos.SynchronizationContextThread._Dispatch (Sooloos.SynchronizationContextThread+SendOrPostWrapper& ret) [0x00012] in <bfa2ce817f344d24a09cb6ca0aa79686>:0 
07/09 18:21:30 Trace: [metadatasvc] GOT [7024] (35944ms) Sooloos.Msg.Metadata.UpdateMetadataResponse: 
07/09 18:21:30 Debug: GET /image/cwraaaaa.256.jpg
07/09 18:21:30 Trace: [metadatasvc] REQ [7025] https://metadataserver.roonlabs.net/md/4/getmetadata?uid=8514a146-b150-462b-ba13-1c7fb19d07a2&lid=&token=f878f4d6-c26c-46ef-8ff2-bb4c3192d557&metadataid[]=7b004d5430303432313238313730&metadataid[]=7a004d4e30303030313735353235&metadataid[]=5e01dec2c9203ce2a04387067c5bfdb1d31e&metadataid[]=7a004d4e30303032383130333737&metadataid[]=5e013ea41bbaa88071448d02c31453f4aa88&metadataid[]=7a004d4e30303032353635363039&metadataid[]=7a004d4e30303030353134393332&metadataid[]=7a004d4e30303030313338303832&metadataid[]=5e01fbd3fd05e96f814b926ef6d52dd1e737&metadataid[]=7a004d4e30303033313234323933&metadataid[]=5e01ea3dccc13b5e67448cd005014a7cfc40&metadataid[]=7a004d4e30303030373530343039&metadataid[]=6401e873c23502ddc63f1ad62ab65928b2f3&metadataid[]=79004d5730303032313930363735&metadataid[]=5e011ae84d5ede25f045bcc44e8c27f04112&metadataid[]=5e012fd41d088100464287e5df45acca0fae&metadataid[]=5e0135f3d6ffa35db24694db7ccd6845e831&metadataid[]=5e01b64107b28a9c1845b0238d8b67eab79e&metadataid[]=5e0148662b3cb9d3dd4fba0aad608b53c2f8&metadataid[]=7a004d4e30303030333435363332&metadataid[]=7a004d4e30303030333834393739&metadataid[]=7a004d4e30303030343730323834&metadataid[]=7a004d4e30303030393933383530&metadataid[]=7a004d4e30303032383637343439&metadataid[]=5e014790bb191d16334a92669325b386e316&metadataid[]=5e01fd5adbee6b1a7b4da5ce3cfb7a506a37&metadataid[]=5e01f761d55d6472cb42a3b2bddeb750eb39&metadataid[]=7a004d4e30303030333939373835&metadataid[]=5e0164bc7e2706df604dbb95fe14936870b2&metadataid[]=7b004d5430303432313238313532&metadataid[]=7a004d4e30303032383130333136&metadataid[]=7a004d4e30303032313936323638&metadataid[]=7a004d4e30303032353436363237&metadataid[]=5e016b2108fff698b84c9c0b6fd16855f2d0&metadataid[]=7a004d4e30303030373433383439&metadataid[]=7a004d4e30303031303637323537&metadataid[]=7a004d4e30303030323333393634&metadataid[]=7a004d4e30303032393334333539&metadataid[]=7a004d4e30303032393738313634&metadataid[]=7b004d5430303432313238313533&metadataid[]=7a004d4e30303031343537333530&metadataid[]=7a004d4e30303032343235393336&metadataid[]=66010ab926dca83744151400df943f66bad2&metadataid[]=64019e3b8ae1d38963fc1fe7a56a7dc59c72&metadataid[]=7b004d5430303432313238313534&metadataid[]=6601f2b59aa8a4213355d4a714993cbb9c08&metadataid[]=64019fbc01775bed964845807a2756c34e06&metadataid[]=7b004d5430303432313238313535&metadataid[]=5e0185b28ae303c9854283765a71944b345c&metadataid[]=6601df9b7eef77b5759c987b3a195f028ee8&metadataid[]=64012018931d5ff67edfe6435ccf6606b705&metadataid[]=7a004d4e30303030353830343938&metadataid[]=7b004d5430303432313238313536&metadataid[]=5e0177872ed2528fac439ab9dd4e639d16da&metadataid[]=640164d713396e2382b67a431d0f06d63c67&metadataid[]=7b004d5430303432313238313537&metadataid[]=6401c558cb9ab9ae2e08185cdfd3df341215&metadataid[]=7b004d5430303432313238313538&metadataid[]=6401aec28c8e3b6863c7682b460bbb37e765&metadataid[]=7b004d5430303432313238313539&metadataid[]=640125d801dba93d45123ffdeec485dd0acf&metadataid[]=7b004d5430303432313238313630&metadataid[]=6601a7ee174ff6a0d310d7dd98a182c4aaa4&metadataid[]=6401b3caf0fa30fc7c779376c3981aec4f74&metadataid[]=7b004d5430303432313238313631&metadataid[]=6401ac982f6e92b3c6a584e49fb52951ba0c&metadataid[]=7b004d5430303432313238313632&metadataid[]=64012646831ac164d5ba53b7bfc6f1b61934&metadataid[]=7b004d5430303432313238313633&metadataid[]=64015c03bbbf28fe4ef2eaee01234f66f168&metadataid[]=7b004d5430303432313238313634&metadataid[]=640162126ec139f5df953b0b2d8ea7bf7e59&metadataid[]=7b004d5430303432313238313635&metadataid[]=6401104f12b39ae677a4900471c38b5cd1da&metadataid[]=7b004d5430303432313238313636&metadataid[]=6601005ab4260ae19585e3df539a834b0946&metadataid[]=640176f1fbc226f6e96fd5740a6bb8723d54&metadataid[]=7b004d5430303432313238313637&metadataid[]=5e010b60f0b27d381a47b55f7b2893d39327&metadataid[]=6601f171c5da7c4a013c509f105cd3aa3c88&metadataid[]=6401fca328c9aab85fbe0c42f659ee2d5f8e&metadataid[]=7b004d5430303432313238313638&metadataid[]=640197c1d88be6bd75dca83c46533575ab13&metadataid[]=7b004d5430303432313238313639&metadataid[]=64017b6e86c0b281693888e288d9d64b86fc&metadataid[]=7b004d5430303432313238313731&metadataid[]=640181c1f32e898e7565cb490c90bf3497a8&metadataid[]=7b004d5430303432313238313732&metadataid[]=6401a802948104bf98c95867711fd81b4cbe&metadataid[]=7b004d5430303432313238313733&metadataid[]=66017205fc919985a732cc2a6296da5c93d5&metadataid[]=6401138e1ce6458b1b7626bccbcc3d2c3ba6&metadataid[]=61003237323933343830303330&metadataid[]=6401f33e7517f73554094981f8f1b068b8e6&metadataid[]=3e0135714436cc609f469b8443612f41585a&metadataid[]=61003237323933343830303230&metadataid[]=7a004d4e30303030383833333138&metadataid[]=5e0181ee6ff2083c82479d05daeed4a7f4c7&metadataid[]=7a004d4e30303030313937343436&metadataid[]=7a004d4e30303030333833363332 ```

It feels like on hitting a new track Roon is trying to do something in the background, hitting an error and getting into an unplanned state. What are these swim.roonlabs connections and are they really needed to play the music?

Thank for your help

ged_hickman1 · July 9, 2020, 6:51pm

I think swim relates to the roon radio servers if you are having issues once you get to roon radio driving playback then that might make sense.
Is it possible for you to get to the DNS server entries in your router?

lyroon · July 9, 2020, 7:19pm

Radio actually works fine, as far as I have noticed. I don’t use it as often though.

I’m not sure about the DNS setup. Is there a way to check? The thing is, I can connect, because the error is intermittent. But sometimes, for a few hours, this happens. I’m not sure DNS would be volatile.

noris · July 10, 2020, 2:09am

Hi @lyroon,

That error looks like you’re trying to start Roon Radio and it fails to communicate with our servers to start properly. If you reboot the Core is the issue the same? Does the issue only occur on Roon Radio? If you try to queue up a playlist of tracks, do they all play properly?

I would check the DNS setup you have, we have seen users have a better experience if they change the DNS to Cloudflare DNS, Quad9 or Google DNS. It seems like Freebox has all of their documentation in French, so this is what I could find:

lyroon · July 10, 2020, 8:21am

Hi @noris

That is a good point - I misunderstood @ged_hickman1: I don’t use the actual live radio, but I do usually use “roon radio” to select tracks. I am not sure that I have observed this outside of roon radio. That is the usual way I play my library. It does not happen when playing a full album, but it does happen on local files once it starts auto-selecting.

I’ll try changing DNS, it can’t hurt. That said, is it possible to also think about the Roon side of this? I’m not having issues with any other services or applications.

If the Roon Radio server was not reachable for some reason would the expected behaviour be to spin and be unresponsive to controllers for five minutes? Or just to fail back to shuffle the local library? I think this has happened before and it just popped up a message saying it was limiting to the local library and continued. The freezing up for 3 to 5 minutes is the real issue: I don’t really mind if the roon servers are not reachable.

So I will try to change DNS services but I feel the real issue here is that Roon freezes for a few minutes and becomes unresponsive.

noris · July 17, 2020, 1:02am

Hi @lyroon,

I wanted to check in with you, has the DNS change helped at all with the radio issue?

lyroon · August 3, 2020, 11:38am

Hi @noris

I was never able to change the DNS in my Freebox setup.

However, the issue resolved itself the following day, for unknown reasons. Maybe their DNS host was having issues and recovered.

I realise it is apparently an unusual case, but I would still think that in the case of DNS issues there should still be no issues playing local content and if there is this would be a bug.

Thanks

noris · August 3, 2020, 7:06pm

Hi @lyroon,

Thanks for letting me know the issue was resolved by itself.

The issue here was that you tried to start playback of Roon Radio, which involves reaching out to our servers and requesting the server provide a list of playback items, since the DNS issue was occurring, your Roon Core could not fetch this list.

In any case, I will go ahead and close this ticket out, but if you run into any other issues, just let us know!

lyroon · August 4, 2020, 2:46pm

Hi @noris

Thanks, I agree we may as well close it out as resolved, but I think you misunderstood my point regarding this being a bug.

Up to there, I fully agree with you. But if it does connect and finds nothing similar it gives the message “Nothing similar found, restricting to local library”. Something like this behaviour if it cannot connect or is offline seems reasonable. Freezing the system and being unresponsive for 3 to 5 minutes is not the right behaviour.

noris · August 4, 2020, 7:37pm

Thanks for the feedback here @lyroon, so it’s the messaging which you are saying is the issue here. I’ll forward this feedback on to the team, thanks!

system · August 6, 2020, 7:37am

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