Roon Stopping (and sometimes restarting)

DJD · November 15, 2021, 2:49pm

@noris @agillis Noris, Can you be more specific on what you see in the logs on the two Nov. 5th dropouts that makes you think it is the oR or the DAC? A better description may help Andrew (oR) in helping me with the problem. I have seen the thread on the Denefrips DAC you reference - I have used multiple USB cables and still had the drop outs, so I don’t believe the cable is the issue. Once again, it would be helpful for you to describe exactly what happened when it stopped each time on the 5th (ran out of buffer? lost the internet? couldn’t find the DAC? the DAC or oR stopped? etc). I have spent a lot of time looking at the ROON logs and just don’t have the knowledge to interpret what I am reading.

As to replicating the stops - as I said in the beginning its random - if I could reproduce it I would be on my way to solving the issue…

DJD · November 19, 2021, 2:01pm

@noris @agillis Noris, Further input on what went wrong on the two Nov 5th stops would be appreciated.

noris · November 19, 2021, 10:25pm

Hi @DJD ,

This is what the Roon log looked like for that timestamp:

11/05 06:45:40 Trace: [opticalRendu] [HighQuality, 16/44 QOBUZ FLAC => 16/44] [100% buf] [PLAYING @ 1:57/3:46] Dublin Farewell - Anthony da Costa
11/05 06:45:45 Trace: [opticalRendu] [HighQuality, 16/44 QOBUZ FLAC => 16/44] [100% buf] [PLAYING @ 2:02/3:46] Dublin Farewell - Anthony da Costa
11/05 06:45:50 Trace: [opticalRendu] [HighQuality, 16/44 QOBUZ FLAC => 16/44] [100% buf] [PLAYING @ 2:07/3:46] Dublin Farewell - Anthony da Costa
11/05 06:45:52 Info: [stats] 35729mb Virtual, 898mb Physical, 206mb Managed, 287 Handles, 111 Threads
11/05 06:45:54 Trace: [Sonore opticalRendu @ 192.168.1.11:34173] [raatclient] GOT [121] {"status":"Dropout","samples":1419}
11/05 06:45:55 Trace: [Sonore opticalRendu @ 192.168.1.11:34173] [raatclient] GOT [121] {"status":"Dropout","samples":22060}
11/05 06:45:55 Trace: [opticalRendu] [HighQuality, 16/44 QOBUZ FLAC => 16/44] [100% buf] [PLAYING @ 2:12/3:46] Dublin Farewell - Anthony da Costa
11/05 06:45:55 Trace: [Sonore opticalRendu @ 192.168.1.11:34173] [raatclient] GOT [121] {"status":"Dropout","samples":22060}
11/05 06:45:56 Trace: [Sonore opticalRendu @ 192.168.1.11:34173] [raatclient] GOT [121] {"status":"Dropout","samples":12133}
11/05 06:45:59 Trace: [opticalRendu] [zoneplayer/raat] sync Sonore opticalRendu: realtime=17792415427182 rtt=500us offset=-29699995572us delta=1540us drift=-28699us in 3620.156s (-7.928ppm, -28.540ms/hr)
11/05 06:46:00 Trace: [opticalRendu] [HighQuality, 16/44 QOBUZ FLAC => 16/44] [100% buf] [PLAYING @ 2:17/3:46] Dublin Farewell - Anthony da Costa
11/05 06:46:05 Trace: [opticalRendu] [HighQuality, 16/44 QOBUZ FLAC => 16/44] [100% buf] [PLAYING @ 2:22/3:46] Dublin Farewell - Anthony da Costa
11/05 06:46:07 Info: [stats] 35834mb Virtual, 903mb Physical, 245mb Managed, 287 Handles, 124 Threads
11/05 06:46:10 Trace: [opticalRendu] [HighQuality, 16/44 QOBUZ FLAC => 16/44] [100% buf] [PLAYING @ 2:27/3:46] Dublin Farewell - Anthony da Costa
11/05 06:46:14 Trace: [raat] RAATServer discovered: RaatServer iPhone @ 192.168.1.243:9200
11/05 06:46:14 Info: [raatserver] GOT SERVER 55bbfea7-4a28-4f7d-b429-944efced0dae::e9869362-e31c-483f-b2ec-df0a80830c38 @ 192.168.1.243:9200 iPhone PROTOVER=1 RAATVER=1.1.38 
11/05 06:46:14 Trace: [raatserver] [RaatServer iPhone @ 192.168.1.243:9200] connecting (attempt 1)
11/05 06:46:14 Trace: [push] restarting connection (Unable to read data from the transport connection: Software caused connection abort.)
11/05 06:46:14 Trace: [push] retrying connection in 86456ms

