Tracks Slow to Load & Playback Randomly Stops on Synology 3615XS+ Roon Core

[noris]

Hi John,

Thanks for giving that a try. I’m going to reach out to our QA team and ask if they have seen any similar reports for your NAS model. If you make any new findings over the weekend do let me know. Maybe it’s worth to check if you have then newest Roon package on the NAS or reinstall the app?

– Noris

[c2c2c2 (John Calvert)]

Thanks @noris,

I do have the latest Roon Core installed. I may try for a complete de-install and re-install on the NAS. I presume the backup will get everything? Playlists, ratings, Meta, etc.?

[c2c2c2 (John Calvert)]

@noris,

I conducted some additional tests this weekend as follows:

1. I deinstalled Roon entirely from the NAS, then reinstalled and restored from backup. RESULT: no improvement.
2. I desintalled Roon entirely from the NAS, then reinstalled on a different volume – this time rather than on the SSD I installed on a HDD volume. I then restored from backup. RESULT: no improvement.

[noris]

Hi John,

Thanks for running those tests. Just to confirm something here, does this same behavior occur for both Local Library tracks or do TIDAL/Qobuz tracks show the same symptoms?

I would next like to take a closer look at the SFP+ connection, can you reproduce the same behavior when you are connected via a regular Ethernet cable and if so can you let me know some timestamps?

– Noris

[c2c2c2 (John Calvert)]

@noris,

Yes, the same behavior occurs with either local library tracks or TIDAL, I get the same symptoms. I do not use Qobuz.

As you may recall, I’ve already taken SFP+ out of the equation, here is my previous message on that.

I have confirmed that the problem is not resolved by replacing the SPF+ link from the NAS to the router with a standard ethernet (copper) connection. This would rule out the cable theory and also eliminate anything related to transiting on fiber.

[noris]

Hi @c2c2c2,

Yes I do recall that you took the SPF+ out of the equation before but I have not had a chance to review the diagnostics with just the Ethernet cable connected and the SPF+ out of the way. Can you try connecting it via Ethernet once more and let me know the timestamp if the behavior is the same so I can review and see if the diagnostics traces are identical?

– Noris

[c2c2c2 (John Calvert)]

@noris

As you’ve requested, I’ve disconnected the SPF+ connection from the NAS to the router and reconnected it using a standard copper Ethernet cable. As was the case the last time we did this, the problem and symptoms remain. Here are three specific time stamps where the problem was observed from the user’s point of view:

05/06 18:26
05/06 19:21 – 19:22
05/07 06:30 – 06:35

As you can see, the logs are full of problematic entries, not just at the above time stamps.

[noris]

Hi @c2c2c2,

Thanks for sharing those timestamps. Would it be possible for you to send me the Bluesound logs as well so that QA has the full information here for review?

– Noris

[c2c2c2 (John Calvert)]

@noris

I can & will, I can’t access them until this evening however so look for them later today. I will remind you that with the previous batch I sent the Bluesound logs so you already have a synced set. This one will be different only in that it’s an Ethernet connection from NAS to router versus SPF+.

Also, in my own review of the logs, one can see the lost connection, however, there is nothing in the logs that to my eye reveals the root problem. I hope I’m missing something.

I am of the belief that this is a problem with the Core itself or it’s interaction with the host O/S. Remember this all worked fine when I spun up a Windows 10 core and restored from back to that… Ergo, there is something bad with the Core on Synology…my guess anyway.

[noris]

Hi @c2c2c2,

I am of the belief that this is a problem with the Core itself or it’s interaction with the host O/S.

I believe this could be related as well, and as such I have asked QA to take a closer look at this case but they require all the info for review.

I will remind you that with the previous batch I sent the Bluesound logs so you already have a synced set.

Apologies, but I might be missing a message here, last time you mentioned that you would send these in a day or two but I didn’t see a follow up to this:

I can get you the BS log, I monitor that myself (it’s annoying that their time stamps aren’t in local time as you no doubt know). To be certain that you can align all the logs, let me get you a clean set of contemporaneous logs from Roon and Bluesound. It will take me a day or so as I’m not home now.

If you still have the sync’d logs and the new ones when you are running on regular Ethernet, please do send both sets.

– Noris

[c2c2c2 (John Calvert)]

@noris,

Okay, I will send soon.

I’m including the diagram below to help your team.

[c2c2c2 (John Calvert)]

@noris,

I am ready to send you the Bluesound Log. I’m sure you know that the time stamps are different because Bluesound doesn’t localize it’s clock. By my calculation, here are the equivalents:

