Connection to RoonReady-Device is lost every X hours

Support
1

Roon Core Machine

Virtual Windows Server 2016
Virtual WIN10

Networking Gear & Setup Details

OPNSense Router
Mikrotik switch
Ethernet based connection

Connected Audio Devices

Dutch&Dutch 8c

Number of Tracks in Library

8000

Description of Issue

Sporadically, while playing music on a pair of roon-ready pair of Dutch&Dutch speakers, the music stops and can’t be restarted by giving the play command again.
When the problem first arised I helped myself by restarting the Server that has the roon-Core installed, later on I found out that restarting roonserver or even just re-initialise the connection to speakers in order to get it going again.
Some weeks ago I found that in the settings->audio menu the speakers are associated with an null IP-Address of 169.x.x.x if the connection is lost (not clear if this was visible before the last major upgrade? just found out lately)
So at this point the supposed reason is already quite clear in front of me: for some weird reason the roon-server seems to “forget” the ip-addresse(s) of the speakers from time to time and is, for some reason, not able to resolve this on it’s own.
I tried to dig some logs to no avail. Maybe i have to turn on some debugging first?
I then tried to move the server from some server2016 machine to some win10 machine just to be perfectly in line with the system recommendations, which didn’t help.
Thats’s where I am now: I ask myself: how is the discovery-mechanism for the roon-ready-devices organized? Does it rely on some protocol like avahi or the like? Is there an hidden option to configure the roon-ready-devices manually? My speakers have an fixed-ip-address assigned and there is little reason to doubt that this Ip-address does ever change even for seconds or the like.

2

I already can add up to this (maybe beginning to post in forums for technical problems also cranks up one’s own seriousness about really wanting to debug stuff - the forum as a mean of constructive self talk)?

Anyway: the Roon-server.log (in contrast to the raat-server-log) does give away some information about the initialization of the speakers … at this time it is not clear why i didn’t find anything potentially useful in the logs when i tried in the past.

As I didn’t track the “error” yesterday in the evening exactly timewise (and started playing music on different devices afterwards) I will, for now, wait until the error strikes again and will try to pin down this moment in the logs.

7

Ok, this didn’t take too long.
Also, this time, I think I can come up with some log to hopefully draw some conclusions from.

11/18 19:53:31 Trace: [Office] [Enhanced, 16/44 MQA TIDAL FLAC => 24/44 MQA] [100% buf] [PLAYING @ 0:16/10:21] Heir Apparent - Opeth
11/18 19:53:36 Trace: [Office] [Enhanced, 16/44 MQA TIDAL FLAC => 24/44 MQA] [100% buf] [PLAYING @ 0:21/10:21] Heir Apparent - Opeth
11/18 19:53:41 Trace: [Office] [Enhanced, 16/44 MQA TIDAL FLAC => 24/44 MQA] [100% buf] [PLAYING @ 0:25/10:21] Heir Apparent - Opeth
11/18 19:53:43 Trace: [Office] [zoneplayer/raat] sync Dutch & Dutch 8c: realtime=10803087434182 rtt=500us offset=62060434us delta=-54us drift=104495us in 3394,2065s (30,786ppm, 110,831ms/hr)
11/18 19:53:45 Info: [stats] 5740mb Virtual, 484mb Physical, 313mb Managed, 2219 Handles, 116 Threads
11/18 19:53:46 Trace: [Office] [Enhanced, 16/44 MQA TIDAL FLAC => 24/44 MQA] [100% buf] [PLAYING @ 0:31/10:21] Heir Apparent - Opeth
11/18 19:53:51 Trace: [Office] [Enhanced, 16/44 MQA TIDAL FLAC => 24/44 MQA] [100% buf] [PLAYING @ 0:36/10:21] Heir Apparent - Opeth
11/18 19:53:56 Trace: [Office] [Enhanced, 16/44 MQA TIDAL FLAC => 24/44 MQA] [100% buf] [PLAYING @ 0:41/10:21] Heir Apparent - Opeth
11/18 19:54:00 Info: [stats] 5744mb Virtual, 484mb Physical, 314mb Managed, 2230 Handles, 117 Threads
11/18 19:54:01 Trace: [Office] [Enhanced, 16/44 MQA TIDAL FLAC => 24/44 MQA] [100% buf] [PLAYING @ 0:46/10:21] Heir Apparent - Opeth
11/18 19:54:04 Debug: [raat/tcpaudiosource] disconnecting
11/18 19:54:04 Debug: [raat/tcpaudiosource] connecting to 169.254.249.160:46705
11/18 19:54:06 Trace: [Office] [Enhanced, 16/44 MQA TIDAL FLAC => 24/44 MQA] [100% buf] [PLAYING @ 0:51/10:21] Heir Apparent - Opeth
11/18 19:54:11 Trace: [Office] [Enhanced, 16/44 MQA TIDAL FLAC => 24/44 MQA] [100% buf] [PLAYING @ 0:56/10:21] Heir Apparent - Opeth
11/18 19:54:14 Debug: [raat/tcpaudiosource] disconnecting
11/18 19:54:14 Warn: [zoneplayer/raat] Error during streaming: System.Exception: serverside buffer overrun
   bei Sooloos.Broker.Transport.RaatTcpAudioSource.SendFrames(IPEndPoint ep, Int32 stream_id, Int64 streamsample, Double buffersize, StreamFormat format, Double gain, Double peak, Byte[] buf, Int32 nsamples)
   bei Sooloos.Broker.Transport.RaatZonePlayer.<>c__DisplayClass31_0.<_StartStream4>b__1()
