Increasing Lag Time with Roon Remotes, Connection Dropouts

Nicholas_Harsin · February 10, 2024, 7:10pm

Roon Server Machine

Roon Nucleus, ver 2.0 (build 1365)

Networking Gear & Setup Details

Ethernet connection from Nucleus to Netgear 16 port gigabit switch. Switch connects to TP-link wifi 6E router, to which several remotes are connected (MacBook Pros, iPads, iPhones).

Connected Audio Devices

KEF LS50 Wireless II + Elac Z3 (both connected via ethernet to switch)

Number of Tracks in Library

3800 local tracks. Nearly all listening is done via streaming Tidal and Qobuz.

Description of Issue:

Perpetually slow Nucleus performance. When opening a remote on a Mac, there is a lag / load time of 5-7 seconds per window. When using an iPhone, lag times while navigating the Roon Remote (latest software) is 10-12 seconds. When navigating via iPad, it’s up to 30 seconds. This is all despite multiple power cycles, reboots, etc.

Partial log from Nucleus Server:

02/10 18:34:58 Info: Starting RoonServer v2.0 (build 1365) production on linuxx64
02/10 18:34:58 Info: Local time is 02/10/2024 18:34:58, UTC time is 02/10/2024 18:34:58
02/10 18:34:58 Trace: [roondns] loaded 13 last-known-good entries
02/10 18:34:58 Debug: Init DefaultBackingApi: HttpWebRequest
02/10 18:34:58 Debug: [easyhttp] default backing API HttpClient -> HttpWebRequest. This may cancel all in progress http requests
02/10 18:34:58 Trace: Checking if we are already running
02/10 18:34:58 Info: get lock file path: /tmp/.rnsems0-
02/10 18:34:58 Info: GetLockFile, fd: 61
02/10 18:34:58 Info: GetLockFile, res: 0
02/10 18:34:58 Trace: Nope, we are the only one running
02/10 18:34:58 Info: Is 64 bit? True
02/10 18:34:58 Info: Command Line Argument: -watchdogport=45917
02/10 18:34:58 Trace: [realtime] fetching time from NTP server
02/10 18:34:58 Warn: [orbit] init failed due to Invalid Type: 10, reiniting
02/10 18:34:58 Trace: [ipaddresses] enumerating addresses
02/10 18:34:58 Trace: [ipaddresses]    FOUND   lo 127.0.0.1
02/10 18:34:58 Trace: [ipaddresses]    FOUND   eth0 192.168.1.121
02/10 18:34:58 Trace: [ipaddresses]    SKIPPED docker0: not up
02/10 18:34:58 Info: [broker] starting 9e220375-320b-4597-8b3f-1f7bf58b7a1b
02/10 18:34:58 Trace: [realtime] Got time from NTP: 02/10/2024 18:34:58 UTC (3916578898663ms)
02/10 18:34:58 Trace: [realtime] Updated clock skew to -00:00:00.0334891 (-33.4891ms)
02/10 18:34:58 Trace: [httpcache] loaded 9456 cache entries from /roon/data/RoonServer/Cache/httpcache_2.db, current: 127mb / 128mb
02/10 18:34:58 Info: [broker/locations] adding storage location: Internet:Name=Internet Media:Id=e268f098-04c4-4e65-af3f-38ba3c3fcecb
02/10 18:34:58 Info: [broker/locations] media availability: Internet:Name=Internet Media:Id=e268f098-04c4-4e65-af3f-38ba3c3fcecb is online
02/10 18:34:58 Info: [broker/locations] adding storage location: MetadataService:Name=Metadata Service:Id=13769258-b70b-4243-b1d6-bd46e8257ba8
02/10 18:34:58 Info: [broker/locations] media availability: MetadataService:Name=Metadata Service:Id=13769258-b70b-4243-b1d6-bd46e8257ba8 is online
02/10 18:34:58 Info: [broker/locations] adding storage location: Offline:Name=Offline:Id=f1e4b43f-f643-47ba-b875-fd93b32a6006
02/10 18:34:58 Debug: [broker/locations/migration] start, propname: location_automounts
02/10 18:34:58 Debug: [broker/locations/migration] start, propname: loc_29bdcae6b5fdd66627bfa1f6afceabac
02/10 18:34:58 Debug: [broker/locations] Migrating UUID based storage location, id: loc_29bdcae6b5fdd66627bfa1f6afceabac, version: 2
02/10 18:34:58 Debug: [broker/locations/migration] start, propname: loc_6df2c62a4c4244988aa48a34b76dd0cd
02/10 18:34:58 Debug: [broker/locations] Migrating UUID based storage location, id: loc_6df2c62a4c4244988aa48a34b76dd0cd, version: 2
02/10 18:34:58 Debug: [broker/locations] load pre 1.3 automounts, strlist: 
02/10 18:34:58 Trace: [storage] [directory] directorystorage init, location(/roon/sys/storage/mounts/InternalStorage, dirwatcher is available: True) 
02/10 18:34:58 Trace: [storage] [directory] init just before reorg delete thread, path: /roon/sys/storage/mounts/InternalStorage
02/10 18:34:58 Info: [broker/locations] storage location backend created and attached (DefaultMusicFolder:Name=Nucleus Internal Storage:Id=29bdcae6-b5fd-d666-27bf-a1f6afceabac)
02/10 18:34:58 Trace: [storage] [directory] temp directory cleared, path: /roon/sys/storage/mounts/InternalStorage/.tmp
02/10 18:34:58 Info: [broker/locations] adding storage location: DefaultMusicFolder:Name=Nucleus Internal Storage:Id=29bdcae6-b5fd-d666-27bf-a1f6afceabac
02/10 18:34:58 Info: [broker/locations] media availability: DefaultMusicFolder:Name=Nucleus Internal Storage:Id=29bdcae6-b5fd-d666-27bf-a1f6afceabac is online
02/10 18:34:58 Info: [broker/locations/directorystoragelocation] initializing FileBrowser.Entry:  THANK YOU, General UDisk : /Yucca Fest OST, drive availability is: False
02/10 18:34:58 Info: [broker/locations] created disabled location, FileBrowser.Entry:  THANK YOU, General UDisk : /Yucca Fest OST
02/10 18:34:58 Info: [broker/locations] adding storage location: Folder:Name=:Location=FileBrowser.Entry:  THANK YOU, General UDisk : /Yucca Fest OST:Id=6df2c62a-4c42-4498-8aa4-8a34b76dd0cd
02/10 18:34:58 Debug: [broker/locations] write pre 1.3 automounts, strlist: 
02/10 18:34:58 Info: [media] resolved oop decoder to /roon/app/Vendor/Codecs/ffmpeg
02/10 18:34:58 Info: [remoting/distributedbroker] V2 Protocol Support is enabled
02/10 18:34:58 Info: [remoting/brokerserver] Enabling broker server (V2)
02/10 18:34:58 Info: [broker/httpserver] HTTP server listening on port 9330
02/10 18:34:59 Info: [broker/httpserver] HTTPS server listening on port 43209
02/10 18:34:59 Trace: [broker/backups] initializing
02/10 18:34:59 Info: [loadstatus] IsMediaModuleLoading : False => True
02/10 18:34:59 Info: [loadstatus] IsLocalLibraryLoading True => True
02/10 18:34:59 Info: [loadstatus] IsTransportLoading True => True
02/10 18:34:59 Trace: [broker/accounts] Data updated. AccountStatus=LoggedIn MachineStatus=Licensed UserId=e12d84b0-9838-4424-8c92-f6bb83a8e2a4
02/10 18:34:59 Trace: [broker/accounts] Data updated. AccountStatus=LoggedIn MachineStatus=Licensed UserId=e12d84b0-9838-4424-8c92-f6bb83a8e2a4
02/10 18:34:59 Trace: [broker/accounts] [heartbeat] now=02/10/2024 18:34:59 nextauthrefresh=02/10/2024 18:29:59 nextmachineallocate=01/01/0001 00:00:00
02/10 18:34:59 Trace:  [broker/accounts]   doing auth refresh, next=02/10/2024 18:29:59
02/10 18:34:59 Trace: [broker/accounts] refreshing account info for email='nharsin@gmail.com' userid=e12d84b0-9838-4424-8c92-f6bb83a8e2a4
02/10 18:34:59 Trace: [fiveaccountserver] POST https://accounts5.roonlabs.com/accounts/3/login
02/10 18:34:59 Trace: [fiveaccountserver] BODY token=d78d8032-dd61-424c-95fd-3e88c2d9b0ae
02/10 18:34:59 Trace: [broker/accounts]    doing machine allocate, next=02/10/2024 22:34:59
02/10 18:34:59 Trace: [broker/accounts] Updating Machine Allocation machineid=189dd3a7-ca36-5b3e-450a-b7aa2fccbe8d hwserial=3B7853D2-7B01-44E0-8A43-83B21B8B0015,54B2039EAA26 machinename=House Burgundy Nucleus machinetype=Server
02/10 18:34:59 Trace: [fiveaccountserver] POST https://accounts5.roonlabs.com/accounts/3/machineallocate
02/10 18:34:59 Trace: [fiveaccountserver] BODY token=d78d8032-dd61-424c-95fd-3e88c2d9b0ae&machine=189dd3a7-ca36-5b3e-450a-b7aa2fccbe8d&serial=3B7853D2-7B01-44E0-8A43-83B21B8B0015%2c54B2039EAA26&name=House+Burgundy+Nucleus&type=Server
02/10 18:34:59 Trace: [inetdiscovery] added device broker/9e220375-320b-4597-8b3f-1f7bf58b7a1b in addr:__ADDR__
02/10 18:34:59 Info: [broker] is licensed for userid e12d84b0-9838-4424-8c92-f6bb83a8e2a4
02/10 18:34:59 Info: [libraryapi] loaded first run time 01/16/2021 03:13:57
02/10 18:34:59 Info: [loadstatus] IsMediaModuleLoading qobuz,tidal: True => True
02/10 18:34:59 Info: [loadstatus] IsLocalLibraryLoading True => True
02/10 18:34:59 Info: [loadstatus] IsTransportLoading True => True
02/10 18:34:59 Info: [clientdata] initializing with /roon/data/RoonServer/Database/Core/e12d84b0983844248c92f6bb83a8e2a4/clientdata.db
02/10 18:34:59 Trace: [inetdiscovery] added device broker/9e220375-320b-4597-8b3f-1f7bf58b7a1b in addr:__ADDR__
02/10 18:34:59 Trace: [devicedb] initializing
02/10 18:34:59 Trace: [roondns] flushed 13 last-known-good entries
02/10 18:34:59 Info: [raatserver] [runner] Start or Connect...
02/10 18:34:59 Info: [raatserver] [runner] Start or Connect... /roon/app/RoonServer/Appliance/RAATServer
02/10 18:34:59 Info: ConnectOrStartAndWaitForExit RAATServer, path: /roon/app/RoonServer/Appliance/RAATServer
02/10 18:34:59 Info: ConnectOrStartAndWaitForExit RAATServer: Try to connect to existing raatserver
02/10 18:34:59 Info: ConnectOrStartAndWaitForExit RAATServer: Failed to connect to existing raatserver, let's start one
02/10 18:34:59 Info: [stats] 5020mb Virtual, 80mb Physical, 3mb Managed, 184 Handles, 78 Threads
02/10 18:34:59 Info: [raatserver] [runner] Status: Started
02/10 18:34:59 Info: Database Size for /roon/data/RoonServer/Database/Core/e12d84b0983844248c92f6bb83a8e2a4: 1594MiB
02/10 18:34:59 Info: Database Size for /roon/data/RoonServer/Database/Core/e12d84b0983844248c92f6bb83a8e2a4/broker_4.db: 1476MiB
02/10 18:34:59 Warn: [multicastreceiver] couldn't bind to iface 127.0.0.1:5350, message: Invalid argument
02/10 18:34:59 Warn: [multicastreceiver] couldn't bind to iface 192.168.1.121:5350, message: Invalid argument
02/10 18:34:59 Info: [roonapi] audioinput is supported
02/10 18:34:59 Trace: [broker/services] refreshing metadata URL bits
02/10 18:34:59 Info: [broker/info] Adding tidal=max parameter to Roon services requests
02/10 18:34:59 Info: [broker/services] using url override for metadata: https://metadataserver.roonlabs.net/md/
02/10 18:34:59 Info: [broker/services] using url override for identifier: https://identifier.roonlabs.net/identifier/
02/10 18:34:59 Info: [broker/services] using url override for imagecache: https://imagecache.roonlabs.net/im/
02/10 18:34:59 Info: [broker/services] using url override for swim: https://swim.roonlabs.net/
02/10 18:34:59 Info: [broker/services] using url override for metadataservice2: https://metadata.roonlabs.net/
02/10 18:34:59 Info: [broker/services] using url override for qobuzservice: https://qobuz.roonlabs.net/
02/10 18:34:59 Info: [broker/services] using url override for tidalservice: https://tidal.roonlabs.net/
02/10 18:34:59 Info: [broker/services] using url override for kkboxservice: https://kkbox.roonlabs.net/
02/10 18:34:59 Info: [broker/services] using url override for searchservice: https://search.roonlabs.net/
02/10 18:34:59 Info: [broker/services] using url override for discoverservice: https://discover.roonlabs.net/
02/10 18:34:59 Info: [broker/services] using url override for browseservice: https://discover.roonlabs.net/
02/10 18:34:59 Info: Using FTMSI-B Cache
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /proc
02/10 18:34:59 Trace: [mobile] [remoteconnectivity] found new upnp device: Device={ DeviceType=urn:schemas-upnp-org:device:InternetGatewayDevice Version=1 FriendlyName=Archer AXE75 Manufacturer=TP-Link ModelName=Archer AXE75 UDN=uuid:be45ee76-59e0-4284-957f-af4295048d49 Description=Archer AXE75 ModelNumber=1.20 ManufacturerUri=http://www.tp-link.com/ ModelUrl=http://www.tp-link.com/Device={ DeviceType=urn:schemas-upnp-org:device:WANDevice Version=1 FriendlyName=WANDevice Manufacturer=MiniUPnP ModelName=WAN Device UDN=uuid:be45ee76-59e0-4284-957f-af4295048d49 Description=WAN Device ModelNumber=20230718 UPC=000000000000 ManufacturerUri=http://miniupnp.free.fr/ ModelUrl=http://miniupnp.free.fr/Device={ DeviceType=urn:schemas-upnp-org:device:WANConnectionDevice Version=1 FriendlyName=WANConnectionDevice Manufacturer=MiniUPnP ModelName=MiniUPnPd UDN=uuid:be45ee76-59e0-4284-957f-af4295048d49 Description=MiniUPnP daemon ModelNumber=20230718 UPC=000000000000 ManufacturerUri=http://miniupnp.free.fr/ ModelUrl=http://miniupnp.free.fr/Service={ ServiceType=urn:schemas-upnp-org:service:WANIPConnection ServiceVersion=1 ServiceId=urn:upnp-org:serviceId:WANIPConn1 ControlUri=http://192.168.1.1:1900/syyzj/ctl/IPConn SCPDUri=http://192.168.1.1:1900/syyzj/WANIPCn.xml }  } Service={ ServiceType=urn:schemas-upnp-org:service:WANCommonInterfaceConfig ServiceVersion=1 ServiceId=urn:upnp-org:serviceId:WANCommonIFC1 ControlUri=http://192.168.1.1:1900/syyzj/ctl/CmnIfCfg SCPDUri=http://192.168.1.1:1900/syyzj/WANCfg.xml }  } Service={ ServiceType=urn:schemas-upnp-org:service:Layer3Forwarding ServiceVersion=1 ServiceId=urn:upnp-org:serviceId:Layer3Forwarding1 ControlUri=http://192.168.1.1:1900/syyzj/ctl/L3F SCPDUri=http://192.168.1.1:1900/syyzj/L3F.xml }  }
02/10 18:34:59 Info: connected to watchdogport: 45917
02/10 18:34:59 Trace: [mobile] [remoteconnectivity] Port Verification started due to: found UPnP WANConnectiondevice, not testing port opening because mobile module init has not finished
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] skipping /proc because it is not a /dev/sd[0-9]* (mountline: none /proc proc rw,relatime 0 0)
02/10 18:34:59 Info: [broker/messaging] initializing
02/10 18:34:59 Info: [broker/images] migrated 0 records, 0 cached images to clean up
02/10 18:34:59 Info: [broker/images]     deleted 0 cached remote images
02/10 18:34:59 Info: [broker/images]     deleted 0 scaled cached local images
02/10 18:34:59 Info: [broker/images] cleaning up database...
02/10 18:34:59 Info: [broker/images] all done!
02/10 18:34:59 Trace:  [broker/accounts]   doing auth refresh in EnsureAuthReady, next=02/10/2024 19:34:59
02/10 18:34:59 Trace: [broker/accounts] refreshing account info for email='[moderated]' userid=e12d84b0-9838-4424-8c92-f6bb83a8e2a4
02/10 18:34:59 Trace: [fiveaccountserver] POST https://accounts5.roonlabs.com/accounts/3/login
02/10 18:34:59 Trace: [fiveaccountserver] BODY token=d78d8032-dd61-424c-95fd-3e88c2d9b0ae
02/10 18:34:59 Info: [broker/dropbox] no account configured
02/10 18:34:59 Info: [remoting] loaded protocol hash 1c975d142ef5a6df161394ca3170f80e22b8100d from /roon/app/RoonServer/Appliance/Roon.Broker.Api.Remote.dll
02/10 18:34:59 Info: [library/mobilesync] init
02/10 18:34:59 Info: [library/mobilesync] in InitDownloads
02/10 18:34:59 Info: [remoting/brokerserver] Remoting server (V1) listening on port 9331
02/10 18:34:59 Info: [remoting/brokerserver] Remoting server (V2) listening on port 9332
02/10 18:34:59 Trace: [inetdiscovery] added service com.roonlabs.roon.broker.tcp for device broker/9e220375-320b-4597-8b3f-1f7bf58b7a1b
02/10 18:34:59 Trace: [inetdiscovery] added service com.roonlabs.roon.broker.tcpv2 for device broker/9e220375-320b-4597-8b3f-1f7bf58b7a1b
02/10 18:34:59 Trace: [inetdiscovery] added service com.roonlabs.roon.broker.http for device broker/9e220375-320b-4597-8b3f-1f7bf58b7a1b
02/10 18:34:59 Trace: [geoip] GET https://geoip.roonlabs.net/geoip/1/lookup
02/10 18:34:59 Trace: [library/mobilesync] expiring mobile sync data for clients that last synced before 01/11/2024 18:34:59
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /dev
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /sys
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /tmp
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /overlay/boot
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /overlay/ro
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /overlay/rw
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /dev/pts
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] skipping /dev/pts because it is not a /dev/sd[0-9]* (mountline: none /dev/pts devpts rw,relatime,mode=600,ptmxmode=000 0 0)
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /sys/fs/cgroup
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] skipping /sys/fs/cgroup because it is not a /dev/sd[0-9]* (mountline: cgroup /sys/fs/cgroup tmpfs rw,relatime,mode=755 0 0)
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /sys/fs/cgroup/cpuset
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] skipping /sys/fs/cgroup/cpuset because it is not a /dev/sd[0-9]* (mountline: cgroup /sys/fs/cgroup/cpuset cgroup rw,relatime,cpuset 0 0)
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /sys/fs/cgroup/cpu
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] skipping /sys/fs/cgroup/cpu because it is not a /dev/sd[0-9]* (mountline: cgroup /sys/fs/cgroup/cpu cgroup rw,relatime,cpu 0 0)
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /sys/fs/cgroup/cpuacct
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] skipping /sys/fs/cgroup/cpuacct because it is not a /dev/sd[0-9]* (mountline: cgroup /sys/fs/cgroup/cpuacct cgroup rw,relatime,cpuacct 0 0)
02/10 18:34:59 Debug: [easyhttp] [1] POST to https://api.roonlabs.net/accounts5/accounts/3/login returned after 753 ms, status code: 200, request body size: 42 B
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /sys/fs/cgroup/blkio
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] skipping /sys/fs/cgroup/blkio because it is not a /dev/sd[0-9]* (mountline: cgroup /sys/fs/cgroup/blkio cgroup rw,relatime,blkio 0 0)
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /sys/fs/cgroup/memory
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] skipping /sys/fs/cgroup/memory because it is not a /dev/sd[0-9]* (mountline: cgroup /sys/fs/cgroup/memory cgroup rw,relatime,memory 0 0)
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /sys/fs/cgroup/devices
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] skipping /sys/fs/cgroup/devices because it is not a /dev/sd[0-9]* (mountline: cgroup /sys/fs/cgroup/devices cgroup rw,relatime,devices 0 0)
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /sys/fs/cgroup/freezer
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] skipping /sys/fs/cgroup/freezer because it is not a /dev/sd[0-9]* (mountline: cgroup /sys/fs/cgroup/freezer cgroup rw,relatime,freezer 0 0)
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /sys/fs/cgroup/net_cls
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] skipping /sys/fs/cgroup/net_cls because it is not a /dev/sd[0-9]* (mountline: cgroup /sys/fs/cgroup/net_cls cgroup rw,relatime,net_cls 0 0)
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /sys/fs/cgroup/perf_event
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] skipping /sys/fs/cgroup/perf_event because it is not a /dev/sd[0-9]* (mountline: cgroup /sys/fs/cgroup/perf_event cgroup rw,relatime,perf_event 0 0)
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /sys/fs/cgroup/net_prio
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] skipping /sys/fs/cgroup/net_prio because it is not a /dev/sd[0-9]* (mountline: cgroup /sys/fs/cgroup/net_prio cgroup rw,relatime,net_prio 0 0)
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /sys/fs/cgroup/hugetlb
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] skipping /sys/fs/cgroup/hugetlb because it is not a /dev/sd[0-9]* (mountline: cgroup /sys/fs/cgroup/hugetlb cgroup rw,relatime,hugetlb 0 0)
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /sys/fs/cgroup/pids
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] skipping /sys/fs/cgroup/pids because it is not a /dev/sd[0-9]* (mountline: cgroup /sys/fs/cgroup/pids cgroup rw,relatime,pids 0 0)
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /roon/app
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /roon/sys/storage/mounts/InternalStorage
02/10 18:34:59 Trace: [fiveaccountserver] GOT {"status":"Success","userid":"e12d84b0-9838-4424-8c92-f6bb83a8e2a4","token":"d78d8032-dd61-424c-95fd-3e88c2d9b0ae","expiration":30,"email":"[moderated],"groups":[]}
02/10 18:34:59 Debug: [easyhttp] [2] POST to https://api.roonlabs.net/accounts5/accounts/3/machineallocate returned after 776 ms, status code: 200, request body size: 186 B
02/10 18:34:59 Info: [music/database] opened database. migration version = 8 current version = 8
02/10 18:34:59 Debug: [broker/filebrowser/volumeattached] skipping /roon/sys/storage/mounts/InternalStorage because it is not a removable drive (mountline: /dev/sda1 /roon/sys/storage/mounts/InternalStorage ext4 rw,relatime 0 0), also the drive's /sys/block/sda path contains no '/usb': ../devices/pci0000:00/0000:00:17.0/ata1/host0/target0:0:0/0:0:0:0/block/sda
02/10 18:34:59 Info: [playlistdb] opened. migration version = 1 current version = 1
02/10 18:34:59 Info: [identification] Starting
02/10 18:34:59 Info: [library/index] init
02/10 18:34:59 Info: [music/searchindex] isSpellingCorrectionActive: True
02/10 18:35:00 Debug: [easyhttp] [3] POST to https://api.roonlabs.net/accounts5/accounts/3/login returned after 229 ms, status code: 200, request body size: 42 B
02/10 18:35:00 Info: [additionalimages] starting
02/10 18:35:00 Trace: [taste] loaded ProfileId=63:1:2e837edf-76ef-4e04-8c11-f785c59e02b8 IsDirty=True LastUpdate=02/10/2024 16:38:35 LastSummaryHash=473ff8cf:29727675:fc80cf28:3b2c60c4:89fde3fe
02/10 18:35:00 Trace: [taste] loaded ProfileId=63:1:f37274fe-bf9c-4b68-a6d5-2b1e7defa8b4 IsDirty=True LastUpdate=02/10/2024 16:38:48 LastSummaryHash=7cd6a0a1:5feb8e8d:4232ac03:73448ee0:dfd75643
02/10 18:35:00 Debug: [easyhttp] [4] GET to https://api.roonlabs.net/geoip/geoip/1/lookup returned after 246 ms, status code: 200, request body size: 0 B
02/10 18:35:00 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /roon/data
02/10 18:35:00 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /identity
02/10 18:35:00 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /roon/data/__docker
02/10 18:35:00 Debug: [broker/filebrowser/volumeattached] skipping /roon/data/__docker because it is not a /dev/sd[0-9]* (mountline: /dev/nvme0n1p4 /roon/data/__docker ext4 rw,relatime 0 0)
02/10 18:35:00 Trace: [fiveaccountserver] GOT {"status":"Success","licenseid":"15e717f7-d3a4-46a3-895b-ce33d272c3f3"}
02/10 18:35:00 Info: [loadstatus] account loading is complete
02/10 18:35:00 Trace: [fiveaccountserver] GOT {"status":"Success","userid":"e12d84b0-9838-4424-8c92-f6bb83a8e2a4","token":"d78d8032-dd61-424c-95fd-3e88c2d9b0ae","expiration":30,"email":"[moderated]","groups":[]}
02/10 18:35:00 Trace: [geoip] GOT {"source":"geolite","country_iso":"US","country":"United States of America","state":"California","state_iso":"CA","city":"Los Angeles","latitude":34.0672,"longitude":-118.3016,"postalcode":"90020","accuracy":20,"ip":"38.13.15.54","status":"Success","decimal_ip":"638390070","ipaddress":"38.13.15.54"}
02/10 18:35:00 Trace: [fiveaccountserver] GET https://accounts5.roonlabs.com/accounts/3/profileslist?token=d78d8032-dd61-424c-95fd-3e88c2d9b0ae
02/10 18:35:00 Trace: [fiveaccountserver] GET https://accounts5.roonlabs.com/accounts/3/userinfo?token=d78d8032-dd61-424c-95fd-3e88c2d9b0ae&machineid=189dd3a7-ca36-5b3e-450a-b7aa2fccbe8d
02/10 18:35:00 Trace: [broker/accounts] updated token. New expiration is 03/11/2024 18:35:00
02/10 18:35:00 Trace: [broker/accounts] Data updated. AccountStatus=LoggedIn MachineStatus=Licensed UserId=e12d84b0-9838-4424-8c92-f6bb83a8e2a4
02/10 18:35:00 Trace: [bits] myinfo: {"pushid":"broker/9e220375-320b-4597-8b3f-1f7bf58b7a1b","roon_auth_token":"d78d8032-dd61-424c-95fd-3e88c2d9b0ae","os":"RoonOS 1.0 (build 259) production","platform":"linuxx64","machineversion":200001365,"branch":"production","appmodifier":"","appname":"RoonServer"}
02/10 18:35:00 Trace: [fiveaccountserver] GET https://accounts5.roonlabs.com/accounts/3/profileslist?token=d78d8032-dd61-424c-95fd-3e88c2d9b0ae
02/10 18:35:00 Trace: [fiveaccountserver] GET https://accounts5.roonlabs.com/accounts/3/userinfo?token=d78d8032-dd61-424c-95fd-3e88c2d9b0ae&machineid=189dd3a7-ca36-5b3e-450a-b7aa2fccbe8d
02/10 18:35:00 Trace: [broker/accounts] updated token. New expiration is 03/11/2024 18:35:00
02/10 18:35:00 Trace: [broker/accounts] Data updated. AccountStatus=LoggedIn MachineStatus=Licensed UserId=e12d84b0-9838-4424-8c92-f6bb83a8e2a4
02/10 18:35:00 Trace: [broker/accounts] Data updated. AccountStatus=LoggedIn MachineStatus=Licensed UserId=e12d84b0-9838-4424-8c92-f6bb83a8e2a4
02/10 18:35:00 Trace: [broker/accounts] Machine Allocation Succeeded
02/10 18:35:00 Debug: [easyhttp] [12] GET to https://api.roonlabs.net/accounts5/accounts/3/userinfo?token=d78d8032-dd61-424c-95fd-3e88c2d9b0ae&machineid=189dd3a7-ca36-5b3e-450a-b7aa2fccbe8d returned after 118 ms, status code: 200, request body size: 0 B
02/10 18:35:00 Trace: [fiveaccountserver] GOT {"user":{"tfa":{"enabled":false},"userid":"e12d84b0-9838-4424-8c92-f6bb83a8e2a4","firstname":"Nicholas","lastname":"Harsin","email":"[moderated]","joinmailinglist":true,"allowpushnotifications":true,"class":"Normal","groups":[],"dncs":["roon_software_promos","roon_store_promos"],"trialallowed":false},"status":"Success"}
02/10 18:35:00 Trace: [broker/accounts] Data updated. AccountStatus=LoggedIn MachineStatus=Licensed UserId=e12d84b0-9838-4424-8c92-f6bb83a8e2a4
02/10 18:35:00 Debug: [easyhttp] [8] GET to https://api.roonlabs.net/accounts5/accounts/3/profileslist?token=d78d8032-dd61-424c-95fd-3e88c2d9b0ae returned after 245 ms, status code: 200, request body size: 0 B
02/10 18:35:00 Trace: [fiveaccountserver] GOT {"status":"Success","profiles":[{"id":"2e837edf-76ef-4e04-8c11-f785c59e02b8","name":"Nicholas","photo":"https://sooloos-profileimages.s3.amazonaws.com/five-e12d84b0-9838-4424-8c92-f6bb83a8e2a4--2e837edf-76ef-4e04-8c11-f785c59e02b8.jpg","birthdate":"19870000"},{"id":"f37274fe-bf9c-4b68-a6d5-2b1e7defa8b4","name":"Craig","photo":"https://sooloos-profileimages.s3.amazonaws.com/five-e12d84b0-9838-4424-8c92-f6bb83a8e2a4--f37274fe-bf9c-4b68-a6d5-2b1e7defa8b4.jpg","birthdate":"19560429"}]}
02/10 18:35:00 Debug: [easyhttp] [9] GET to https://api.roonlabs.net/accounts5/accounts/3/userinfo?token=d78d8032-dd61-424c-95fd-3e88c2d9b0ae&machineid=189dd3a7-ca36-5b3e-450a-b7aa2fccbe8d returned after 256 ms, status code: 200, request body size: 0 B
02/10 18:35:00 Trace: [broker/accounts] Data updated. AccountStatus=LoggedIn MachineStatus=Licensed UserId=e12d84b0-9838-4424-8c92-f6bb83a8e2a4
02/10 18:35:00 Trace: [fiveaccountserver] GOT {"user":{"tfa":{"enabled":false},"userid":"e12d84b0-9838-4424-8c92-f6bb83a8e2a4","firstname":"Nicholas","lastname":"Harsin","email":"[moderated]","joinmailinglist":true,"allowpushnotifications":true,"class":"Normal","groups":[],"dncs":["roon_software_promos","roon_store_promos"],"trialallowed":false},"status":"Success"}
02/10 18:35:00 Trace: [broker/accounts] Data updated. AccountStatus=LoggedIn MachineStatus=Licensed UserId=e12d84b0-9838-4424-8c92-f6bb83a8e2a4
02/10 18:35:00 Debug: [easyhttp] [11] GET to https://api.roonlabs.net/accounts5/accounts/3/profileslist?token=d78d8032-dd61-424c-95fd-3e88c2d9b0ae returned after 228 ms, status code: 200, request body size: 0 B
02/10 18:35:00 Trace: [fiveaccountserver] GOT {"status":"Success","profiles":[{"id":"2e837edf-76ef-4e04-8c11-f785c59e02b8","name":"Nicholas","photo":"https://sooloos-profileimages.s3.amazonaws.com/five-e12d84b0-9838-4424-8c92-f6bb83a8e2a4--2e837edf-76ef-4e04-8c11-f785c59e02b8.jpg","birthdate":"19870000"},{"id":"f37274fe-bf9c-4b68-a6d5-2b1e7defa8b4","name":"Craig","photo":"https://sooloos-profileimages.s3.amazonaws.com/five-e12d84b0-9838-4424-8c92-f6bb83a8e2a4--f37274fe-bf9c-4b68-a6d5-2b1e7defa8b4.jpg","birthdate":"19560429"}]}
02/10 18:35:00 Trace: [broker/accounts] Data updated. AccountStatus=LoggedIn MachineStatus=Licensed UserId=e12d84b0-9838-4424-8c92-f6bb83a8e2a4
02/10 18:35:00 Debug: [easyhttp] [10] POST to https://api.roonlabs.net/bits/1/q/roon.base.,roon.internet_discovery.,roon.debug.,roon.broker.,roon.dsp.,roon.sood.?roon_auth_token=d78d8032-dd61-424c-95fd-3e88c2d9b0ae returned after 280 ms, status code: 200, request body size: 265 B
02/10 18:35:00 Trace: [bits] updated bits, in 290ms
02/10 18:35:00 Debug: [easyhttp] [13] GET to https://api.roonlabs.net/profileimages/five-e12d84b0-9838-4424-8c92-f6bb83a8e2a4--2e837edf-76ef-4e04-8c11-f785c59e02b8.jpg?random=e515f8c4-dfaa-4a53-8a9b-de3db34e77cf returned after 245 ms, status code: 200, request body size: 0 B
02/10 18:35:00 Debug: [easyhttp] [15] GET to https://api.roonlabs.net/messaging/1/api/messages/e12d84b0-9838-4424-8c92-f6bb83a8e2a4 returned after 240 ms, status code: 200, request body size: 0 B
02/10 18:35:00 Info: [library] Queueing initial load of 26603 tracks + 1076 auxfiles
02/10 18:35:00 Debug: [easyhttp] [16] GET to https://api.roonlabs.net/profileimages/five-e12d84b0-9838-4424-8c92-f6bb83a8e2a4--2e837edf-76ef-4e04-8c11-f785c59e02b8.jpg?random=01f74228-bc8f-4386-89e0-4ffdbd15f8e0 returned after 224 ms, status code: 200, request body size: 0 B
02/10 18:35:00 Debug: [easyhttp] [17] GET to https://api.roonlabs.net/profileimages/five-e12d84b0-9838-4424-8c92-f6bb83a8e2a4--f37274fe-bf9c-4b68-a6d5-2b1e7defa8b4.jpg?random=8791eefc-3198-40bb-a3e4-2f6c02c64829 returned after 225 ms, status code: 200, request body size: 0 B
02/10 18:35:00 Debug: [easyhttp] [14] GET to https://api.roonlabs.net/profileimages/five-e12d84b0-9838-4424-8c92-f6bb83a8e2a4--f37274fe-bf9c-4b68-a6d5-2b1e7defa8b4.jpg?random=8b2d2727-4db6-431a-8f7c-4d279ef07d5a returned after 327 ms, status code: 200, request body size: 0 B
02/10 18:35:00 Trace: [volumewatcher] ev_VolumeChanged DidMount: /proc
02/10 18:35:00 Trace: [volumewatcher] ev_VolumeChanged DidMount: /dev
02/10 18:35:00 Trace: [volumewatcher] ev_VolumeChanged DidMount: /sys
02/10 18:35:00 Trace: [volumewatcher] ev_VolumeChanged DidMount: /tmp
02/10 18:35:00 Trace: [volumewatcher] ev_VolumeChanged DidMount: /overlay/boot
02/10 18:35:00 Trace: [volumewatcher] ev_VolumeChanged DidMount: /overlay/ro
02/10 18:35:00 Trace: [volumewatcher] ev_VolumeChanged DidMount: /overlay/rw
02/10 18:35:00 Trace: [volumewatcher] ev_VolumeChanged DidMount: /
02/10 18:35:00 Trace: [volumewatcher] ev_VolumeChanged DidMount: /dev/pts
02/10 18:35:00 Trace: [volumewatcher] ev_VolumeChanged DidMount: /sys/fs/cgroup
02/10 18:35:00 Trace: [volumewatcher] ev_VolumeChanged DidMount: /sys/fs/cgroup/cpuset
02/10 18:35:00 Trace: [volumewatcher] ev_VolumeChanged DidMount: /sys/fs/cgroup/cpu
02/10 18:35:00 Trace: [volumewatcher] ev_VolumeChanged DidMount: /sys/fs/cgroup/cpuacct
02/10 18:35:00 Trace: [volumewatcher] ev_VolumeChanged DidMount: /sys/fs/cgroup/blkio
02/10 18:35:00 Trace: [volumewatcher] ev_VolumeChanged DidMount: /sys/fs/cgroup/memory
02/10 18:35:00 Trace: [volumewatcher] ev_VolumeChanged DidMount: /sys/fs/cgroup/devices
02/10 18:35:00 Trace: [volumewatcher] ev_VolumeChanged DidMount: /sys/fs/cgroup/freezer
02/10 18:35:00 Trace: [volumewatcher] ev_VolumeChanged DidMount: /sys/fs/cgroup/net_cls
02/10 18:35:00 Trace: [volumewatcher] ev_VolumeChanged DidMount: /sys/fs/cgroup/perf_event
02/10 18:35:00 Trace: [volumewatcher] ev_VolumeChanged DidMount: /sys/fs/cgroup/net_prio
02/10 18:35:00 Trace: [volumewatcher] ev_VolumeChanged DidMount: /sys/fs/cgroup/hugetlb

Geoff_Coupe · February 10, 2024, 8:46pm

So if you have added Qobuz and/or Tidal albums to your Library, they count as well. What is then the total number of tracks in your library?

Geoff_Coupe · February 10, 2024, 8:53pm

BTW, not a good idea to post logs into the public forum - they contain your email address. I think I’ve removed all instances.

The Support team can pull logs from your Nucleus, so it’s not necessary to post them here.

Nicholas_Harsin · February 12, 2024, 8:36pm

26,614 tracks. And thanks for cleaning up the log file.

connor · February 21, 2024, 6:38pm

Hi @Nicholas_Harsin,

Thank you for your patience - we’re still investigating this case but wanted to ask if you’ve seen any performance improvements since updating to the newly released build of Roon.

Are you able to bypass the network switch and hardwire the Nuclues to the router? The network reachability failures registred on our servers from your account are patterned - it seems like this Nucleus, as well as your Remotes, are frequently being dropped and reregistered on the local network. Are there any other hardware components involved in this network?

A useful test would be to make a Backup of your database and disconnect the device entirely before downloading RoonServer to one of your Mac Remotes. Temporarily deauthorize the Nucleus as a RoonServer and test if your MacBook, as a RoonServer, shows the same problems. This should isolate whether the Nucleus itself or the network topology is responsible for the slowness. Thanks!