LOCAL (Roon)			GMT/BST +8 (Bluesound)
05/06 18:26		        05/07	02:26
05/06 19:21 – 19:22	        05/07	03:21-03:22
05/07 06:30 – 06:35	        05/07	14:30-14:35

There appear to be no entries in the BS logs that overlap, let me know what you think. Please let me know how you’d like me to send you the BS log to you (It’s too large to post here), Dropbox?

Also, I found the following lines interesting from the BS logs:

[247215.158414] Out of memory: Kill process 12387 (raat_bluos) score 537 or sacrifice child
[247215.167122] Killed process 12387 (raat_bluos) total-vm:1285688kB, anon-rss:129600kB, file-rss:0kB, shmem-rss:0kB
[247217.080156] oom_reaper: reaped process 12387 (raat_bluos), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB

[noris]

Hi John,

Thanks for posting those equivalencies and for the network diagram, it is appreciated.
Yes, getting this info over as a shared Dropbox/Google Drive/Firefox Send link would be best.
I will also make note of the interesting BS log traces you saw in your case notes.

– Noris

[c2c2c2 (John Calvert)]

Link with Bluesound log sent.

[c2c2c2 (John Calvert)]

@noris,

Here is a different test, one I believe to be a different view of the same underlying problem. In this test, I set Roon to play ‘radio’ to my Headphones overnight. As you can see, the endpoint is an Auralic Mini and the connection is wired. When I wake up, the unit is not playing. A search through the logs and one can see where it loses connection. In this case, the unit is wired and the endpoint is from a different manufacturer. Additionally, as we’ve discussed, if the core is running on the Windows workstation this doesn’t happen. This is easy to repeat. If I set any endpoint to play, either from a playlist, a long queue, or the radio, the end point will at some point just stop.