11/18 19:54:14 Debug: FTMSI-B closed file for ti/46A613AC; open files:0
11/18 19:54:14 Debug: FTMSI-B ti/46A613AC download status: FirstBlockRetrieved accessTimeout:True openFiles:0 prev:(FirstBlockRetrieved,True,1)
11/18 19:54:14 Info: FTMSI-B ti/46A613AC: allocated bw changed from 51200 to 0 kbps
11/18 19:54:14 Info: FTMSI-B 1 FileCache ti/82249224 dwStatus:AllBlocksDownloaded files:1 accessTimeOut:False priorities: ('zoneplayer:3':32) --> bw limit:0kbps
11/18 19:54:14 Info: FTMSI-B 2 FileCache ti/46A613AC dwStatus:FirstBlockRetrieved files:0 accessTimeOut:True priorities: ('zoneplayer:3':33) --> bw limit:0kbps
11/18 19:54:14 Error: [raat/tcpaudiosource] connect failed: Der Objektverweis wurde nicht auf eine Objektinstanz festgelegt.
11/18 19:54:14 Warn: [zone Office] Track Stopped Due to Error
11/18 19:54:14 Warn: [raat/tcpaudiosource] disconnecting + retrying
11/18 19:54:14 Info: [library] recorded play for profile e276f0b7-1456-42ba-804b-9d795832ad90: mediaid=50:1:9ec2a6ac-de04-40a7-bd0f-408af6493fa5 metadataid= contentid=168:0:96962682 libraryid=50:1:9ec2a6ac-de04-40a7-bd0f-408af6493fa5 isfromradio=False isfrommix=False isfrommobile=
11/18 19:54:14 Info: 
--[ SignalPath ]---------------------------------------------
SignalPath Quality = Inactive
Elements:
------------------------------------------------------------
11/18 19:54:14 Warn: inactive signal path :(
11/18 19:54:14 Info: [zone Office] OnPlayFeedback StoppedEndOfMediaUnnatural
11/18 19:54:14 Debug: [zone Office] _Advance (Track)
11/18 19:54:14 Trace: [library] finished with 40 dirty tracks 4 dirty albums 3 dirty performers 20 dirty works 40 dirty performances 0 clumping tracks, 0 clumping auxfiles 0 compute tracks, 0 deleted tracks, 0 tracks to (re)load, 0 tracks to retain, 0 auxfiles to (re)load, 0 auxfiles to retain, and 68 changed objects
11/18 19:54:14 Trace: [Office] [Enhanced, 16/44 MQA TIDAL FLAC => 24/44 MQA] [100% buf] [LOADING @ 0:00] Era - Opeth
11/18 19:54:14 Info: [library/albumdetails] found 1 ingroup alternates, 0 other alternates
11/18 19:54:14 Info: [library/albumdetails] found 1 ingroup alternates, 0 other alternates
11/18 19:54:14 Debug: [music/profilestats] Computed stats in 101ms, got 18 top albums, 16 top performers, 11 genres
11/18 19:54:14 Debug: [music/profilestats] Computed stats in 73ms, got 18 top albums, 16 top performers, 11 genres
11/18 19:54:14 Debug: [music/profilestats] Computed stats in 75ms, got 18 top albums, 16 top performers, 11 genres
11/18 19:54:14 Debug: [music/profilestats] Computed stats in 177ms, got 50 top albums, 50 top performers, 55 genres
11/18 19:54:14 Trace: [dbperf] flush 0 bytes, 0 ops in 39 ms (cumulative 0 bytes, 0 ops in 4898 ms)
11/18 19:54:14 Trace: [library] endmutation in 550ms
11/18 19:54:14 Trace: [dbperf] flush 0 bytes, 0 ops in 3 ms (cumulative 0 bytes, 0 ops in 4901 ms)
11/18 19:54:15 Trace: [music/searchindex] [search-index]  removed: 1 albums, 1 tracks, 0 works, 1 performers, 0 labels, 0 genres
11/18 19:54:15 Trace: [music/searchindex] [search-index] added in 8405ms: 1 albums, 1 tracks, 0 works, 1 performers, 0 labels, 0 genres
11/18 19:54:15 Debug: [easyhttp] [969] GET to https://api.tidal.com/v1/tracks/96962683/playbackinfopostpaywall?countryCode=DE&audioquality=HI_RES&assetpresentation=FULL&playbackmode=STREAM returned after 203 ms, status code: 200
11/18 19:54:15 Trace: [tidal/http] GET https://api.tidal.com/v1/tracks/96962683/playbackinfopostpaywall?countryCode=DE&audioquality=HI_RES&assetpresentation=FULL&playbackmode=STREAM => Success
11/18 19:54:15 Debug: [easyhttp] [970] GET to https://api.tidal.com/v1/tracks/96962684/playbackinfopostpaywall?countryCode=DE&audioquality=HI_RES&assetpresentation=FULL&playbackmode=STREAM returned after 220 ms, status code: 200
11/18 19:54:15 Trace: [tidal/http] GET https://api.tidal.com/v1/tracks/96962684/playbackinfopostpaywall?countryCode=DE&audioquality=HI_RES&assetpresentation=FULL&playbackmode=STREAM => Success
11/18 19:54:15 Debug: [easyhttp] [971] GET to https://api.tidal.com/v1/tracks/96962683?countryCode=DE returned after 34 ms, status code: 200
11/18 19:54:15 Trace: [tidal/http] GET https://api.tidal.com/v1/tracks/96962683?countryCode=DE => Success
11/18 19:54:15 Info: [Office] [zoneplayer] Playing: http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInMjNkMzhmODZlNTkwNjE0YTk1ZmRjMzVmMjQzOTU1OWJfNjAubXA0/0.flac
11/18 19:54:15 Debug: FTMSI-B closed file for ti/82249224; open files:0
11/18 19:54:15 Info: [audio/env] [zoneplayer -> stream] All streams were disposed
11/18 19:54:15 Debug: FTMSI-B ti/82249224 download status: AllBlocksDownloaded accessTimeout:False openFiles:0 prev:(AllBlocksDownloaded,False,1)
11/18 19:54:15 Trace: [Office] [zoneplayer/raat] Endpoint Dutch & Dutch 8c State Changed: Playing => Prepared
11/18 19:54:15 Trace: [Dutch & Dutch 8c @ 10.4.0.93:35075] [raatclient] SENT [9615]{"request":"end_stream"}
11/18 19:54:15 Info: [audio/env] [zoneplayer -> stream -> endpoint] All streams were disposed
11/18 19:54:15 Info: [audio/env] [zoneplayer] All streams were disposed
11/18 19:54:15 Trace: [Dutch & Dutch 8c @ 10.4.0.93:35075] [raatclient] GOT [6186] {"status":"Ended"}
11/18 19:54:15 Trace: [Dutch & Dutch 8c @ 10.4.0.93:35075] [raatclient] GOT [9615] {"status":"Success"}
11/18 19:54:15 Debug: [easyhttp] [972] GET to https://api.tidal.com/v1/tracks/96962684?countryCode=DE returned after 137 ms, status code: 200
11/18 19:54:15 Trace: [tidal/http] GET https://api.tidal.com/v1/tracks/96962684?countryCode=DE => Success
11/18 19:54:15 Debug: [easyhttp] [967] POST to https://metadata.roonlabs.net/1/albums/translate?c=tidal-de returned after 613 ms, status code: 200
11/18 19:54:15 Info: [stats] 5784mb Virtual, 488mb Physical, 324mb Managed, 2227 Handles, 127 Threads
11/18 19:54:15 Debug: [easyhttp] [965] POST to https://metadata.roonlabs.net/1/albums/translate?c=tidal-de returned after 634 ms, status code: 200
11/18 19:54:15 Debug: [easyhttp] [968] POST to https://metadata.roonlabs.net/1/performers/translate?c=tidal-de returned after 633 ms, status code: 200
11/18 19:54:15 Debug: [easyhttp] [966] POST to https://metadata.roonlabs.net/1/performers/translate?c=tidal-de returned after 635 ms, status code: 200
11/18 19:54:15 Info: sleep 500ms after flush
11/18 19:54:15 Debug: FTMSI-B Cache open file ti/46A613AC domain: zoneplayer:3 ordinal:34
11/18 19:54:15 Debug: FTMSI-B ti/46A613AC download status: FirstBlockRetrieved accessTimeout:True openFiles:1 prev:(FirstBlockRetrieved,True,0)
11/18 19:54:15 Info: [Office] [zoneplayer] Queueing: http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInZTM1NjhkOTJhOTg3YjJmOGNmZGIzMWY1YzdkYzI1NjVfNjAubXA0/0.flac
11/18 19:54:15 Info: FTMSI-B ti/46A613AC: allocated bw changed from 0 to 51200 kbps
11/18 19:54:15 Info: FTMSI-B 1 FileCache ti/82249224 dwStatus:AllBlocksDownloaded files:0 accessTimeOut:True priorities: ('zoneplayer:3':32) --> bw limit:0kbps
11/18 19:54:15 Info: FTMSI-B 2 FileCache ti/46A613AC dwStatus:FirstBlockRetrieved files:1 accessTimeOut:True priorities: ('zoneplayer:3':34) --> bw limit:51200kbps
11/18 19:54:15 Info: FTMSI-B FileCache removed ti/82249224
11/18 19:54:15 Debug: FTMSI-B-OE ti/82249224 exit thread signalled
11/18 19:54:15 Trace: FTMSI-B 1 FileCache ti/46A613AC dwStatus:FirstBlockRetrieved files:1 accessTimeOut:True priorities: ('zoneplayer:3':34) --> bw limit:51200kbps
11/18 19:54:15 Debug: FTMSI-B-OE ti/82249224 exit thread signalled
11/18 19:54:15 Info: FTMSI-B new FileCache ti/5AD7F6FB
>>> C:\Users\mFinke\AppData\Local\RoonServer\Cache\smc.db\bfc\31.cache
>>> http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInZTM1NjhkOTJhOTg3YjJmOGNmZGIzMWY1YzdkYzI1NjVfNjAubXA0/0.flac
11/18 19:54:15 Debug: FTMSI-B Cache open file ti/5AD7F6FB domain: zoneplayer:3 ordinal:35
11/18 19:54:15 Debug: FTMSI-B ti/5AD7F6FB download status: DownloadNotStarted accessTimeout:False openFiles:1 prev:no
11/18 19:54:15 Info: FTMSI-B FileCache disposed ti/82249224
11/18 19:54:15 Info: [Office] [zoneplayer]     Open Result (Playing):Result[Status=Success]
11/18 19:54:15 Info: [Office] [zoneplayer] Starting playback
11/18 19:54:15 Trace: [Office] [zoneplayer/raat] StartStream Sooloos.Broker.Transport.RaatZonePlayer+Endpoint: StreamFormat(channels=2, bitspersample=24, samplerate=44100, isdts=False, mqa=44100) => StreamFormat(channels=2, bitspersample=24, samplerate=44100, isdts=False, mqa=44100) streamid=1201454764
11/18 19:54:15 Info: [zone Office] OnPlayFeedback Playing
11/18 19:54:15 Trace: [Office] [Enhanced, 16/44 MQA TIDAL FLAC => 24/44 MQA] [100% buf] [PLAYING @ 0:00] Era - Opeth
11/18 19:54:15 Trace: [prebuffer] ready 149940/441000 (34%) @ 0/450 sec
11/18 19:54:16 Info: 
--[ SignalPath ]---------------------------------------------
SignalPath Quality = Enhanced
Elements:
    Source Format=Flac 44100/16/2  Quality=Lossless MQA 44100
    MQA Subtype=authentication LightState=off OriginalSampleRate=44100 OutputSampleRate= OutputBitsPerSample=
    Raat Device=Dutch & Dutch 8c
    SampleRateConversion FromSampleRate=44100 ToSampleRate=48000 Algorithm=Other Quality=None
    DSP Subtype=dutch_dutch_room_eq PresetKey= TruePeak= Value= StringValue= Model= FromSampleRate= ToSampleRate= Quality=Enhanced PresetDisplayName= ModeDisplayName=10_2022
    DSP Subtype=dutch_dutch_tone_control PresetKey= TruePeak= Value= StringValue= Model= FromSampleRate= ToSampleRate= Quality=Enhanced PresetDisplayName= ModeDisplayName=
    Amplifier Method=dutch_dutch Quality=Lossless
    Output OutputType=Local_Speakers Quality=Lossless SubType= Model=
------------------------------------------------------------
11/18 19:54:16 Debug: FTMSI-B-OE ti/46A613AC exit thread signalled
11/18 19:54:16 Debug: FTMSI-B ti/46A613AC download status: AllBlocksDownloaded accessTimeout:False openFiles:1 prev:(FirstBlockRetrieved,False,1)
11/18 19:54:16 Info: FTMSI-B ti/5AD7F6FB: allocated bw changed from 0 to 51200 kbps
11/18 19:54:16 Info: FTMSI-B ti/46A613AC: allocated bw changed from 51200 to 0 kbps
11/18 19:54:16 Info: FTMSI-B 1 FileCache ti/5AD7F6FB dwStatus:DownloadNotStarted files:1 accessTimeOut:False priorities: ('zoneplayer:3':35) --> bw limit:51200kbps
11/18 19:54:16 Info: FTMSI-B 2 FileCache ti/46A613AC dwStatus:AllBlocksDownloaded files:1 accessTimeOut:False priorities: ('zoneplayer:3':34) --> bw limit:0kbps
11/18 19:54:16 Debug: FTMSI-B-OE ti/5AD7F6FB created new req 1 for block 0 p 4294967295; active requests 1
11/18 19:54:16 Debug: [easyhttp] [974] GET to http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInZTM1NjhkOTJhOTg3YjJmOGNmZGIzMWY1YzdkYzI1NjVfNjAubXA0/0.flac?token=1668801254~NTIwZTk2Y2VlNDFhYWI5NzZmOGE1MjI3YjBkMjJjYzQ2ZmUyNTRkMA== returned after 32 ms, status code: 200
11/18 19:54:16 Debug: FTMSI-B got length for ti/5AD7F6FB; 106,1 MBytes
11/18 19:54:16 Debug: FTMSI-B ti/5AD7F6FB download status: FileLengthRetrieved accessTimeout:False openFiles:1 prev:(DownloadNotStarted,False,1)
11/18 19:54:16 Debug: FTMSI-B-OE set min bandwidth for ti/5AD7F6FB to 1222 kbps
11/18 19:54:16 Info: FTMSI-B-OE ti/5AD7F6FB rid:1 response took 32ms
11/18 19:54:16 Debug: FTMSI-B ti/5AD7F6FB download status: FirstBlockRetrieved accessTimeout:False openFiles:1 prev:(FileLengthRetrieved,False,1)
11/18 19:54:16 Info: [Office] [zoneplayer] Open result (Queueing): Result[Status=Success]
11/18 19:54:16 Debug: FTMSI-B-OE ti/46A613AC rid:1 request ended -- first block: 0 blocks read: 1614 download speed: 6908kbps response time: 190ms
11/18 19:54:17 Warn: [Office] [zoneplayer/raat] failed to sync sender clock to endpointDutch & Dutch 8c: Sooloos.Broker.Transport.ClockSyncResult
11/18 19:54:17 Warn: [Office] [zoneplayer/raat] failed to sync clocks with any endpoints..giving up
11/18 19:54:17 Info: [audio/env] [zoneplayer -> stream] All streams were disposed
11/18 19:54:17 Info: [audio/env] [zoneplayer -> stream -> endpoint] All streams were disposed
11/18 19:54:17 Info: sleep 500ms after flush
11/18 19:54:17 Debug: FTMSI-B closed file for ti/5AD7F6FB; open files:0
11/18 19:54:17 Debug: FTMSI-B ti/5AD7F6FB download status: FirstBlockRetrieved accessTimeout:False openFiles:0 prev:(FirstBlockRetrieved,False,1)
11/18 19:54:17 Info: FTMSI-B ti/5AD7F6FB: allocated bw changed from 51200 to 0 kbps
11/18 19:54:17 Info: FTMSI-B 1 FileCache ti/5AD7F6FB dwStatus:FirstBlockRetrieved files:0 accessTimeOut:False priorities: ('zoneplayer:3':35) --> bw limit:0kbps
11/18 19:54:17 Info: FTMSI-B 2 FileCache ti/46A613AC dwStatus:AllBlocksDownloaded files:1 accessTimeOut:True priorities: ('zoneplayer:3':34) --> bw limit:0kbps
11/18 19:54:17 Warn: [zone Office] Track Stopped Due to Error
11/18 19:54:17 Info: [zone Office] OnPlayFeedback StoppedEndOfMediaUnnatural
11/18 19:54:17 Debug: [zone Office] _Advance (Track)
11/18 19:54:17 Trace: [Office] [Enhanced, 16/44 MQA TIDAL FLAC => 24/44 MQA] [100% buf] [LOADING @ 0:00] Deliverance - Opeth
11/18 19:54:17 Trace: [dbperf] flush 0 bytes, 0 ops in 1 ms (cumulative 0 bytes, 0 ops in 4902 ms)
11/18 19:54:17 Trace: [dbperf] flush 0 bytes, 0 ops in 2 ms (cumulative 0 bytes, 0 ops in 4904 ms)
11/18 19:54:17 Debug: FTMSI-B ti/5AD7F6FB download status: FirstBlockRetrieved accessTimeout:True openFiles:0 prev:(FirstBlockRetrieved,False,0)
11/18 19:54:17 Debug: [easyhttp] [976] GET to https://api.tidal.com/v1/tracks/96962684/playbackinfopostpaywall?countryCode=DE&audioquality=HI_RES&assetpresentation=FULL&playbackmode=STREAM returned after 136 ms, status code: 200
11/18 19:54:17 Trace: [tidal/http] GET https://api.tidal.com/v1/tracks/96962684/playbackinfopostpaywall?countryCode=DE&audioquality=HI_RES&assetpresentation=FULL&playbackmode=STREAM => Success
11/18 19:54:17 Debug: [easyhttp] [977] GET to https://api.tidal.com/v1/tracks/96962684?countryCode=DE returned after 36 ms, status code: 200
11/18 19:54:17 Trace: [tidal/http] GET https://api.tidal.com/v1/tracks/96962684?countryCode=DE => Success
11/18 19:54:17 Info: [Office] [zoneplayer] Playing: http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInZTM1NjhkOTJhOTg3YjJmOGNmZGIzMWY1YzdkYzI1NjVfNjAubXA0/0.flac
11/18 19:54:17 Debug: FTMSI-B closed file for ti/46A613AC; open files:0
11/18 19:54:17 Debug: FTMSI-B Cache open file ti/5AD7F6FB domain: zoneplayer:3 ordinal:36
11/18 19:54:17 Debug: FTMSI-B ti/5AD7F6FB download status: FirstBlockRetrieved accessTimeout:True openFiles:1 prev:(FirstBlockRetrieved,True,0)
11/18 19:54:17 Info: FTMSI-B ti/5AD7F6FB: allocated bw changed from 0 to 51200 kbps
11/18 19:54:17 Info: FTMSI-B 1 FileCache ti/5AD7F6FB dwStatus:FirstBlockRetrieved files:1 accessTimeOut:True priorities: ('zoneplayer:3':36) --> bw limit:51200kbps
11/18 19:54:17 Info: FTMSI-B 2 FileCache ti/46A613AC dwStatus:AllBlocksDownloaded files:1 accessTimeOut:True priorities: ('zoneplayer:3':34) --> bw limit:0kbps
11/18 19:54:17 Info: FTMSI-B FileCache removed ti/46A613AC
11/18 19:54:17 Debug: FTMSI-B-OE ti/46A613AC exit thread signalled
11/18 19:54:17 Trace: FTMSI-B 1 FileCache ti/5AD7F6FB dwStatus:FirstBlockRetrieved files:1 accessTimeOut:True priorities: ('zoneplayer:3':36) --> bw limit:51200kbps
11/18 19:54:17 Debug: FTMSI-B-OE ti/46A613AC exit thread signalled
11/18 19:54:17 Info: [audio/env] [zoneplayer] All streams were disposed
11/18 19:54:17 Info: FTMSI-B FileCache disposed ti/46A613AC
11/18 19:54:17 Info: [Office] [zoneplayer]     Open Result (Playing):Result[Status=Success]
11/18 19:54:17 Info: [Office] [zoneplayer] Starting playback
11/18 19:54:17 Trace: [Office] [zoneplayer/raat] StartStream Sooloos.Broker.Transport.RaatZonePlayer+Endpoint: StreamFormat(channels=2, bitspersample=24, samplerate=44100, isdts=False, mqa=44100) => StreamFormat(channels=2, bitspersample=24, samplerate=44100, isdts=False, mqa=44100) streamid=1201454765
11/18 19:54:17 Info: [zone Office] OnPlayFeedback Playing
11/18 19:54:17 Trace: [Office] [Enhanced, 16/44 MQA TIDAL FLAC => 24/44 MQA] [100% buf] [PLAYING @ 0:00] Deliverance - Opeth
11/18 19:54:17 Trace: [prebuffer] ready 149940/441000 (34%) @ 0/853 sec
11/18 19:54:18 Info: 
--[ SignalPath ]---------------------------------------------
SignalPath Quality = Enhanced
Elements:
    Source Format=Flac 44100/16/2  Quality=Lossless MQA 44100
    MQA Subtype=authentication LightState=off OriginalSampleRate=44100 OutputSampleRate= OutputBitsPerSample=
    Raat Device=Dutch & Dutch 8c
    SampleRateConversion FromSampleRate=44100 ToSampleRate=48000 Algorithm=Other Quality=None
    DSP Subtype=dutch_dutch_room_eq PresetKey= TruePeak= Value= StringValue= Model= FromSampleRate= ToSampleRate= Quality=Enhanced PresetDisplayName= ModeDisplayName=10_2022
    DSP Subtype=dutch_dutch_tone_control PresetKey= TruePeak= Value= StringValue= Model= FromSampleRate= ToSampleRate= Quality=Enhanced PresetDisplayName= ModeDisplayName=
    Amplifier Method=dutch_dutch Quality=Lossless
    Output OutputType=Local_Speakers Quality=Lossless SubType= Model=
------------------------------------------------------------
11/18 19:54:18 Debug: FTMSI-B ti/5AD7F6FB download status: FirstBlockRetrieved accessTimeout:True openFiles:1 prev:(FirstBlockRetrieved,False,1)
11/18 19:54:18 Warn: [Office] [zoneplayer/raat] failed to sync sender clock to endpointDutch & Dutch 8c: Sooloos.Broker.Transport.ClockSyncResult
11/18 19:54:18 Warn: [Office] [zoneplayer/raat] failed to sync clocks with any endpoints..giving up
11/18 19:54:18 Info: [audio/env] [zoneplayer -> stream] All streams were disposed
11/18 19:54:18 Info: [audio/env] [zoneplayer -> stream -> endpoint] All streams were disposed
11/18 19:54:19 Info: sleep 500ms after flush
11/18 19:54:19 Warn: [zone Office] Track Stopped Due to Error
11/18 19:54:19 Info: [zone Office] OnPlayFeedback StoppedEndOfMediaUnnatural
11/18 19:54:19 Debug: [zone Office] _Advance (Track)
11/18 19:54:19 Info: [transport/autosleep] scheduling autosleep for Dutch & Dutch 8c (23:1:bc6d667e-56e9-8e1b-fa24-f10754e08898) [IsAvailable=True] in 300 seconds
11/18 19:54:19 Trace: [Office] [Enhanced, 16/44 MQA TIDAL FLAC => 24/44 MQA] [100% buf] [STOPPED @ 0:00] 
11/18 19:54:24 Trace: [zone Office] [zone] no playback for 5s, suspending to release audio device
11/18 19:54:24 Info: 
--[ SignalPath ]---------------------------------------------
SignalPath Quality = Inactive
Elements:
------------------------------------------------------------
11/18 19:54:24 Warn: inactive signal path :(
11/18 19:54:24 Trace: [zone Office] Suspend
11/18 19:54:24 Trace: [zone Office] Stop
11/18 19:54:24 Info: [zone Office] OnPlayFeedback Stopped
11/18 19:54:24 Info: [zone Office] Canceling Pending Sleep
11/18 19:54:24 Debug: FTMSI-B closed file for ti/5AD7F6FB; open files:0
11/18 19:54:24 Debug: FTMSI-B ti/5AD7F6FB download status: FirstBlockRetrieved accessTimeout:True openFiles:0 prev:(FirstBlockRetrieved,True,1)
11/18 19:54:24 Info: FTMSI-B ti/5AD7F6FB: allocated bw changed from 51200 to 0 kbps
11/18 19:54:24 Info: FTMSI-B 1 FileCache ti/5AD7F6FB dwStatus:FirstBlockRetrieved files:0 accessTimeOut:True priorities: ('zoneplayer:3':36) --> bw limit:0kbps
11/18 19:54:24 Info: [audio/env] [zoneplayer] All streams were disposed
11/18 19:54:30 Info: [stats] 5744mb Virtual, 497mb Physical, 337mb Managed, 2240 Handles, 117 Threads
11/18 19:54:45 Info: [stats] 5720mb Virtual, 497mb Physical, 337mb Managed, 2234 Handles, 111 Threads
11/18 19:55:00 Info: [stats] 5724mb Virtual, 497mb Physical, 335mb Managed, 2228 Handles, 112 Threads
11/18 19:55:15 Info: [stats] 5724mb Virtual, 497mb Physical, 340mb Managed, 2228 Handles, 112 Threads
11/18 19:55:30 Info: [stats] 5724mb Virtual, 496mb Physical, 340mb Managed, 2235 Handles, 112 Threads
11/18 19:55:45 Info: [stats] 5724mb Virtual, 496mb Physical, 339mb Managed, 2231 Handles, 112 Threads
11/18 19:56:00 Info: [stats] 5728mb Virtual, 496mb Physical, 338mb Managed, 2239 Handles, 113 Threads
11/18 19:56:15 Info: [stats] 5728mb Virtual, 496mb Physical, 337mb Managed, 2239 Handles, 113 Threads
11/18 19:56:30 Info: [stats] 5724mb Virtual, 496mb Physical, 336mb Managed, 2235 Handles, 112 Threads
11/18 19:56:45 Info: [stats] 5720mb Virtual, 496mb Physical, 341mb Managed, 2233 Handles, 111 Threads
11/18 19:57:00 Info: [stats] 5724mb Virtual, 496mb Physical, 340mb Managed, 2233 Handles, 112 Threads
11/18 19:57:15 Info: [stats] 5724mb Virtual, 496mb Physical, 338mb Managed, 2221 Handles, 112 Threads
11/18 19:57:30 Info: [stats] 5748mb Virtual, 498mb Physical, 339mb Managed, 2253 Handles, 118 Threads
8

Music stopped playing at 19:54:14, afterwards I can find this in the audio settings:
screen

9

Even after having a little more confidence in the log-files at the various locations I am still simply not able to draw conclusions from this on my own. The log in question is from the RoonServer_log.txt, I will double check if the other locations can give some more hints…

10

OK, all other logs of the involved Client/Server so not give any more hints on this.

I looked for the buffer/overrun exception here in the forum and it seems, at least after this short search and quick conclusion, that this simply is the server process complaining that the playing device is not doing what it is supposed to do (like an USB-device not present anymore …)

One could further assume that indeed the Roon-Ready-device is not receiving the stream anymore in orderly manner - now the question is: because some discovery-mechanism in the background “decided” that the device changed it’s IP (or whatever)?
Or is it more likely a simple hickup in the network and just afterwards the device goes missing?

Which part of the Roon-Server does the (Roon-Ready-)Device-Discovery in the network based on which mechanism?

So far,
Thanks for every input!

11

I’m not sure if this will help, but a quick search on google for ‘failed to sync sender clock to endpointDutch & Dutch 8c: Sooloos.Broker.Transport.ClockSyncResult’, lead me to the following:

In short, the problem was caused by running a VPN. Are you running one?

12

Yes, but there is none between the Speakers/Server and also from the post mentioned it is not clear what the VPN did in his case.
It still would help immensely to get a better understanding of how the discovery of the roon-ready device works. Of course some unusual subnetting/VPNs could confuse said mechanism?

What i already found in the past (and which helped right away just as the same error appeared while answering here!): opening the roon-client on my iphone seems to initialize the device-discovery successfully on the spot. As I did this before Roon was done skipping through the queue, it continued playing right away. Does this make sense?

13

Quite possibly, but I don’t know enough about how discovery works to offer any sensible comments. Hopefully @support will chime in with something more useful but, in the meanwhile, it might be worth disabling your VPN to see if it makes a difference.

15

Hi @Matthias_Finke,

Thank you for patiently awaiting an official response from Roon on the matter.

I agree with @DaveN on the idea of eliminating the VPN from the equation. We should absolutely try that step first.

Our network discovery is done via RAAT. If eliminating the VPN yields no results you can also try rebuilding RAAT with the steps below.

Please let me know how your tests go. Those speakers are absolutely amazing and I’d like you to be able to enjoy the music unimpaired.

Thanks,
Wes

You can generate a new RAATServer instance on your device by following these instructions, but please be aware that this will reset your Roon Settings → Audio Tab to factory settings and I would advise making a backup of any custom DSP settings you have:

  • Create a Backup of your current Roon database
  • Exit out of Roon
  • Navigate to your Roon’s Database Location
  • Find the folder that says “RAATServer”
  • Rename the “RAATServer” folder to “RAATServer_old”
  • Restart the Roon App to generate a new RAATServer folder
16

Thanks for your Input. I already moved the ROON-Server (and hence the RAAT-Part?) from one machine (server 2016) to another (win10) in order to see if this changes anything, which it did not. Then the RAAT-Part is moved along I guess? I can give this a try.

Mentioning VPN: of course there could be some correlation but I see no reasons to assume a correlation in this case. For the sake of it we could also assume I am not using VPN in this context. I am dealing with network issues from time to time im a professional context and simply assuming context on this level with the specific problem given does not yield enough probability.

If I want some esoteric assumptions to wonder about: I was thinking if it may makes a difference whether I start the playback via a ROON-Client on my iPhone or a Windows-Based Client. I have not enough data to drive this point home at this moment in time.

17

But I will take a closer look at the RAAT-Part of the server where the preferences of the audio devices an therefore also for the roon-ready-device in question should be found.
What comes to mind in this context: the preferences for max-volume and idle-standby I had to put in more than once (which made me wonder if there are some preferences which are saved at the roon-client side as well) but than again I don’t have enough data at this time to really make anything useful out of it.

18

What I did today: I wiresharked the start-up procedure of the roon-server and a roon-client in order to see which part of the software is even interacting if the IP-Address(es) of the roon-ready-speakers. It is the server-machine exclusively. There seems to be a discovery-protocol which uses Multicast packets to identify other instances of roon and/or roon-ready devices in the local network.
This also is reflected in the ROON-Server log, not in the RAAT-Log. So far so good, picture a little clearer and so far more or less what was to be expected to be found.
What I find interesting: Roon exclusively communicates with the IP-address of one of the speakers, the IP-address of the second speaker is nowhere to be found. This seems to be true for the playbackstream as well.
Then I found that the speakers have some debug-log as well.

19

so for me the initial hypothesis still stands, now with more details: the device is (of course) known to Roon, presumably there is some DB with all Infos and parameters of the device. It is not clear if the IP-address is also in that DB, it is more likely that the actual IP-address of the device is enumerated on startup (and then from time to time?). I a consumer-grade network surrounding ip addresses could change anytime, for example after a change of the router device and of course roon has to reflect on that. also it does not seem possible to give a fixed IP-address to a known roon-ready device or in the process of discovery.
I will go from here and am still happy if someone can add to this. I will also try to get in contact with the manufacturer of the speakers, I guess they also have some knowledge about what is happening when and why.

20

Last Input / thoughts for today:
@Wes
I walked me through your instructions and found that this will not make any difference in my case. The RAAT-Server files und %appdata%/local … only contain very little files at all and from what i can tell there is only Information found which are related to audio-devices connected to the host machine in question. As all local audio devices of the server machine are disabled it is basically empty.
So most likely all the infos connected to Roon-Ready devices seem to be in the roon-server-database itself. At least they are not in the RAAT-Folders.

What i Found: when i change the Volume-Limits of my roon-ready-device some files in RoonServer\Settings get are “touched”. The name of the file contains some identification like endpoint_17017e666dbce9561b8efa24f10754e08898_volume_hard_limit_max. There is one file for every volume limit. The Id seems to change/iterate with every edit of said volumes in the roon-preferences. Older files are deleted.

22

Hi @Matthias_Finke,

We have discussed your case with our hardware ecosystem expert and they seem to think there’s something that D&D might be able to correct.

Alternatively, only a rename of DB and RAAT folders on our side could have any bearing on the situation. We do have a Roon side DB of Roon Ready and Roon Tested devices but I can’t see there being a problem on our side given the multitude of 8c’s out there.

Please let me know how things go with D&D support.

Wes

1 Like
23

Thanks @Wes ,

i was afk for quite a long time, so no follow up.
I absolutely agree that the very issue can very well be also on the D&D side (even though I hoped it would be possible to get some more profound knowledge by looking at the roon-side first).
However: the D&D got a, at least from the looks, completely overhauled software lately. I installed it several days ago and didn’t experience “my” issue since. So maybe this has sorted itself out already, else I will get in contact with them dutch team.

Regards

1 Like
24

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