Pulled the handshake from the log: “Unable to read data from the transport connection” says it all.
11/20 22:08:47 Info: [brokerserver] Client connected: 192.168.1.55:10106
11/20 22:08:47 Trace: [raat] [sood] Refreshing device list
11/20 22:08:47 Trace: [raatserver] [sood] Refreshing device list
11/20 22:08:47 Info: [stats] 23314mb Virtual, 931mb Physical, 451mb Managed, 307 Handles, 80 Threads
11/20 22:08:47 Trace: SENT NONFINAL DistributedBroker.ConnectResponse={ BrokerId=9473c75d-e16a-4260-b6de-19edb92f7366 BrokerName=‘Vault’ }
11/20 22:08:47 Trace: SENT NONFINAL DistributedBroker.UpdatesChangedResponse={ IsSupported=True WasJustUpdated=False Status=‘UpToDate’ HasChangeLog=False CurrentVersion={ MachineValue=100800850 DisplayValue=‘1.8 (build 850) stable’ Branch=‘stable’ } }
11/20 22:08:47 Trace: [push] restarting connection (Unable to read data from the transport connection: Software caused connection abort.)
11/20 22:08:47 Trace: [push] retrying connection in 44445ms
11/20 22:08:48 Debug: [easyhttp] [5132] POST to https://discovery.roonlabs.net/1/query returned after 1074 ms, status code: 200
11/20 22:08:57 Trace: Successful POST response from https://push.roonlabs.com/push/1/connect
11/20 22:08:57 Trace: [push] connecting to 35.237.106.222:9204
11/20 22:08:58 Trace: [push] connected
11/20 22:09:02 Info: [stats] 23339mb Virtual, 931mb Physical, 452mb Managed, 305 Handles, 85 Threads
11/20 22:09:11 Info: [brokerserver] Client disconnected: 192.168.1.55:10106
Again, this works fine on other machines. The Core and this machine (referred to above) are connected on the same Ubiquiti switch at 1GB
Local log shows repeated cycles of the following:
11/21 16:19:26 Info: [raatserver] [runner] Start or Connect…
11/21 16:19:26 Info: [raatserver] [runner] Start or Connect… C:\Users\Study\AppData\Local\Roon\Application\RAATServer.exe
11/21 16:19:26 Info: ConnectOrStartAndWaitForExit RAATServer, path: C:\Users\Study\AppData\Local\Roon\Application\RAATServer.exe
11/21 16:19:26 Critical: scx: in OnExit: System.NullReferenceException: Object reference not set to an instance of an object.
at Sooloos.Broker.Music.Library.EndMutation()
at Sooloos.Broker.Music.Module.ev_exit()
at Sooloos.SynchronizationContextThread.OnExit()
11/21 16:19:27 Info: [stats] 5670mb Virtual, 201mb Physical, 30mb Managed, 1826 Handles, 154 Threads
11/21 16:19:27 Critical: scx: in OnExit: System.NullReferenceException: Object reference not set to an instance of an object.
at Sooloos.Broker.Music.Library.EndMutation()
at Sooloos.Broker.Music.Module.ev_exit()
at Sooloos.SynchronizationContextThread.OnExit()
11/21 16:19:28 Info: [raatserver] [runner] Status: Started
11/21 16:19:32 Debug: [easyhttp] [77] POST to https://discovery.roonlabs.net/1/query returned after 436 ms, status code: 200
11/21 16:19:33 Critical: scx: in OnExit: System.NullReferenceException: Object reference not set to an instance of an object.
at Sooloos.Broker.Music.Library.EndMutation()
at Sooloos.Broker.Music.Module.ev_exit()
at Sooloos.SynchronizationContextThread.OnExit()
11/21 16:19:34 Critical: scx: in OnExit: System.NullReferenceException: Object reference not set to an instance of an object.
at Sooloos.Broker.Music.Library.EndMutation()
at Sooloos.Broker.Music.Module.ev_exit()
at Sooloos.SynchronizationContextThread.OnExit()
11/21 16:19:34 Debug: [easyhttp] [79] POST to https://discovery.roonlabs.net/1/query returned after 440 ms, status code: 200
11/21 16:19:34 Debug: [easyhttp] [78] POST to https://discovery.roonlabs.net/1/query returned after 474 ms, status code: 200
11/21 16:19:36 Warn: exception starting raatserver: System.Net.Sockets.SocketException (0x80004005): No connection could be made because the target machine actively refused it 127.0.0.1:9004
at System.Net.Sockets.TcpClient…ctor(String hostname, Int32 port)
at Sooloos.RAATServer.ConnectOrStartAndWaitForExit(String path, String args, Action`1 status, ChildProcess& p)
ProcMonitor shows roon.exe doing lots of registry R/W and UDP pings on port 9003…
The raatserver log give me:
11/21 16:27:57 Info: Starting RAATServer v1.8 (build 831) stable on windows
11/21 16:27:58 Warn: [easyhttp] [1] Post https://bits.roonlabs.net/1/q/roon.base.,roon.internet_discovery. web exception without response: The request was aborted: Could not create SSL/TLS secure channel.
11/21 16:27:58 Warn: [bits] http request failed updating bits, status code: 999, message: <>
11/21 16:27:58 Info: [RAATServer] creating RAAT__manager
11/21 16:27:58 Info: [RAATServer] appdata_dir = C:\Users\Study\AppData\Local\RAATServer
11/21 16:27:58 Info: [RAATServer] unique_id = 39e04f80-d505-4915-8fb4-ebc926d612dc
11/21 16:27:58 Info: [RAATServer] machine_id = 1f679399-5d2b-1d58-cb47-874ec6b62e1c
11/21 16:27:58 Info: [RAATServer] machine_name = MORDOR
11/21 16:27:58 Info: [RAATServer] os_version = Windows 10
11/21 16:27:58 Info: [RAATServer] vendor =
11/21 16:27:58 Info: [RAATServer] model =
11/21 16:27:58 Info: [RAATServer] service_id = d7634b85-8190-470f-aa51-6cb5538dc1b9
11/21 16:27:58 Info: [RAATServer] is_dev = False
11/21 16:27:58 Trace: [raatmanager] starting
11/21 16:27:58 Trace: [raatmanager/windows] FOUND type=wasapi id={0.0.0.00000000}.{18c5c16f-9a71-4d42-86a9-9cc5cdc1c7f4} usb_id=
11/21 16:27:58 Trace: [raatmanager/windows] name=XSplit Stream Audio Renderer output_name=Speakers
11/21 16:27:58 Trace: [raatmanager/windows] FOUND type=wasapi id={0.0.0.00000000}.{33d56cb9-e9c8-44ea-a1f4-0765b0b9a313} usb_id=
11/21 16:27:58 Trace: [raatmanager/windows] name=VB-Audio VoiceMeeter VAIO output_name=VoiceMeeter Input
11/21 16:27:58 Trace: [raatmanager/windows] FOUND type=wasapi id={0.0.0.00000000}.{a6ac4e8c-0fb1-4e07-bcc4-15ae6d5b69e5} usb_id=20b1:307c
11/21 16:27:58 Trace: [raatmanager/windows] name=Questyle Hi-end USB Audio output_name=Speakers
11/21 16:27:58 Trace: [raatmanager/windows] FOUND type=asio id={DCB31301-550E-4338-982F-583080CE9CFD} usb_id=
11/21 16:27:58 Trace: [raatmanager/windows] name=Questyle ASIO Driver output_name=
11/21 16:27:58 Trace: [raatmanager/windows] FOUND type=asio id={A80362FF-CE76-4DD9-874A-704C57BF0D6A} usb_id=
11/21 16:27:58 Trace: [raatmanager/windows] name=Realtek ASIO output_name=
11/21 16:27:58 Trace: [raatmanager/windows] FOUND type=asio id={9175CF07-885D-46B4-9EA1-4126D6648DE6} usb_id=
11/21 16:27:58 Trace: [raatmanager/windows] name=Voicemeeter Virtual ASIO output_name=
11/21 16:27:58 Trace: [raatmanager] initialized
11/21 16:27:58 Info: [RAATServer] running RAAT__manager
11/21 16:27:58 Trace: [raatmanager] starting discovery
11/21 16:27:58 Trace: [discovery] starting
11/21 16:27:58 Info: [discovery] [iface:10G:192.168.1.55] multicast recv socket is bound to 0.0.0.0:9003
11/21 16:27:58 Info: [discovery] [iface:10G:192.168.1.55] multicast send socket is bound to 0.0.0.0:54508
11/21 16:27:58 Info: [discovery] [iface:Intel 1G:192.168.1.52] multicast recv socket is bound to 0.0.0.0:9003
11/21 16:27:58 Info: [discovery] [iface:Intel 1G:192.168.1.52] multicast send socket is bound to 0.0.0.0:54509
11/21 16:27:58 Info: [discovery] [iface:Loopback Pseudo-Interface 1:127.0.0.1] multicast recv socket is bound to 0.0.0.0:9003
11/21 16:27:58 Info: [discovery] [iface:Loopback Pseudo-Interface 1:127.0.0.1] multicast send socket is bound to 0.0.0.0:54510
11/21 16:27:58 Info: [discovery] [iface:vEthernet (10G):192.168.96.1] multicast recv socket is bound to 0.0.0.0:9003
11/21 16:27:58 Info: [discovery] [iface:vEthernet (10G):192.168.96.1] multicast send socket is bound to 0.0.0.0:54511
11/21 16:27:58 Info: [discovery] [iface:vEthernet (Intel 1G):172.17.176.1] multicast recv socket is bound to 0.0.0.0:9003
11/21 16:27:58 Info: [discovery] [iface:vEthernet (Intel 1G):172.17.176.1] multicast send socket is bound to 0.0.0.0:54512
11/21 16:27:58 Info: [discovery] [iface:vEthernet (Ethernet 3):172.31.96.1] multicast recv socket is bound to 0.0.0.0:9003
11/21 16:27:58 Info: [discovery] [iface:vEthernet (Ethernet 3):172.31.96.1] multicast send socket is bound to 0.0.0.0:54513
11/21 16:27:58 Info: [discovery] [iface:vEthernet (WiFi 2):172.30.16.1] multicast recv socket is bound to 0.0.0.0:9003
11/21 16:27:58 Info: [discovery] [iface:vEthernet (WiFi 2):172.30.16.1] multicast send socket is bound to 0.0.0.0:54514
11/21 16:27:58 Info: [discovery] [iface:vEthernet (WiFi):192.168.16.1] multicast recv socket is bound to 0.0.0.0:9003
11/21 16:27:58 Info: [discovery] [iface:vEthernet (WiFi):192.168.16.1] multicast send socket is bound to 0.0.0.0:54515
11/21 16:27:58 Info: [discovery] unicast socket is bound to 0.0.0.0:9003
11/21 16:27:58 Trace: [raatmanager] starting server
11/21 16:27:58 Error: [jsonserver] uv_tcp_bind or uv_listen failed: permission denied
11/21 16:27:58 Error: [raatmanager] while starting json server: RNET__JSON_SERVER_STATUS_NETWORK_ERROR
So… lots of things failing and hard for me to know which is the root. But the lack of a raatserver would have to be fatal…
I pulled together synchronised RAATserver log and procmon logs with the raatserver log highlighted.
Nothing there seems to explain why the JSON server is throwing an error other than the RAATServerApp.PDB file not being created…
IF someone with some expertise can advice what to look at next I would appreciate it…
regards
Rod