05/08 02:59:43 Trace: [Music Room] [Enhanced 99.1x, 16/44 FLAC => 24/192] [100% buf] [PLAYING @ 2:20/4:03] The Color of a Cloudy Day - Allison Moorer / Shelby Lynne
05/08 02:59:43 Trace: [Headphones Auralic] [Enhanced, 16/44 FLAC => 32/44] [100% buf] [PLAYING @ 0:34/3:15] Twenty Years - Jones / Elvin Jones / Bill Frisell / Dave Holland
05/08 02:59:48 Trace: [Music Room] [Enhanced 98.9x, 16/44 FLAC => 24/192] [100% buf] [PLAYING @ 2:25/4:03] The Color of a Cloudy Day - Allison Moorer / Shelby Lynne
05/08 02:59:48 Trace: [Headphones Auralic] [Enhanced, 16/44 FLAC => 32/44] [100% buf] [PLAYING @ 0:40/3:15] Twenty Years - Jones / Elvin Jones / Bill Frisell / Dave Holland
05/08 02:59:53 Trace: [Music Room] [Enhanced 99.0x, 16/44 FLAC => 24/192] [100% buf] [PLAYING @ 2:30/4:03] The Color of a Cloudy Day - Allison Moorer / Shelby Lynne
05/08 02:59:53 Trace: [Headphones Auralic] [Enhanced, 16/44 FLAC => 32/44] [100% buf] [PLAYING @ 0:45/3:15] Twenty Years - Jones / Elvin Jones / Bill Frisell / Dave Holland
05/08 02:59:55 Trace: [Music Room] [zoneplayer/raat] sync Bluesound NODE 2: realtime=153018934269 rtt=0us offset=-34236356065us delta=-469us drift=-6473us in 152.3825s (-42.480ppm, -152.927ms/hr)
05/08 02:59:57 Info: [stats] 6114mb Virtual, 2416mb Physical, 1734mb Managed, 0 Handles, 95 Threads
05/08 02:59:58 Trace: [Music Room] [Enhanced 99.3x, 16/44 FLAC => 24/192] [100% buf] [PLAYING @ 2:35/4:03] The Color of a Cloudy Day - Allison Moorer / Shelby Lynne
05/08 02:59:58 Trace: [Headphones Auralic] [Enhanced, 16/44 FLAC => 32/44] [100% buf] [PLAYING @ 0:50/3:15] Twenty Years - Jones / Elvin Jones / Bill Frisell / Dave Holland
05/08 03:00:02 Trace: [raat] [AURALiC ARIES_MINI @ 10.0.0.44:36657] => Disconnected
05/08 03:00:02 Trace: [raat] [AURALiC ARIES_MINI @ 10.0.0.44:36657] lost client connection. Retrying
05/08 03:00:02 Trace: [raat] [AURALiC ARIES_MINI @ 10.0.0.44:36657] connecting (attempt 1)
05/08 03:00:02 Trace: [push] restarting connection (Unable to read data from the transport connection: interrupted.)
05/08 03:00:02 Trace: [push] retrying connection in 64839ms
05/08 03:00:02 Info: [transport] destroyed zone Headphones Auralic was playing? True
05/08 03:00:02 Trace: [zone Headphones Auralic] Suspend
05/08 03:00:02 Warn: [raat_ll/client] [AURALiC ARIES_MINI @ 10.0.0.44:36657] failed to connect Connection refused
05/08 03:00:02 Info: [zone Headphones Auralic] OnPlayFeedback Stopped
05/08 03:00:02 Debug: [raat/tcpaudiosource] disconnecting
05/08 03:00:02 Info: [library] recorded play for profile 6ba7518c-b0df-4230-a9db-1a84933aeef7: mediaid=50:1:e0fe6e8f-2c13-4e9f-ac80-9adf1a5e9679 metadataid=123:0:MT0007223717 contentid= libraryid=50:1:e0fe6e8f-2c13-4e9f-ac80-9adf1a5e9679 isfromswim=True
05/08 03:00:02 Info: [audio/env] [zoneplayer] All streams were disposed
05/08 03:00:02 Info: [audio/env] [zoneplayer -> stream] All streams were disposed
05/08 03:00:02 Info: [audio/env] [zoneplayer -> stream -> endpoint] All streams were disposed
05/08 03:00:02 Debug: [easyhttp] POST to https://swim.roonlabs.net/1/session/2108cd780eb040799ac382d1a23970a3/return
05/08 03:00:02 Debug: [easyhttp] POST to https://swim.roonlabs.net/1/session/2108cd780eb040799ac382d1a23970a3/end
05/08 03:00:02 Trace: [Headphones Auralic] [zoneplayer/raat] Endpoint AURALiC ARIES_MINI State Changed: Playing => Prepared
05/08 03:00:02 Trace: [raat] [AURALiC ARIES_MINI @ 10.0.0.44:36657] => Connecting
05/08 03:00:02 Trace: [raat] [AURALiC ARIES_MINI @ 10.0.0.44:36657] => ConnectionFailed
05/08 03:00:02 Trace: [raat] [AURALiC ARIES_MINI @ 10.0.0.44:36657] client connection failed. Retrying in 500ms
05/08 03:00:02 Trace: [library] finished with 134 dirty tracks 10 dirty albums 55 dirty performers 108 dirty works 112 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 285 changed objects
05/08 03:00:02 Debug: [easyhttp] POST to https://swim.roonlabs.net/1/session/2108cd780eb040799ac382d1a23970a3/end returned after 146 ms, status code: 200
05/08 03:00:02 Debug: [easyhttp] POST to https://swim.roonlabs.net/1/session/2108cd780eb040799ac382d1a23970a3/return returned after 161 ms, status code: 200
05/08 03:00:03 Trace: [Music Room] [Enhanced 99.0x, 16/44 FLAC => 24/192] [100% buf] [PLAYING @ 2:40/4:03] The Color of a Cloudy Day - Allison Moorer / Shelby Lynne
05/08 03:00:03 Trace: [raat] [AURALiC ARIES_MINI @ 10.0.0.44:36657] connecting (attempt 2)
05/08 03:00:03 Trace: [raat] [AURALiC ARIES_MINI @ 10.0.0.44:36657] => Connecting
05/08 03:00:03 Warn: [raat_ll/client] [AURALiC ARIES_MINI @ 10.0.0.44:36657] failed to connect Connection refused
05/08 03:00:03 Trace: [raat] [AURALiC ARIES_MINI @ 10.0.0.44:36657] => ConnectionFailed
05/08 03:00:03 Trace: [raat] [AURALiC ARIES_MINI @ 10.0.0.44:36657] client connection failed. Retrying in 750ms
05/08 03:00:03 Info: sleep 553ms after flush
05/08 03:00:03 Trace: [Headphones Auralic] [Enhanced, 16/44 FLAC => 32/44] [100% buf] [PLAYING @ 0:54/3:15] Twenty Years - Jones / Elvin Jones / Bill Frisell / Dave Holland
05/08 03:00:03 Trace: [dbperf] flush 0 bytes, 0 ops in 5 ms (cumulative 448116181 bytes, 416488 ops in 202868 ms)
05/08 03:00:03 Trace: [library] endmutation in 584ms
05/08 03:00:03 Trace: [raat] [AURALiC ARIES_MINI @ 10.0.0.44:36657] connecting (attempt 3)
05/08 03:00:03 Trace: [raat] [AURALiC ARIES_MINI @ 10.0.0.44:36657] => Connecting
05/08 03:00:03 Warn: [raat_ll/client] [AURALiC ARIES_MINI @ 10.0.0.44:36657] failed to connect Connection refused
05/08 03:00:03 Trace: [raat] [AURALiC ARIES_MINI @ 10.0.0.44:36657] => ConnectionFailed
05/08 03:00:03 Trace: [raat] [AURALiC ARIES_MINI @ 10.0.0.44:36657] client connection failed. Retrying in 1125ms
05/08 03:00:05 Trace: [raat] [AURALiC ARIES_MINI @ 10.0.0.44:36657] connecting (attempt 4)
05/08 03:00:05 Trace: [raat] [AURALiC ARIES_MINI @ 10.0.0.44:36657] => Connecting
05/08 03:00:05 Warn: [raat_ll/client] [AURALiC ARIES_MINI @ 10.0.0.44:36657] failed to connect Connection refused
05/08 03:00:05 Trace: [raat] [AURALiC ARIES_MINI @ 10.0.0.44:36657] => ConnectionFailed
05/08 03:00:05 Trace: [raat] [AURALiC ARIES_MINI @ 10.0.0.44:36657] client connection failed. Retrying in 1687ms
05/08 03:00:06 Trace: [raat] [AURALiC ARIES_MINI @ 10.0.0.44:36657] connecting (attempt 5)
05/08 03:00:06 Trace: [raat] [AURALiC ARIES_MINI @ 10.0.0.44:36657] => Connecting
05/08 03:00:06 Warn: [raat_ll/client] [AURALiC ARIES_MINI @ 10.0.0.44:36657] failed to connect Connection refused
05/08 03:00:06 Trace: [raat] [AURALiC ARIES_MINI @ 10.0.0.44:36657] => ConnectionFailed
05/08 03:00:06 Trace: [raat] [AURALiC ARIES_MINI @ 10.0.0.44:36657] client connection failed. Giving up
05/08 03:00:08 Trace: [Music Room] [Enhanced 98.8x, 16/44 FLAC => 24/192] [100% buf] [PLAYING @ 2:45/4:03] The Color of a Cloudy Day - Allison Moorer / Shelby Lynne
05/08 03:00:12 Info: [stats] 5853mb Virtual, 2175mb Physical, 1330mb Managed, 0 Handles, 92 Threads
05/08 03:00:12 Trace: Successful POST response from https://push.roonlabs.com/push/1/connect
05/08 03:00:12 Trace: [push] connecting to 34.73.64.181:9200
05/08 03:00:12 Trace: [push] connected