Roon was playing as expected with a full buffer, then there were dropouts on the OpticalRendu (unclear as to why, but the OpticalRendu logs might have more info).

Later we see a similar pattern:

11/05 06:50:56 Trace: [opticalRendu] [HighQuality, 16/44 QOBUZ FLAC => 16/44] [100% buf] [PLAYING @ 3:27/5:24] The Tailor - Terre Roche
11/05 06:51:01 Trace: [opticalRendu] [HighQuality, 16/44 QOBUZ FLAC => 16/44] [100% buf] [PLAYING @ 3:32/5:24] The Tailor - Terre Roche
11/05 06:51:04 Trace: Successful POST response from https://push.roonlabs.com/push/1/connect
11/05 06:51:04 Trace: [push] connecting to 35.196.114.77:9204
11/05 06:51:05 Trace: [push] connected
11/05 06:51:05 Trace: [opticalRendu] [zoneplayer/raat] sync Sonore opticalRendu: realtime=18098133671251 rtt=0us offset=-29699999328us delta=183us drift=-32455us in 3925.878s (-8.267ppm, -29.762ms/hr)
11/05 06:51:06 Trace: [Sonore opticalRendu @ 192.168.1.11:34173] [raatclient] GOT [121] {"status":"Dropout","samples":6563}
11/05 06:51:06 Trace: [opticalRendu] [HighQuality, 16/44 QOBUZ FLAC => 16/44] [100% buf] [PLAYING @ 3:37/5:24] The Tailor - Terre Roche
11/05 06:51:06 Trace: [Sonore opticalRendu @ 192.168.1.11:34173] [raatclient] GOT [121] {"status":"Dropout","samples":22060}
11/05 06:51:07 Trace: [Sonore opticalRendu @ 192.168.1.11:34173] [raatclient] GOT [121] {"status":"Dropout","samples":22060}
11/05 06:51:07 Trace: [Sonore opticalRendu @ 192.168.1.11:34173] [raatclient] GOT [121] {"status":"Dropout","samples":7721}
11/05 06:51:08 Info: [stats] 35754mb Virtual, 973mb Physical, 342mb Managed, 286 Handles, 113 Threads
11/05 06:51:11 Trace: [opticalRendu] [HighQuality, 16/44 QOBUZ FLAC => 16/44] [100% buf] [PLAYING @ 3:42/5:24] The Tailor - Terre Roche
11/05 06:51:16 Trace: [opticalRendu] [HighQuality, 16/44 QOBUZ FLAC => 16/44] [100% buf] [PLAYING @ 3:47/5:24] The Tailor - Terre Roche
11/05 06:51:21 Trace: [opticalRendu] [HighQuality, 16/44 QOBUZ FLAC => 16/44] [100% buf] [PLAYING @ 3:52/5:24] The Tailor - Terre Roche
11/05 06:51:23 Info: [stats] 35914mb Virtual, 906mb Physical, 230mb Managed, 286 Handles, 133 Threads
11/05 06:51:26 Trace: [opticalRendu] [HighQuality, 16/44 QOBUZ FLAC => 16/44] [100% buf] [PLAYING @ 3:57/5:24] The Tailor - Terre Roche
11/05 06:51:31 Trace: [opticalRendu] [HighQuality, 16/44 QOBUZ FLAC => 16/44] [100% buf] [PLAYING @ 4:02/5:24] The Tailor - Terre Roche
11/05 06:51:32 Info: [brokerserver] Client connected: 192.168.1.243:49194
11/05 06:51:32 Trace: [raat] [sood] Refreshing device list
11/05 06:51:32 Trace: [raatserver] [sood] Refreshing device list
11/05 06:51:32 Trace: [raat] RAATServer discovered: RaatServer iPhone @ 192.168.1.243:9200
11/05 06:51:32 Info: [raatserver] GOT SERVER 55bbfea7-4a28-4f7d-b429-944efced0dae::e9869362-e31c-483f-b2ec-df0a80830c38 @ 192.168.1.243:9200 iPhone PROTOVER=1 RAATVER=1.1.38 
11/05 06:51:32 Trace: [push] restarting connection (Unable to read data from the transport connection: Software caused connection abort.)
11/05 06:51:32 Trace: [raatserver] [RaatServer iPhone @ 192.168.1.243:9200] connecting (attempt 1)
11/05 06:51:32 Trace: [push] retrying connection in 58903ms
11/05 06:51:32 Trace: [raatserver] [RaatServer iPhone @ 192.168.1.243:9200] connected

What is interesting about the dropouts is that your iPhone and the connection from the Core to our servers also occurred around the same time, potentially suggesting that the network had a hiccup and couldn’t route network connections properly.