[noris]

Hi John (@c2c2c2),

I spoke spoke to the QA team regarding your case and they would like to see if this issue could be performance relate and to verify if the same behavior occurs on a smaller library and with no DSP re-sampling in the mix. Can I please ask you to try the following?

• Create a Roon backup of your NAS database and have it saved somewhere safe
• Start with a fresh database of Roon on your NAS
• Have only TIDAL/Qobuz connected and have a library smaller of 50k tracks
• Do not enable any DSP re-sampling
• Check to see if the unstable behavior is the same

– Noris

[c2c2c2 (John Calvert)]

@noris,

Okay @noris, I’ll run this test. I’ve run careful monitoring of resources on the NAS with Roon running. Even with all zones running and lots of DSP in place (not normal, I did this just to stress test), the resource use on the NAS is minimal - this model is designed for business-class use and has far more capacity than most would have at home. I will not be able to do this until tonight. I’ll let you know.

Best.

[c2c2c2 (John Calvert)]

@noris,

I’ve performed the test as you’ve described. A new Roon install, with a library of <50K tracks all from Tidal, nothing from local library and no DSP for any reason. The behavior has not changed, the problem persists.

[noris]

Hi John (@c2c2c2),

Thank you for running that test. I will update your case notes with this information and also reach out to our hardware team to see if they are able to reproduce similar behavior on their end. I will be sure to update you once I have additional suggestions to share.

– Noris

[c2c2c2 (John Calvert)]

Okay @noris, thank you.