Aug 27 19:39:00 volumio5678 dhcpcd[1060]: wlan0: carrier lost Aug 27 19:39:00 volumio5678 sudo[2844]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:00 volumio5678 welcome[2849]: Resolved ip:[0] Aug 27 19:39:00 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: Cleaning previous... Aug 27 19:39:00 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:00.367-04:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.12.7:59991,00:00:00:00:00:00%01 @ 0x1dbf3b0" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Aug 27 19:39:00 volumio5678 volumio[1402]: info: Received Get System Info Aug 27 19:39:00 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 19:39:00 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 19:39:00 volumio5678 volumio[1402]: info: Discovery: Getting this device information Aug 27 19:39:00 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:00 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:00 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 19:39:00 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 27 19:39:00 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 27 19:39:00 volumio5678 sudo[2868]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Aug 27 19:39:00 volumio5678 sudo[2868]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 27 19:39:00 volumio5678 systemd[1]: Finished welcome.service - Show a welcome message on console. Aug 27 19:39:00 volumio5678 systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Aug 27 19:39:00 volumio5678 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Aug 27 19:39:00 volumio5678 sudo[2868]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:00 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: InterfaceValidator: READY - wlan0 is ready for operations Aug 27 19:39:00 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: InterfaceValidator: wlan0 became ready after 1ms Aug 27 19:39:00 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: ensureInterfaceReady: Interface ready (MAC: 2c:cf:67:8c:2c:7f) Aug 27 19:39:00 volumio5678 sudo[2883]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Aug 27 19:39:00 volumio5678 sudo[2883]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:00 volumio5678 sudo[2883]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:00 volumio5678 sudo[2891]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Aug 27 19:39:00 volumio5678 sudo[2891]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:00 volumio5678 sudo[2896]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 19:39:00 volumio5678 sudo[2896]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:00 volumio5678 sudo[2896]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:00 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:00.889-04:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.12.7:59991,00:00:00:00:00:00%01 @ 0x1dbf3b0" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Aug 27 19:39:00 volumio5678 volumio[1402]: info: Received Get System Info Aug 27 19:39:00 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 19:39:00 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 19:39:00 volumio5678 volumio[1402]: info: Discovery: Getting this device information Aug 27 19:39:00 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:00 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:00 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 19:39:00 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 27 19:39:00 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 27 19:39:01 volumio5678 sudo[2899]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 19:39:01 volumio5678 sudo[2899]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:01 volumio5678 sudo[2899]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:01 volumio5678 ntpd[1204]: IO: Deleting interface #3 wlan0, 192.168.12.60#123, interface stats: received=188, sent=189, dropped=0, active_time=294 secs Aug 27 19:39:01 volumio5678 ntpd[1204]: PROTO: 172.234.25.10 unlink local addr 192.168.12.60 -> Aug 27 19:39:01 volumio5678 ntpd[1204]: PROTO: 172.232.15.202 unlink local addr 192.168.12.60 -> Aug 27 19:39:01 volumio5678 ntpd[1204]: PROTO: 45.33.53.84 unlink local addr 192.168.12.60 -> Aug 27 19:39:01 volumio5678 ntpd[1204]: PROTO: 162.244.81.139 unlink local addr 192.168.12.60 -> Aug 27 19:39:01 volumio5678 ntpd[1204]: PROTO: 167.248.62.201 unlink local addr 192.168.12.60 -> Aug 27 19:39:01 volumio5678 ntpd[1204]: PROTO: 45.79.82.45 unlink local addr 192.168.12.60 -> Aug 27 19:39:01 volumio5678 ntpd[1204]: PROTO: 45.63.54.13 unlink local addr 192.168.12.60 -> Aug 27 19:39:01 volumio5678 ntpd[1204]: PROTO: 144.86.176.16 unlink local addr 192.168.12.60 -> Aug 27 19:39:01 volumio5678 ntpd[1204]: PROTO: 23.186.168.123 unlink local addr 192.168.12.60 -> Aug 27 19:39:01 volumio5678 ntpd[1204]: PROTO: 72.14.182.49 unlink local addr 192.168.12.60 -> Aug 27 19:39:01 volumio5678 ntpd[1204]: PROTO: 172.233.157.223 unlink local addr 192.168.12.60 -> Aug 27 19:39:01 volumio5678 ntpd[1204]: PROTO: 192.207.55.254 unlink local addr 192.168.12.60 -> Aug 27 19:39:01 volumio5678 ntpd[1204]: PROTO: 23.152.160.74 unlink local addr 192.168.12.60 -> Aug 27 19:39:01 volumio5678 ntpd[1204]: PROTO: 23.150.41.123 unlink local addr 192.168.12.60 -> Aug 27 19:39:01 volumio5678 ntpd[1204]: PROTO: 45.84.199.136 unlink local addr 192.168.12.60 -> Aug 27 19:39:01 volumio5678 ntpd[1204]: PROTO: 199.101.96.52 unlink local addr 192.168.12.60 -> Aug 27 19:39:01 volumio5678 volumio[1402]: info: Volumio Network Manager: Network status updated: 0 Aug 27 19:39:02 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:02.261-04:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 27 19:39:02 volumio5678 sudo[2916]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 19:39:02 volumio5678 sudo[2916]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:02 volumio5678 sudo[2916]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:03 volumio5678 sudo[2891]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:03 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: Regdomain already correct: US Aug 27 19:39:03 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: Start wireless flow Aug 27 19:39:03 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: Stopped hotspot (if there).. Aug 27 19:39:03 volumio5678 sudo[2922]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Aug 27 19:39:03 volumio5678 sudo[2922]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 27 19:39:03 volumio5678 sudo[2922]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:03 volumio5678 sudo[2924]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Aug 27 19:39:03 volumio5678 sudo[2924]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 27 19:39:03 volumio5678 sudo[2924]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:03 volumio5678 volumio[1402]: info: Received Get System Info Aug 27 19:39:03 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 19:39:03 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 19:39:03 volumio5678 volumio[1402]: info: Discovery: Getting this device information Aug 27 19:39:03 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:03 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:03 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 19:39:03 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:03.789-04:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.12.7:59991,00:00:00:00:00:00%01 @ 0x1dbf3b0" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Aug 27 19:39:03 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 27 19:39:03 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 27 19:39:03 volumio5678 sudo[2927]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 19:39:03 volumio5678 sudo[2927]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:03 volumio5678 sudo[2927]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:03 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: InterfaceValidator: READY - wlan0 is ready for operations Aug 27 19:39:03 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: STAGE 1: wlan0 validated and ready (MAC: 2c:cf:67:8c:2c:7f, USB: false) Aug 27 19:39:03 volumio5678 wpa_supplicant[2933]: Successfully initialized wpa_supplicant Aug 27 19:39:03 volumio5678 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Aug 27 19:39:03 volumio5678 wpa_supplicant[2933]: nl80211: kernel reports: Registration to specific type not supported Aug 27 19:39:03 volumio5678 sudo[2939]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Aug 27 19:39:03 volumio5678 sudo[2939]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 27 19:39:03 volumio5678 sudo[2939]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:04 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:04.316-04:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.12.7:59991,00:00:00:00:00:00%01 @ 0x1dbf3b0" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Aug 27 19:39:04 volumio5678 volumio[1402]: info: Received Get System Info Aug 27 19:39:04 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 19:39:04 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 19:39:04 volumio5678 volumio[1402]: info: Discovery: Getting this device information Aug 27 19:39:04 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:04 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:04 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 19:39:04 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 27 19:39:04 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 27 19:39:04 volumio5678 sudo[2946]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 19:39:04 volumio5678 sudo[2946]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:04 volumio5678 sudo[2946]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:04 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: DHCP IP fallback Aug 27 19:39:04 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: STAGE 2: Starting event-driven WPA state monitor Aug 27 19:39:04 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: WpaStateMachine: Starting state monitor for wlan0 Aug 27 19:39:05 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: WpaStateMachine: State transition: NULL -> SCANNING (duration: 0ms) Aug 27 19:39:05 volumio5678 sudo[2955]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 19:39:05 volumio5678 sudo[2955]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:05 volumio5678 sudo[2955]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:05 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:05.664-04:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 27 19:39:06 volumio5678 sudo[2964]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 19:39:06 volumio5678 sudo[2964]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:06 volumio5678 sudo[2964]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:06 volumio5678 wpa_supplicant[2936]: wlan0: Trying to associate with 10:5a:95:85:85:25 (SSID='TMOBILE-F5B1_EXT_5G' freq=5745 MHz) Aug 27 19:39:06 volumio5678 wpa_supplicant[2936]: wlan0: Associated with 10:5a:95:85:85:25 Aug 27 19:39:06 volumio5678 wpa_supplicant[2936]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Aug 27 19:39:06 volumio5678 wpa_supplicant[2936]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US Aug 27 19:39:06 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: WpaStateMachine: State transition: SCANNING -> ASSOCIATED (duration: 1512ms) Aug 27 19:39:06 volumio5678 wpa_supplicant[2936]: wlan0: WPA: Key negotiation completed with 10:5a:95:85:85:25 [PTK=CCMP GTK=CCMP] Aug 27 19:39:06 volumio5678 wpa_supplicant[2936]: wlan0: CTRL-EVENT-CONNECTED - Connection to 10:5a:95:85:85:25 completed [id=0 id_str=] Aug 27 19:39:06 volumio5678 dhcpcd[1060]: wlan0: carrier acquired Aug 27 19:39:06 volumio5678 dhcpcd[1060]: wlan0: connected to Access Point: TMOBILE-F5B1_EXT_5G Aug 27 19:39:06 volumio5678 dbus-daemon[1033]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1621 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=1032 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Aug 27 19:39:06 volumio5678 dhcpcd[1060]: wlan0: IAID 67:8c:2c:7f Aug 27 19:39:07 volumio5678 dhcpcd[1060]: wlan0: soliciting an IPv6 router Aug 27 19:39:07 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: WpaStateMachine: State transition: ASSOCIATED -> COMPLETED (duration: 504ms) Aug 27 19:39:07 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: WpaStateMachine: COMPLETED - connection successful Aug 27 19:39:07 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: STAGE 2: Connection successful - Connected to 10:5a:95:85:85:25 Aug 27 19:39:07 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: Onboard WiFi adapter detected, using standard dhcpcd flow Aug 27 19:39:07 volumio5678 volumio[1402]: info: Received Get System Info Aug 27 19:39:07 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 19:39:07 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 19:39:07 volumio5678 volumio[1402]: info: Discovery: Getting this device information Aug 27 19:39:07 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:07 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:07 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 19:39:07 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:07.464-04:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.12.7:59991,00:00:00:00:00:00%01 @ 0x1dbf3b0" available=true connected=true macAddress=2c:cf:67:8c:2c:7f ip4Address= ip6Address= ssid=TMOBILE-F5B1_EXT_5G Aug 27 19:39:07 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 27 19:39:07 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 27 19:39:07 volumio5678 sudo[2978]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 19:39:07 volumio5678 sudo[2978]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:07 volumio5678 sudo[2978]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:08 volumio5678 dhcpcd[1060]: wlan0: soliciting a DHCP lease Aug 27 19:39:08 volumio5678 dhcpcd[1060]: wlan0: offered 192.168.12.60 from 192.168.12.1 Aug 27 19:39:08 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:08.339-04:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 27 19:39:08 volumio5678 sudo[2981]: root : PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd wlan0 Aug 27 19:39:08 volumio5678 sudo[2981]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 27 19:39:08 volumio5678 dhcpcd[1060]: ps_ctl_dispatch: cannot handle another client Aug 27 19:39:08 volumio5678 dhcpcd[1060]: control_free: No such file or directory Aug 27 19:39:08 volumio5678 sudo[2981]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:08 volumio5678 sudo[2984]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 19:39:08 volumio5678 sudo[2984]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:08 volumio5678 sudo[2984]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:08 volumio5678 dhcpcd[1060]: wlan0: probing address 192.168.12.60/24 Aug 27 19:39:09 volumio5678 volumio[1402]: info: Discovery: Networking Restart detected, restarting advertisement and browsing Aug 27 19:39:09 volumio5678 volumio[1402]: info: Discovery: Restarting Advertising Aug 27 19:39:09 volumio5678 volumio[1402]: info: Discovery: Stopping existing advertisement Aug 27 19:39:09 volumio5678 volumio[1402]: info: Discovery: Restarting Browsing Aug 27 19:39:09 volumio5678 sudo[2988]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 19:39:09 volumio5678 sudo[2988]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:09 volumio5678 sudo[2988]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:10 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: Start ap Aug 27 19:39:10 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: Notified systemd about wireless ready Aug 27 19:39:10 volumio5678 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Aug 27 19:39:10 volumio5678 systemd[1]: Started wireless.service - Wireless Services. Aug 27 19:39:10 volumio5678 sudo[2811]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:10 volumio5678 volumio[1402]: info: Discovery: A device disappeared from network Aug 27 19:39:10 volumio5678 sudo[2997]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 19:39:10 volumio5678 sudo[2997]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:10 volumio5678 sudo[2997]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:10 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:10.773-04:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=1 chunks=1 index=0 tries=11 Aug 27 19:39:11 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: trying... Aug 27 19:39:11 volumio5678 sudo[3008]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 19:39:11 volumio5678 sudo[3008]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:11 volumio5678 sudo[3008]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:11 volumio5678 sudo[3011]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 19:39:11 volumio5678 sudo[3011]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 27 19:39:11 volumio5678 sudo[3011]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:11 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: ... wlan0 IPv4 is undefined, ipV6 is undefined Aug 27 19:39:11 volumio5678 sudo[3014]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 19:39:11 volumio5678 sudo[3014]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:11 volumio5678 sudo[3014]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:12 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: trying... Aug 27 19:39:12 volumio5678 sudo[3039]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 19:39:12 volumio5678 sudo[3039]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:12 volumio5678 sudo[3039]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:12 volumio5678 sudo[3043]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 19:39:12 volumio5678 sudo[3043]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 27 19:39:12 volumio5678 sudo[3043]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:12 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: ... wlan0 IPv4 is undefined, ipV6 is undefined Aug 27 19:39:12 volumio5678 sudo[3046]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 19:39:12 volumio5678 sudo[3046]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:12 volumio5678 sudo[3046]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:13 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: WARNING: dhcpcd running but no IP assigned yet Aug 27 19:39:13 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: trying... Aug 27 19:39:13 volumio5678 sudo[3066]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 19:39:13 volumio5678 sudo[3066]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:13 volumio5678 sudo[3066]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:13 volumio5678 sudo[3069]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 19:39:13 volumio5678 sudo[3069]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 27 19:39:13 volumio5678 sudo[3069]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:13 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: ... wlan0 IPv4 is undefined, ipV6 is undefined Aug 27 19:39:13 volumio5678 sudo[3072]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 19:39:13 volumio5678 sudo[3072]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:13 volumio5678 sudo[3072]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:14 volumio5678 dhcpcd[1060]: wlan0: leased 192.168.12.60 for 86400 seconds Aug 27 19:39:14 volumio5678 avahi-daemon[1812]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.12.60. Aug 27 19:39:14 volumio5678 avahi-daemon[1812]: New relevant interface wlan0.IPv4 for mDNS. Aug 27 19:39:14 volumio5678 dhcpcd[1060]: wlan0: adding route to 192.168.12.0/24 Aug 27 19:39:14 volumio5678 dhcpcd[1060]: wlan0: adding default route via 192.168.12.1 Aug 27 19:39:14 volumio5678 avahi-daemon[1812]: Registering new address record for 192.168.12.60 on wlan0.IPv4. Aug 27 19:39:14 volumio5678 systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Aug 27 19:39:14 volumio5678 systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Aug 27 19:39:14 volumio5678 systemd[1]: welcome.service: Deactivated successfully. Aug 27 19:39:14 volumio5678 systemd[1]: Stopped welcome.service - Show a welcome message on console. Aug 27 19:39:14 volumio5678 systemd[1]: Stopping welcome.service - Show a welcome message on console... Aug 27 19:39:14 volumio5678 systemd[1]: Starting welcome.service - Show a welcome message on console... Aug 27 19:39:14 volumio5678 welcome[3089]: Resolved ip:[1] 192.168.12.60 Aug 27 19:39:14 volumio5678 systemd[1]: Finished welcome.service - Show a welcome message on console. Aug 27 19:39:14 volumio5678 systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Aug 27 19:39:14 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: trying... Aug 27 19:39:14 volumio5678 sudo[3109]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 19:39:14 volumio5678 sudo[3109]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:14 volumio5678 sudo[3109]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:14 volumio5678 sudo[3112]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 19:39:14 volumio5678 sudo[3112]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 27 19:39:14 volumio5678 sudo[3112]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:14 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: ... wlan0 IPv4 is 192.168.12.60, ipV6 is undefined Aug 27 19:39:14 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: Connected to SSID: TMOBILE-F5B1_EXT_5G Aug 27 19:39:14 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: It's done! AP Aug 27 19:39:14 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: Restarting avahi-daemon... Aug 27 19:39:14 volumio5678 sudo[3117]: root : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart avahi-daemon Aug 27 19:39:14 volumio5678 sudo[3117]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 27 19:39:14 volumio5678 volumio[1402]: info: Discovery: Started advertising with name: Volumio5678 Aug 27 19:39:14 volumio5678 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 27 19:39:14 volumio5678 systemd[1]: shairport-sync.service: Deactivated successfully. Aug 27 19:39:14 volumio5678 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 27 19:39:14 volumio5678 systemd[1]: shairport-sync.service: Consumed 1.737s CPU time. Aug 27 19:39:14 volumio5678 avahi-daemon[1812]: Got SIGTERM, quitting. Aug 27 19:39:14 volumio5678 systemd[1]: Stopping avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Aug 27 19:39:14 volumio5678 avahi-daemon[1812]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.12.60. Aug 27 19:39:14 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:14.518-04:00 level=WARN msg="disconnected from Avahi daemon, trying to reconnect" component=discovery/localnet error="avahi: Daemon connection failed" Aug 27 19:39:14 volumio5678 avahi-daemon[1812]: Leaving mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Aug 27 19:39:14 volumio5678 vtcs[2169]: [2026-08-27 19:39:14.519] [tisoc] [error] [avahiImpl.cpp:113] avahiClientCallback() AVAHI_CLIENT_S_COLLISION/AVAHI_CLIENT_FAILURE Aug 27 19:39:14 volumio5678 volumio[1402]: info: Discovery: Browse raised the following error Error: dns service error: unknown Aug 27 19:39:14 volumio5678 volumio[1402]: info: Discovery: Restarting Browsing Aug 27 19:39:14 volumio5678 volumio[1402]: Cast browser error: Error: dns service error: unknown Aug 27 19:39:14 volumio5678 sudo[3122]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 19:39:14 volumio5678 volumio[1402]: info: Discovery: Browse raised the following error Error: dns service error: unknown Aug 27 19:39:14 volumio5678 volumio[1402]: info: Discovery: Restarting Browsing Aug 27 19:39:14 volumio5678 volumio[1402]: info: Discovery: Restart already pending, ignoring duplicate call Aug 27 19:39:14 volumio5678 dbus-daemon[1033]: [system] Activating via systemd: service name='org.freedesktop.Avahi' unit='dbus-org.freedesktop.Avahi.service' requested by ':1.41' (uid=0 pid=1852 comm="/usr/sbin/smbd --foreground --no-process-group") Aug 27 19:39:14 volumio5678 sudo[3122]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:14 volumio5678 volumio[1402]: error: Discovery: Advertisement error: Error: dns service error: unknown Aug 27 19:39:14 volumio5678 volumio[1402]: error: Discovery: advertisement error: Error: dns service error: unknown Aug 27 19:39:14 volumio5678 volumio[1402]: info: Discovery: Advertisement raised the following error Error: dns service error: unknown Aug 27 19:39:14 volumio5678 volumio[1402]: info: Discovery: Stopping Advertising Immediately Aug 27 19:39:14 volumio5678 volumio[1402]: info: Discovery: Stopping existing advertisement Aug 27 19:39:14 volumio5678 sudo[3122]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:14 volumio5678 avahi-daemon[1812]: avahi-daemon 0.8 exiting. Aug 27 19:39:14 volumio5678 systemd[1]: avahi-daemon.service: Deactivated successfully. Aug 27 19:39:14 volumio5678 systemd[1]: Stopped avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Aug 27 19:39:14 volumio5678 sudo[3126]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Aug 27 19:39:14 volumio5678 sudo[3126]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:14 volumio5678 sudo[3126]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:14 volumio5678 systemd[1]: Starting avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Aug 27 19:39:14 volumio5678 avahi-daemon[3130]: Process 1812 died: No such process; trying to remove PID file. (/run/avahi-daemon//pid) Aug 27 19:39:14 volumio5678 avahi-daemon[3130]: Found user 'avahi' (UID 103) and group 'avahi' (GID 109). Aug 27 19:39:14 volumio5678 avahi-daemon[3130]: Successfully dropped root privileges. Aug 27 19:39:14 volumio5678 avahi-daemon[3130]: avahi-daemon 0.8 starting up. Aug 27 19:39:14 volumio5678 dbus-daemon[1033]: [system] Successfully activated service 'org.freedesktop.Avahi' Aug 27 19:39:14 volumio5678 systemd[1]: Started avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Aug 27 19:39:14 volumio5678 avahi-daemon[3130]: Successfully called chroot(). Aug 27 19:39:14 volumio5678 avahi-daemon[3130]: Successfully dropped remaining capabilities. Aug 27 19:39:14 volumio5678 avahi-daemon[3130]: Loading service file /services/volumio.service. Aug 27 19:39:14 volumio5678 sudo[3117]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:14 volumio5678 avahi-daemon[3130]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.12.60. Aug 27 19:39:14 volumio5678 avahi-daemon[3130]: New relevant interface wlan0.IPv4 for mDNS. Aug 27 19:39:14 volumio5678 avahi-daemon[3130]: Joining mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Aug 27 19:39:14 volumio5678 avahi-daemon[3130]: New relevant interface lo.IPv4 for mDNS. Aug 27 19:39:14 volumio5678 avahi-daemon[3130]: Network interface enumeration completed. Aug 27 19:39:14 volumio5678 avahi-daemon[3130]: Registering new address record for 192.168.12.60 on wlan0.IPv4. Aug 27 19:39:14 volumio5678 avahi-daemon[3130]: Registering new address record for 127.0.0.1 on lo.IPv4. Aug 27 19:39:14 volumio5678 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 27 19:39:14 volumio5678 wireless.js[2815]: WIRELESS.JS - INFO: Notified systemd about wireless ready Aug 27 19:39:14 volumio5678 volumio[1402]: info: Received Get System Info Aug 27 19:39:14 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 19:39:14 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 19:39:14 volumio5678 volumio[1402]: info: Discovery: Getting this device information Aug 27 19:39:14 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:14 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:14 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 19:39:14 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 27 19:39:14 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 27 19:39:14 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:14.716-04:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.12.7:59991 @ 0x1dbf3b0" available=true connected=true macAddress=2c:cf:67:8c:2c:7f ip4Address=192.168.12.60/24 ip6Address= ssid=TMOBILE-F5B1_EXT_5G Aug 27 19:39:14 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:14.723-04:00 level=ERROR msg="failed to read message" component=conn/ws remoteAddr=192.168.12.7:59991 error="read tcp 192.168.12.60:7331->192.168.12.7:59991: read: connection reset by peer" Aug 27 19:39:14 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:14.723-04:00 level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=192.168.12.7:59991 Aug 27 19:39:14 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:14.723-04:00 level=INFO msg="connection to address closed" component=conn/multi addr=192.168.12.7:59991 Aug 27 19:39:15 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: wizard , reportWirelessConnection Aug 27 19:39:15 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessInfo Aug 27 19:39:15 volumio5678 sudo[3151]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 19:39:15 volumio5678 sudo[3151]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:15 volumio5678 sudo[3151]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:15 volumio5678 sudo[3155]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Aug 27 19:39:15 volumio5678 sudo[3155]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:15 volumio5678 sudo[3155]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:15 volumio5678 avahi-daemon[3130]: Server startup complete. Host name is volumio5678.local. Local service cookie is 3323711616. Aug 27 19:39:15 volumio5678 ntpd[1204]: IO: Listen normally on 4 wlan0 192.168.12.60:123 Aug 27 19:39:15 volumio5678 ntpd[1204]: IO: new interface(s) found: waking up resolver Aug 27 19:39:16 volumio5678 avahi-daemon[3130]: Service "Volumio5678" (/services/volumio.service) successfully established. Aug 27 19:39:16 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:16.518-04:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 27 19:39:16 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:16.779-04:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.12.7:60591 Aug 27 19:39:16 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:16.799-04:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.12.7:60591 @ 0x208e2d0" latency=89.706797ms timeout=10s Aug 27 19:39:16 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:16.810-04:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.12.7:60591 @ 0x208e2d0" latency=97.161319ms timeout=20s Aug 27 19:39:16 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:16.810-04:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.12.7:60591 @ 0x208e2d0" Aug 27 19:39:16 volumio5678 volumio[1402]: info: Received Get System Info Aug 27 19:39:16 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 19:39:16 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 19:39:16 volumio5678 volumio[1402]: info: Discovery: Getting this device information Aug 27 19:39:16 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:16 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:16 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 19:39:16 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:16.812-04:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.12.7:60591 @ 0x208e2d0" name=Volumio5678 Aug 27 19:39:16 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:16.812-04:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.12.7:60591 @ 0x208e2d0" language=en Aug 27 19:39:16 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Aug 27 19:39:16 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:16.813-04:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.12.7:60591 @ 0x208e2d0" timezone=America/New_York Aug 27 19:39:16 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:16.814-04:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.12.7:60591 @ 0x208e2d0" available=true connected=false macAddress= ip4Address= ip6Address= Aug 27 19:39:16 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:16.816-04:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.12.7:60591 @ 0x208e2d0" available=true connected=true macAddress=2c:cf:67:8c:2c:7f ip4Address=192.168.12.60/24 ip6Address= ssid=TMOBILE-F5B1_EXT_5G Aug 27 19:39:16 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:16.816-04:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.12.7:60591 @ 0x208e2d0" setupComplete=true Aug 27 19:39:16 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Aug 27 19:39:16 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Aug 27 19:39:16 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 19:39:16 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 27 19:39:16 volumio5678 volumio[1402]: amixer -c 0 info | grep "vc4-hdmi-0" Aug 27 19:39:16 volumio5678 volumio[1402]: Card sysdefault:0 'vc4hdmi0'/'vc4-hdmi-0' Aug 27 19:39:16 volumio5678 volumio[1402]: amixer -c 1 info | grep "vc4-hdmi-1" Aug 27 19:39:16 volumio5678 volumio[1402]: Card sysdefault:1 'vc4hdmi1'/'vc4-hdmi-1' Aug 27 19:39:16 volumio5678 volumio[1402]: amixer -c 2 info | grep "snd_rpi_hifiberry_dacplus" Aug 27 19:39:16 volumio5678 volumio[1402]: Card sysdefault:2 'sndrpihifiberry'/'snd_rpi_hifiberry_dacplus' Aug 27 19:39:16 volumio5678 volumio[1402]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 2 Aug 27 19:39:16 volumio5678 volumio[1402]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 27 19:39:16 volumio5678 volumio[1402]: {"cmd":"/usr/local/bin/alsacap -C 2","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 2\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Aug 27 19:39:16 volumio5678 volumio[1402]: amixer -c 2 info | grep "HiFiBerry DAC Plus [Pi5]" Aug 27 19:39:16 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:16.867-04:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.12.7:60591 @ 0x208e2d0" selectedOutputId=2 Aug 27 19:39:16 volumio5678 volumio[1402]: info: Received Get System Info Aug 27 19:39:16 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 19:39:16 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 19:39:16 volumio5678 volumio[1402]: info: Discovery: Getting this device information Aug 27 19:39:16 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:16 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:16 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 19:39:16 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:16.904-04:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.12.7:60591 @ 0x208e2d0" currentVersion=4.119 latestVersion=4.119 Aug 27 19:39:16 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:16.904-04:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.12.7:60591 @ 0x208e2d0" status=UPDATE_STATUS_NONE progress=0 Aug 27 19:39:16 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:16.904-04:00 level=INFO msg="emitting user changed event" component=server peer="192.168.12.7:60591 @ 0x208e2d0" userId=Uvf9JXV3r0QeaAm3GBOnTCAmReN2 Aug 27 19:39:16 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:16.905-04:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.12.7:60591 @ 0x208e2d0" providers=9 Aug 27 19:39:16 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:16.905-04:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.12.7:60591 @ 0x208e2d0" plugins=71 Aug 27 19:39:16 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:16 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:16 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:16.907-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.12.7:60591 @ 0x208e2d0" state=STATUS_STOPPED positionMs=0 volume=68 Aug 27 19:39:16 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:16.907-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.12.7:60591 @ 0x208e2d0" id="mnt/USB/8AD3-EF4F/Bruce Cockburn/Waiting for a Miracle- Singles 1970-1987 Disc 1/01 Going to the Country.wav" title="Track 1" Aug 27 19:39:17 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:17.070-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.12.7:60591 @ 0x208e2d0" latency=89.706797ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=270.558567ms Aug 27 19:39:17 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:17.088-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.12.7:60591 @ 0x208e2d0" latency=89.706797ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=288.112966ms Aug 27 19:39:17 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:17.108-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.12.7:60591 @ 0x208e2d0" latency=89.706797ms timeout=10s endpoint=https://securetoken.googleapis.com duration=307.743572ms Aug 27 19:39:17 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:17.108-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.12.7:60591 @ 0x208e2d0" latency=89.706797ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=308.081885ms Aug 27 19:39:17 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:17.117-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.12.7:60591 @ 0x208e2d0" latency=89.706797ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=317.508488ms Aug 27 19:39:17 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:17.127-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.12.7:60591 @ 0x208e2d0" latency=89.706797ms timeout=10s endpoint=https://www.googleapis.com duration=326.725462ms Aug 27 19:39:17 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:17.129-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.12.7:60591 @ 0x208e2d0" latency=89.706797ms timeout=10s endpoint=https://functions.volumio.cloud duration=329.377425ms Aug 27 19:39:17 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:17.157-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.12.7:60591 @ 0x208e2d0" latency=89.706797ms timeout=10s endpoint=http://pushupdates.volumio.org duration=357.224273ms Aug 27 19:39:17 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:17.248-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.12.7:60591 @ 0x208e2d0" latency=89.706797ms timeout=10s endpoint=http://plugins.volumio.org duration=447.846471ms Aug 27 19:39:17 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:17.330-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.12.7:60591 @ 0x208e2d0" latency=89.706797ms timeout=10s endpoint=http://cddb.volumio.org duration=530.143282ms Aug 27 19:39:17 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:17.528-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.12.7:60591 @ 0x208e2d0" latency=89.706797ms timeout=10s endpoint=https://google.com duration=727.926954ms Aug 27 19:39:17 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:17.790-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.12.7:60591 @ 0x208e2d0" latency=89.706797ms timeout=10s endpoint=https://database.volumio.cloud duration=989.831616ms Aug 27 19:39:17 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:17.828-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.12.7:60591 @ 0x208e2d0" latency=89.706797ms timeout=10s endpoint=https://functions.volumio.cloud duration=1.027508119s Aug 27 19:39:19 volumio5678 volumio[1402]: info: Discovery: Restarting Advertising Aug 27 19:39:20 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: upnp , onRestart Aug 27 19:39:20 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: network , onNetworkingRestart Aug 27 19:39:20 volumio5678 volumio[1402]: info: Refreshing Cached IP Addresses Aug 27 19:39:20 volumio5678 sudo[3189]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/killall upmpdcli Aug 27 19:39:20 volumio5678 sudo[3189]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:20 volumio5678 sudo[3191]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 27 19:39:20 volumio5678 sudo[3191]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:20 volumio5678 sudo[3191]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:20 volumio5678 sudo[3193]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 19:39:20 volumio5678 sudo[3193]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:20 volumio5678 sudo[3189]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:20 volumio5678 sudo[3193]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:20 volumio5678 sudo[3201]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 27 19:39:20 volumio5678 sudo[3201]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:20 volumio5678 sudo[3201]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:20 volumio5678 sudo[3203]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 19:39:20 volumio5678 sudo[3203]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:20 volumio5678 sudo[3203]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:20 volumio5678 volumio[1402]: verbose: New Socket.io Connection to 192.168.12.60 from 192.168.12.7 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Engine version: 3 Transport: polling Total Clients: 7 Aug 27 19:39:20 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 27 19:39:20 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 27 19:39:20 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetVisibleSources Aug 27 19:39:20 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 19:39:20 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:20 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:20 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 27 19:39:20 volumio5678 volumio[1402]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 27 19:39:20 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 27 19:39:20 volumio5678 volumio[1402]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Aug 27 19:39:20 volumio5678 volumio[1402]: info: Received Get System Info Aug 27 19:39:20 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 19:39:20 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 19:39:20 volumio5678 volumio[1402]: info: Discovery: Getting this device information Aug 27 19:39:20 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:20 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:20 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 19:39:20 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:20 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:20 volumio5678 volumio[1402]: info: Listing playlists Aug 27 19:39:20 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 27 19:39:20 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 27 19:39:20 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Aug 27 19:39:21 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Aug 27 19:39:21 volumio5678 sudo[3210]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Aug 27 19:39:21 volumio5678 sudo[3210]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:21 volumio5678 sudo[3210]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:21 volumio5678 sudo[3215]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Aug 27 19:39:21 volumio5678 sudo[3215]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:21 volumio5678 sudo[3215]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:21 volumio5678 sudo[3223]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Aug 27 19:39:21 volumio5678 sudo[3223]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:21 volumio5678 sudo[3233]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 27 19:39:21 volumio5678 sudo[3233]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:21 volumio5678 sudo[3227]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Aug 27 19:39:21 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Aug 27 19:39:21 volumio5678 sudo[3227]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:21 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Aug 27 19:39:21 volumio5678 sudo[3233]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:21 volumio5678 sudo[3223]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:21 volumio5678 sudo[3237]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 19:39:21 volumio5678 sudo[3237]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:21 volumio5678 sudo[3237]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:21 volumio5678 sudo[3241]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 27 19:39:21 volumio5678 sudo[3241]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:21 volumio5678 sudo[3227]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:21 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:21.371-04:00 level=INFO msg="new address was allocated" component=ble/conn old=2 new=3 Aug 27 19:39:21 volumio5678 dbus-daemon[1033]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1621 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=1032 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Aug 27 19:39:21 volumio5678 volumio[1402]: info: Volumio Network Manager: Network status updated: 2 Aug 27 19:39:22 volumio5678 sudo[3259]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 27 19:39:22 volumio5678 sudo[3259]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:22 volumio5678 sudo[3259]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:22 volumio5678 sudo[3261]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 19:39:22 volumio5678 sudo[3261]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:22 volumio5678 sudo[3261]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:22 volumio5678 volumio[1402]: verbose: New Socket.io Connection to 192.168.12.60 from 192.168.12.7 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Engine version: 3 Transport: polling Total Clients: 7 Aug 27 19:39:22 volumio5678 sudo[3265]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 27 19:39:22 volumio5678 sudo[3265]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:22 volumio5678 sudo[3265]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:22 volumio5678 sudo[3267]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 19:39:22 volumio5678 sudo[3267]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:22 volumio5678 sudo[3267]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:22 volumio5678 volumio[1402]: verbose: New Socket.io Connection to 192.168.12.60 from 192.168.12.7 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Engine version: 3 Transport: polling Total Clients: 8 Aug 27 19:39:22 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 27 19:39:22 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetVisibleSources Aug 27 19:39:22 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 19:39:22 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:22 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:22 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 27 19:39:22 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 27 19:39:22 volumio5678 volumio[1402]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Aug 27 19:39:22 volumio5678 volumio[1402]: info: Received Get System Info Aug 27 19:39:22 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 19:39:22 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 19:39:22 volumio5678 volumio[1402]: info: Discovery: Getting this device information Aug 27 19:39:22 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:22 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:22 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 19:39:22 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:22 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:22 volumio5678 volumio[1402]: info: Listing playlists Aug 27 19:39:22 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 27 19:39:22 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 27 19:39:22 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 27 19:39:23 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:23 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:24 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Aug 27 19:39:24 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 27 19:39:24 volumio5678 volumio[1402]: info: Received Get System Info Aug 27 19:39:24 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 19:39:24 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 19:39:24 volumio5678 volumio[1402]: info: Discovery: Getting this device information Aug 27 19:39:24 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:24 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:24 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 19:39:24 volumio5678 volumio[1402]: info: Discovery: Started advertising with name: Volumio5678 Aug 27 19:39:25 volumio5678 sudo[3241]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:25 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 27 19:39:25 volumio5678 volumio[1402]: info: Received Get System Info Aug 27 19:39:25 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 19:39:25 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 19:39:25 volumio5678 volumio[1402]: info: Discovery: Getting this device information Aug 27 19:39:25 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:25 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:25 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 19:39:25 volumio5678 volumio[1402]: info: Executing endpoint metavolumio Aug 27 19:39:25 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Aug 27 19:39:25 volumio5678 volumio[1402]: info: Executing endpoint metavolumio Aug 27 19:39:25 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Aug 27 19:39:25 volumio5678 volumio[1402]: info: Executing endpoint metavolumio Aug 27 19:39:25 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Aug 27 19:39:25 volumio5678 volumio[1402]: info: Received Get System Info Aug 27 19:39:25 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 19:39:25 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 19:39:25 volumio5678 volumio[1402]: info: Discovery: Getting this device information Aug 27 19:39:25 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:25 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:25 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 19:39:25 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 27 19:39:25 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 27 19:39:25 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:25.601-04:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.12.7:60591,00:00:00:00:00:00%02 @ 0x208e2d0" available=true connected=true macAddress=2c:cf:67:8c:2c:7f ip4Address=192.168.12.60/24 ip6Address= ssid=TMOBILE-F5B1_EXT_5G Aug 27 19:39:25 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 19:39:25 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 19:39:25 volumio5678 volumio[1402]: info: Discovery: Getting this device information Aug 27 19:39:25 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:25 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:25 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 19:39:25 volumio5678 volumio[1402]: verbose: New Socket.io Connection to 192.168.12.60:3000 from 192.168.12.7 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Aug 27 19:39:25 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 27 19:39:25 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 27 19:39:25 volumio5678 volumio[1402]: info: Discovery: adding c0fbf0c4-32cd-4bf1-87ea-a490540ef4db Aug 27 19:39:25 volumio5678 volumio[1402]: info: Discovery: Found device Volumio5678 Aug 27 19:39:25 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:25 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:25 volumio5678 volumio[1402]: info: Discovery: this is already registered, c0fbf0c4-32cd-4bf1-87ea-a490540ef4db Aug 27 19:39:25 volumio5678 volumio[1402]: info: Discovery: Found device Volumio5678 Aug 27 19:39:25 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:25 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:26 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:26.586-04:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 27 19:39:27 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetQueue Aug 27 19:39:27 volumio5678 volumio[1402]: info: CoreStateMachine::getQueue Aug 27 19:39:27 volumio5678 volumio[1402]: info: CorePlayQueue::getQueue Aug 27 19:39:27 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 19:39:27 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 19:39:27 volumio5678 volumio[1402]: info: Discovery: Getting this device information Aug 27 19:39:27 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:27 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:27 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 19:39:27 volumio5678 volumio[1402]: verbose: New Socket.io Connection to 192.168.12.60:3000 from 192.168.12.7 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Aug 27 19:39:27 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 27 19:39:27 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 27 19:39:30 volumio5678 sudo[3275]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 27 19:39:30 volumio5678 sudo[3275]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:30 volumio5678 sudo[3277]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 19:39:30 volumio5678 sudo[3277]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:30 volumio5678 sudo[3277]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:30 volumio5678 sudo[3275]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:30 volumio5678 sudo[3281]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 27 19:39:30 volumio5678 sudo[3281]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:30 volumio5678 sudo[3281]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:30 volumio5678 volumio[1402]: info: Upmpdcli Daemon Started Aug 27 19:39:32 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Aug 27 19:39:32 volumio5678 volumio[1402]: error: Failed request for metavolumio API Aug 27 19:39:32 volumio5678 volumio[1402]: error: Failed request for metavolumio API Aug 27 19:39:32 volumio5678 volumio[1402]: error: Failed request for metavolumio API Aug 27 19:39:40 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:40.728-04:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.12.7:60591,00:00:00:00:00:00%02 @ 0x208e2d0" latency=96.273958ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Aug 27 19:39:40 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:40.744-04:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.12.7:60591,00:00:00:00:00:00%02 @ 0x208e2d0" latency=89.176825ms timeout=10s Aug 27 19:39:40 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:40.788-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.12.7:60591,00:00:00:00:00:00%02 @ 0x208e2d0" latency=89.176825ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=44.031163ms Aug 27 19:39:40 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:40.799-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.12.7:60591,00:00:00:00:00:00%02 @ 0x208e2d0" latency=89.176825ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=54.656998ms Aug 27 19:39:40 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:40.799-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.12.7:60591,00:00:00:00:00:00%02 @ 0x208e2d0" latency=89.176825ms timeout=10s endpoint=https://securetoken.googleapis.com duration=54.863127ms Aug 27 19:39:40 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:40.805-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.12.7:60591,00:00:00:00:00:00%02 @ 0x208e2d0" latency=89.176825ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=61.251213ms Aug 27 19:39:40 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:40.808-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.12.7:60591,00:00:00:00:00:00%02 @ 0x208e2d0" latency=89.176825ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=64.289507ms Aug 27 19:39:40 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:40.820-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.12.7:60591,00:00:00:00:00:00%02 @ 0x208e2d0" latency=89.176825ms timeout=10s endpoint=https://functions.volumio.cloud duration=76.25887ms Aug 27 19:39:40 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:40.831-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.12.7:60591,00:00:00:00:00:00%02 @ 0x208e2d0" latency=89.176825ms timeout=10s endpoint=https://functions.volumio.cloud duration=86.593911ms Aug 27 19:39:40 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:40.889-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.12.7:60591,00:00:00:00:00:00%02 @ 0x208e2d0" latency=89.176825ms timeout=10s endpoint=http://pushupdates.volumio.org duration=145.419658ms Aug 27 19:39:40 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:40.909-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.12.7:60591,00:00:00:00:00:00%02 @ 0x208e2d0" latency=89.176825ms timeout=10s endpoint=https://www.googleapis.com duration=164.944618ms Aug 27 19:39:40 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:40.997-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.12.7:60591,00:00:00:00:00:00%02 @ 0x208e2d0" latency=89.176825ms timeout=10s endpoint=https://database.volumio.cloud duration=253.379832ms Aug 27 19:39:41 volumio5678 sudo[3298]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 27 19:39:41 volumio5678 sudo[3298]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:41 volumio5678 sudo[3298]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:41 volumio5678 sudo[3300]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 19:39:41 volumio5678 sudo[3300]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:41 volumio5678 sudo[3300]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:41 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:41.021-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.12.7:60591,00:00:00:00:00:00%02 @ 0x208e2d0" latency=89.176825ms timeout=10s endpoint=http://plugins.volumio.org duration=276.699414ms Aug 27 19:39:41 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:41.057-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.12.7:60591,00:00:00:00:00:00%02 @ 0x208e2d0" latency=89.176825ms timeout=10s endpoint=http://cddb.volumio.org duration=312.851945ms Aug 27 19:39:41 volumio5678 volumio[1402]: verbose: New Socket.io Connection to 192.168.12.60 from 192.168.12.7 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Engine version: 3 Transport: polling Total Clients: 9 Aug 27 19:39:41 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 27 19:39:41 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetVisibleSources Aug 27 19:39:41 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 19:39:41 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:41 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:41 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 27 19:39:41 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 27 19:39:41 volumio5678 volumio[1402]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Aug 27 19:39:41 volumio5678 volumio[1402]: info: Received Get System Info Aug 27 19:39:41 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 19:39:41 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 19:39:41 volumio5678 volumio[1402]: info: Discovery: Getting this device information Aug 27 19:39:41 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:41 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:41 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 19:39:41 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:41 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:41 volumio5678 volumio[1402]: info: Listing playlists Aug 27 19:39:41 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 27 19:39:41 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 27 19:39:41 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 27 19:39:41 volumio5678 volumio5-onboarding[1621]: time=2026-08-27T19:39:41.273-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.12.7:60591,00:00:00:00:00:00%02 @ 0x208e2d0" latency=89.176825ms timeout=10s endpoint=https://google.com duration=528.808457ms Aug 27 19:39:41 volumio5678 sudo[3304]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 27 19:39:41 volumio5678 sudo[3304]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:41 volumio5678 sudo[3304]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:41 volumio5678 sudo[3306]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 19:39:41 volumio5678 sudo[3306]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:39:41 volumio5678 sudo[3306]: pam_unix(sudo:session): session closed for user root Aug 27 19:39:41 volumio5678 volumio[1402]: verbose: New Socket.io Connection to 192.168.12.60 from 192.168.12.7 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Engine version: 3 Transport: polling Total Clients: 9 Aug 27 19:39:41 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 27 19:39:41 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 27 19:39:41 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetVisibleSources Aug 27 19:39:41 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 19:39:41 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:41 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:41 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 27 19:39:41 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 27 19:39:41 volumio5678 volumio[1402]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Aug 27 19:39:41 volumio5678 volumio[1402]: info: Received Get System Info Aug 27 19:39:41 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 19:39:41 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 19:39:41 volumio5678 volumio[1402]: info: Discovery: Getting this device information Aug 27 19:39:41 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:41 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:41 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 19:39:41 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:41 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:41 volumio5678 volumio[1402]: info: Listing playlists Aug 27 19:39:41 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 27 19:39:41 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 27 19:39:42 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:42 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:43 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Aug 27 19:39:43 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 27 19:39:43 volumio5678 volumio[1402]: info: Received Get System Info Aug 27 19:39:43 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 19:39:43 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 19:39:43 volumio5678 volumio[1402]: info: Discovery: Getting this device information Aug 27 19:39:43 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:43 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:43 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 19:39:43 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 27 19:39:43 volumio5678 volumio[1402]: info: Received Get System Info Aug 27 19:39:43 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 19:39:43 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 19:39:43 volumio5678 volumio[1402]: info: Discovery: Getting this device information Aug 27 19:39:43 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:43 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:43 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 19:39:44 volumio5678 volumio[1402]: info: Executing endpoint metavolumio Aug 27 19:39:44 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Aug 27 19:39:44 volumio5678 volumio[1402]: info: Executing endpoint metavolumio Aug 27 19:39:44 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Aug 27 19:39:44 volumio5678 volumio[1402]: info: Executing endpoint metavolumio Aug 27 19:39:44 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Aug 27 19:39:45 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetQueue Aug 27 19:39:45 volumio5678 volumio[1402]: info: CoreStateMachine::getQueue Aug 27 19:39:45 volumio5678 volumio[1402]: info: CorePlayQueue::getQueue Aug 27 19:39:51 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Aug 27 19:39:51 volumio5678 volumio[1402]: error: Failed request for metavolumio API Aug 27 19:39:51 volumio5678 volumio[1402]: error: Failed request for metavolumio API Aug 27 19:39:51 volumio5678 volumio[1402]: error: Failed request for metavolumio API Aug 27 19:39:53 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:53 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:55 volumio5678 volumio[1402]: info: Executing endpoint metavolumio Aug 27 19:39:55 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Aug 27 19:39:55 volumio5678 volumio[1402]: info: Executing endpoint metavolumio Aug 27 19:39:55 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Aug 27 19:39:55 volumio5678 volumio[1402]: info: Executing endpoint metavolumio Aug 27 19:39:55 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Aug 27 19:39:59 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 27 19:39:59 volumio5678 volumio[1402]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Aug 27 19:39:59 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Aug 27 19:39:59 volumio5678 volumio[1402]: info: Received Get System Version Aug 27 19:39:59 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 27 19:39:59 volumio5678 volumio[1402]: info: Received Get System Info Aug 27 19:39:59 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 19:39:59 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 19:39:59 volumio5678 volumio[1402]: info: Discovery: Getting this device information Aug 27 19:39:59 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:39:59 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:39:59 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 19:40:02 volumio5678 volumio[1402]: error: Failed request for metavolumio API Aug 27 19:40:02 volumio5678 volumio[1402]: error: Failed request for metavolumio API Aug 27 19:40:02 volumio5678 volumio[1402]: error: Failed request for metavolumio API Aug 27 19:40:03 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:40:03 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:40:05 volumio5678 volumio[1402]: info: Executing endpoint metavolumio Aug 27 19:40:05 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Aug 27 19:40:05 volumio5678 volumio[1402]: info: Executing endpoint metavolumio Aug 27 19:40:05 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Aug 27 19:40:05 volumio5678 volumio[1402]: info: Executing endpoint metavolumio Aug 27 19:40:05 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Aug 27 19:40:08 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 27 19:40:08 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 27 19:40:13 volumio5678 volumio[1402]: error: Failed request for metavolumio API Aug 27 19:40:13 volumio5678 volumio[1402]: error: Failed request for metavolumio API Aug 27 19:40:13 volumio5678 volumio[1402]: error: Failed request for metavolumio API Aug 27 19:40:17 volumio5678 volumio[1402]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 27 19:40:33 volumio5678 volumio[1402]: info: Received OAUTH Data Aug 27 19:40:33 volumio5678 volumio[1402]: info: Executing Spotify Oauth Login Aug 27 19:40:33 volumio5678 volumio[1402]: info: Saving Spotify Refresh Token Aug 27 19:40:33 volumio5678 sudo[3403]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 27 19:40:33 volumio5678 sudo[3403]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:40:33 volumio5678 sudo[3403]: pam_unix(sudo:session): session closed for user root Aug 27 19:40:33 volumio5678 sudo[3405]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 19:40:33 volumio5678 sudo[3405]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:40:33 volumio5678 sudo[3405]: pam_unix(sudo:session): session closed for user root Aug 27 19:40:33 volumio5678 volumio[1402]: verbose: New Socket.io Connection to 192.168.12.60 from 192.168.12.7 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Engine version: 3 Transport: polling Total Clients: 9 Aug 27 19:40:33 volumio5678 volumio[1402]: info: New Spotify access tokenBQACcQTTcF... Aug 27 19:40:33 volumio5678 volumio[1402]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 27 19:40:33 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 27 19:40:33 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetVisibleSources Aug 27 19:40:33 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 19:40:33 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:40:33 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:40:33 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 27 19:40:33 volumio5678 volumio[1402]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 27 19:40:33 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 27 19:40:33 volumio5678 volumio[1402]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Aug 27 19:40:33 volumio5678 volumio[1402]: info: Received Get System Info Aug 27 19:40:33 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 19:40:33 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 19:40:33 volumio5678 volumio[1402]: info: Discovery: Getting this device information Aug 27 19:40:33 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:40:33 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:40:33 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 19:40:33 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:40:33 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:40:33 volumio5678 volumio[1402]: info: Listing playlists Aug 27 19:40:33 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 27 19:40:33 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 27 19:40:33 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 27 19:40:33 volumio5678 volumio[1402]: SPOTIFY: User informations: {"account_id":"kU83tOGybA","country":"US","display_name":"markbrid1","email":"markbrid@embarqmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/markbrid1"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/markbrid1","id":"markbrid1","images":[],"product":"premium","type":"user","uri":"spotify:user:markbrid1"} Aug 27 19:40:33 volumio5678 volumio[1402]: info: Creating Spotify config file Aug 27 19:40:33 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:40:33 volumio5678 volumio[1402]: info: Spotify config file written Aug 27 19:40:33 volumio5678 sudo[3409]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 27 19:40:33 volumio5678 sudo[3409]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:40:33 volumio5678 systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Aug 27 19:40:33 volumio5678 systemd[1]: go-librespot-daemon.service: Deactivated successfully. Aug 27 19:40:33 volumio5678 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 27 19:40:33 volumio5678 volumio[1402]: info: Connection to go-librespot Websocket closed Aug 27 19:40:33 volumio5678 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 27 19:40:33 volumio5678 go-librespot[3411]: go-librespot daemon starting... Aug 27 19:40:33 volumio5678 sudo[3409]: pam_unix(sudo:session): session closed for user root Aug 27 19:40:33 volumio5678 go-librespot[3412]: time="2026-08-27T19:40:33-04:00" level=info msg="running go-librespot 0.7.1" Aug 27 19:40:33 volumio5678 go-librespot[3412]: time="2026-08-27T19:40:33-04:00" level=debug msg="app state loaded" Aug 27 19:40:33 volumio5678 go-librespot[3412]: time="2026-08-27T19:40:33-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 27 19:40:33 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 27 19:40:33 volumio5678 volumio[1402]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Aug 27 19:40:33 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Aug 27 19:40:33 volumio5678 volumio[1402]: info: Received Get System Version Aug 27 19:40:33 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 27 19:40:33 volumio5678 volumio[1402]: info: Received Get System Info Aug 27 19:40:33 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 19:40:33 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 19:40:33 volumio5678 volumio[1402]: info: Discovery: Getting this device information Aug 27 19:40:33 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:40:33 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:40:33 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 19:40:33 volumio5678 go-librespot[3412]: time="2026-08-27T19:40:33-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Aug 27 19:40:33 volumio5678 go-librespot[3412]: time="2026-08-27T19:40:33-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 27 19:40:33 volumio5678 go-librespot[3412]: time="2026-08-27T19:40:33-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 27 19:40:33 volumio5678 go-librespot[3412]: time="2026-08-27T19:40:33-04:00" level=info msg="zeroconf server listening on port 46429" Aug 27 19:40:33 volumio5678 go-librespot[3412]: time="2026-08-27T19:40:33-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 27 19:40:33 volumio5678 volumio[1402]: info: New Spotify access tokenBQCzhm2WtH... Aug 27 19:40:33 volumio5678 volumio[1402]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 27 19:40:34 volumio5678 go-librespot[3412]: time="2026-08-27T19:40:34-04:00" level=debug msg="obtained new client token: AAGPsI+F/Fxl0zDLY7iKI4M6EeZgHUn9ZkrKel7kkygNDox0K6xnmp1LKU0iy376MJjB6suXg1wIC8hmLfLiaz81cq0AlGcGXD91fwFprVgCjxH/xQfQBa+wk3VPJssRKYIB+mPqseftPUvmYTzYHIeM2SO2fKTv9n8GzkSTO2AhowtfTHS2gSG1DfovfgsPGRLGP6oyQ5l1XaIrd/v73ItnVpxI/JCH3e7J+ZlefWc3NaF76NkKcgs=" Aug 27 19:40:34 volumio5678 volumio[1402]: SPOTIFY: User informations: {"account_id":"kU83tOGybA","country":"US","display_name":"markbrid1","email":"markbrid@embarqmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/markbrid1"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/markbrid1","id":"markbrid1","images":[],"product":"premium","type":"user","uri":"spotify:user:markbrid1"} Aug 27 19:40:34 volumio5678 volumio[1402]: info: Spotify Successfully logged in Aug 27 19:40:34 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 27 19:40:34 volumio5678 volumio[1402]: info: [1787874034196] CoreMusicLibrary::Adding element Spotify Aug 27 19:40:34 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 19:40:34 volumio5678 go-librespot[3412]: time="2026-08-27T19:40:34-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 27 19:40:34 volumio5678 volumio[1402]: Cannot find translation for source Spotify Aug 27 19:40:34 volumio5678 go-librespot[3412]: time="2026-08-27T19:40:34-04:00" level=debug msg="completed keyexchange" Aug 27 19:40:34 volumio5678 go-librespot[3412]: time="2026-08-27T19:40:34-04:00" level=debug msg="completed challenge" Aug 27 19:40:34 volumio5678 go-librespot[3412]: time="2026-08-27T19:40:34-04:00" level=info msg="authenticated AP" username="ma*****d1" Aug 27 19:40:34 volumio5678 go-librespot[3412]: time="2026-08-27T19:40:34-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 27 19:40:34 volumio5678 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 19:40:34 volumio5678 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 19:40:35 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Aug 27 19:40:35 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 27 19:40:35 volumio5678 volumio[1402]: info: Received Get System Info Aug 27 19:40:35 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 19:40:35 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 19:40:35 volumio5678 volumio[1402]: info: Discovery: Getting this device information Aug 27 19:40:35 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:40:35 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:40:35 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 19:40:35 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 27 19:40:35 volumio5678 volumio[1402]: info: Received Get System Info Aug 27 19:40:35 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 19:40:35 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 19:40:35 volumio5678 volumio[1402]: info: Discovery: Getting this device information Aug 27 19:40:35 volumio5678 volumio[1402]: info: CoreCommandRouter::volumioGetState Aug 27 19:40:35 volumio5678 volumio[1402]: info: CorePlayQueue::getTrack 0 Aug 27 19:40:35 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 19:40:36 volumio5678 volumio[1402]: info: Initializing connection to go-librespot Websocket Aug 27 19:40:36 volumio5678 volumio[1402]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 27 19:40:36 volumio5678 volumio[1402]: info: go-librespot daemon successfully initialized Aug 27 19:40:37 volumio5678 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 27 19:40:37 volumio5678 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 27 19:40:37 volumio5678 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 27 19:40:37 volumio5678 go-librespot[3422]: go-librespot daemon starting... Aug 27 19:40:37 volumio5678 go-librespot[3423]: time="2026-08-27T19:40:37-04:00" level=info msg="running go-librespot 0.7.1" Aug 27 19:40:37 volumio5678 go-librespot[3423]: time="2026-08-27T19:40:37-04:00" level=debug msg="app state loaded" Aug 27 19:40:37 volumio5678 go-librespot[3423]: time="2026-08-27T19:40:37-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 27 19:40:37 volumio5678 go-librespot[3423]: time="2026-08-27T19:40:37-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 27 19:40:37 volumio5678 go-librespot[3423]: time="2026-08-27T19:40:37-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 27 19:40:37 volumio5678 go-librespot[3423]: time="2026-08-27T19:40:37-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 27 19:40:37 volumio5678 go-librespot[3423]: time="2026-08-27T19:40:37-04:00" level=info msg="zeroconf server listening on port 37187" Aug 27 19:40:37 volumio5678 go-librespot[3423]: time="2026-08-27T19:40:37-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 27 19:40:38 volumio5678 go-librespot[3423]: time="2026-08-27T19:40:38-04:00" level=debug msg="obtained new client token: AAFp8+9OPo/ozr8gQ2d56MIRTsU12otSfHqhcSqAes9dRRlP23pPYJYUwdHQHs9pC9iuPf8ES7cvzn1uKDMPr+7bPri9VwrjdcELK6Ne1IIUm3pMCFZkdVSIwrpf5SIhZLG0rdfUfR2ZLu1lfFpBIL26qzMaZDh4UIU02YK7s+xtadCtB1yGJKgRQYkMZgg7MJt0mwVKnGGl6XvxCD2blZ3+qySBwiKxZaHmtYrEvP15ibA9OOfHZC4=" Aug 27 19:40:38 volumio5678 go-librespot[3423]: time="2026-08-27T19:40:38-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 27 19:40:38 volumio5678 go-librespot[3423]: time="2026-08-27T19:40:38-04:00" level=debug msg="completed keyexchange" Aug 27 19:40:38 volumio5678 go-librespot[3423]: time="2026-08-27T19:40:38-04:00" level=debug msg="completed challenge" Aug 27 19:40:38 volumio5678 go-librespot[3423]: time="2026-08-27T19:40:38-04:00" level=info msg="authenticated AP" username="ma*****d1" Aug 27 19:40:38 volumio5678 go-librespot[3423]: time="2026-08-27T19:40:38-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 27 19:40:38 volumio5678 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 19:40:38 volumio5678 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 19:40:39 volumio5678 volumio[1402]: info: Initializing connection to go-librespot Websocket Aug 27 19:40:39 volumio5678 volumio[1402]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 27 19:40:39 volumio5678 volumio[1402]: info: Initializing connection to go-librespot Websocket Aug 27 19:40:39 volumio5678 volumio[1402]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 27 19:40:40 volumio5678 volumio[1402]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Aug 27 19:40:40 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Aug 27 19:40:40 volumio5678 volumio[1402]: info: Creating Spotify config file Aug 27 19:40:40 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:40:40 volumio5678 volumio[1402]: info: Spotify config file written Aug 27 19:40:40 volumio5678 sudo[3433]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 27 19:40:40 volumio5678 sudo[3433]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:40:40 volumio5678 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 27 19:40:40 volumio5678 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 27 19:40:40 volumio5678 go-librespot[3435]: go-librespot daemon starting... Aug 27 19:40:40 volumio5678 sudo[3433]: pam_unix(sudo:session): session closed for user root Aug 27 19:40:40 volumio5678 go-librespot[3436]: time="2026-08-27T19:40:40-04:00" level=info msg="running go-librespot 0.7.1" Aug 27 19:40:40 volumio5678 go-librespot[3436]: time="2026-08-27T19:40:40-04:00" level=debug msg="app state loaded" Aug 27 19:40:40 volumio5678 go-librespot[3436]: time="2026-08-27T19:40:40-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 27 19:40:40 volumio5678 go-librespot[3436]: time="2026-08-27T19:40:40-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 27 19:40:40 volumio5678 go-librespot[3436]: time="2026-08-27T19:40:40-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 27 19:40:40 volumio5678 go-librespot[3436]: time="2026-08-27T19:40:40-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 27 19:40:40 volumio5678 go-librespot[3436]: time="2026-08-27T19:40:40-04:00" level=info msg="zeroconf server listening on port 39257" Aug 27 19:40:40 volumio5678 go-librespot[3436]: time="2026-08-27T19:40:40-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 27 19:40:40 volumio5678 go-librespot[3436]: time="2026-08-27T19:40:40-04:00" level=debug msg="obtained new client token: AAFdJz0FPlgORI2Z+TnVa007dVB2moP9lGFWvHaELbdnVcKpFabdPG9b5RQMavqj37vJG1v1H8Zl8tc+eTMAM3M/d27+6nkIq/q/zqd9/Eoixx8JlPGf4QeO/WxgdmRTshGFqQAP2/ISVNW9AuZ6xLt0OFnc2B8qk9DTZjyMK4LcmBYTgNLObC0A4KInmy8OLRCU2Sb7D+GUNZJBx6qoT/syAW5aEwQ3hrTKnQYoR4n4qBRtCUvQOop+cg==" Aug 27 19:40:40 volumio5678 go-librespot[3436]: time="2026-08-27T19:40:40-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 27 19:40:40 volumio5678 go-librespot[3436]: time="2026-08-27T19:40:40-04:00" level=debug msg="completed keyexchange" Aug 27 19:40:40 volumio5678 go-librespot[3436]: time="2026-08-27T19:40:40-04:00" level=debug msg="completed challenge" Aug 27 19:40:40 volumio5678 go-librespot[3436]: time="2026-08-27T19:40:40-04:00" level=info msg="authenticated AP" username="ma*****d1" Aug 27 19:40:40 volumio5678 go-librespot[3436]: time="2026-08-27T19:40:40-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 27 19:40:40 volumio5678 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 19:40:40 volumio5678 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 19:40:42 volumio5678 volumio[1402]: info: Initializing connection to go-librespot Websocket Aug 27 19:40:42 volumio5678 volumio[1402]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 27 19:40:43 volumio5678 volumio[1402]: info: go-librespot daemon successfully initialized Aug 27 19:40:43 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Aug 27 19:40:43 volumio5678 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 27 19:40:43 volumio5678 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 27 19:40:43 volumio5678 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 27 19:40:43 volumio5678 go-librespot[3459]: go-librespot daemon starting... Aug 27 19:40:43 volumio5678 go-librespot[3460]: time="2026-08-27T19:40:43-04:00" level=info msg="running go-librespot 0.7.1" Aug 27 19:40:43 volumio5678 go-librespot[3460]: time="2026-08-27T19:40:43-04:00" level=debug msg="app state loaded" Aug 27 19:40:43 volumio5678 go-librespot[3460]: time="2026-08-27T19:40:43-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 27 19:40:44 volumio5678 go-librespot[3460]: time="2026-08-27T19:40:44-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 27 19:40:44 volumio5678 go-librespot[3460]: time="2026-08-27T19:40:44-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 27 19:40:44 volumio5678 go-librespot[3460]: time="2026-08-27T19:40:44-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 27 19:40:44 volumio5678 go-librespot[3460]: time="2026-08-27T19:40:44-04:00" level=info msg="zeroconf server listening on port 45701" Aug 27 19:40:44 volumio5678 go-librespot[3460]: time="2026-08-27T19:40:44-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 27 19:40:44 volumio5678 go-librespot[3460]: time="2026-08-27T19:40:44-04:00" level=debug msg="obtained new client token: AAEL/caZMQqh3IDAG4M4LcruWXb7PWy0KfvacFn/ZWdW24hyGpuGwAQLJQmD7Exx4J035okx8WChJJvWcBG4bicN9p6ue0m0UsluB1Q6UovHqQ8U35SA4+LRj/sI7EhiMwBV2F/a9c0rG6siVYLUNcROJAWb1N2TNwmL/HfQyxZcyfDr8XpX7W10gMGGc28wLqcHIaQpIKL2OOqMVblu6UxlwiRWd0bcOpqKzJXJXmArE86FKjUhGS1J1A==" Aug 27 19:40:44 volumio5678 go-librespot[3460]: time="2026-08-27T19:40:44-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 27 19:40:44 volumio5678 go-librespot[3460]: time="2026-08-27T19:40:44-04:00" level=debug msg="completed keyexchange" Aug 27 19:40:44 volumio5678 go-librespot[3460]: time="2026-08-27T19:40:44-04:00" level=debug msg="completed challenge" Aug 27 19:40:44 volumio5678 go-librespot[3460]: time="2026-08-27T19:40:44-04:00" level=info msg="authenticated AP" username="ma*****d1" Aug 27 19:40:44 volumio5678 go-librespot[3460]: time="2026-08-27T19:40:44-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 27 19:40:44 volumio5678 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 19:40:44 volumio5678 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 19:40:45 volumio5678 volumio[1402]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Aug 27 19:40:45 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Aug 27 19:40:45 volumio5678 volumio[1402]: info: Creating Spotify config file Aug 27 19:40:45 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:40:45 volumio5678 volumio[1402]: info: Spotify config file written Aug 27 19:40:45 volumio5678 sudo[3470]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 27 19:40:45 volumio5678 sudo[3470]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:40:45 volumio5678 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 27 19:40:45 volumio5678 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 27 19:40:45 volumio5678 go-librespot[3472]: go-librespot daemon starting... Aug 27 19:40:45 volumio5678 sudo[3470]: pam_unix(sudo:session): session closed for user root Aug 27 19:40:45 volumio5678 go-librespot[3473]: time="2026-08-27T19:40:45-04:00" level=info msg="running go-librespot 0.7.1" Aug 27 19:40:45 volumio5678 go-librespot[3473]: time="2026-08-27T19:40:45-04:00" level=debug msg="app state loaded" Aug 27 19:40:45 volumio5678 go-librespot[3473]: time="2026-08-27T19:40:45-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 27 19:40:45 volumio5678 volumio[1402]: info: Initializing connection to go-librespot Websocket Aug 27 19:40:45 volumio5678 go-librespot[3473]: time="2026-08-27T19:40:45-04:00" level=debug msg="new websocket client" Aug 27 19:40:45 volumio5678 volumio[1402]: info: Connection to go-librespot Websocket established Aug 27 19:40:45 volumio5678 go-librespot[3473]: time="2026-08-27T19:40:45-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 27 19:40:45 volumio5678 go-librespot[3473]: time="2026-08-27T19:40:45-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 27 19:40:45 volumio5678 go-librespot[3473]: time="2026-08-27T19:40:45-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 27 19:40:45 volumio5678 go-librespot[3473]: time="2026-08-27T19:40:45-04:00" level=info msg="zeroconf server listening on port 46001" Aug 27 19:40:45 volumio5678 go-librespot[3473]: time="2026-08-27T19:40:45-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 27 19:40:46 volumio5678 go-librespot[3473]: time="2026-08-27T19:40:46-04:00" level=debug msg="obtained new client token: AAErSaOrBjGZed3jsxOeUy2W7z+MSlS1Zq00SNOfEvefXktmPan/LXdndDpKpojs3X+lBjdKyu+IVc6PJhZlK74VE8QvS+dD6YSzU694TIyjILisTGXz+UFflmSy0qrQgw6JyZIygxd481ZAwX7r3Od7kmqkopDPScmBWgyskCquFdJvB+SL5QrsNetLLuuant8zW/a/zyhqgiDNyusqgOK9YMCnsE2+8x5w4CaDAI8o8k8cQoCm" Aug 27 19:40:46 volumio5678 go-librespot[3473]: time="2026-08-27T19:40:46-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 27 19:40:46 volumio5678 volumio[1402]: info: Initializing connection to go-librespot Websocket Aug 27 19:40:46 volumio5678 go-librespot[3473]: time="2026-08-27T19:40:46-04:00" level=debug msg="new websocket client" Aug 27 19:40:46 volumio5678 volumio[1402]: info: Connection to go-librespot Websocket established Aug 27 19:40:46 volumio5678 go-librespot[3473]: time="2026-08-27T19:40:46-04:00" level=debug msg="completed keyexchange" Aug 27 19:40:46 volumio5678 go-librespot[3473]: time="2026-08-27T19:40:46-04:00" level=debug msg="completed challenge" Aug 27 19:40:46 volumio5678 go-librespot[3473]: time="2026-08-27T19:40:46-04:00" level=info msg="authenticated AP" username="ma*****d1" Aug 27 19:40:46 volumio5678 go-librespot[3473]: time="2026-08-27T19:40:46-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 27 19:40:46 volumio5678 volumio[1402]: info: Connection to go-librespot Websocket closed Aug 27 19:40:46 volumio5678 volumio[1402]: info: Connection to go-librespot Websocket closed Aug 27 19:40:46 volumio5678 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 19:40:46 volumio5678 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 19:40:47 volumio5678 volumio[1402]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Aug 27 19:40:47 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Aug 27 19:40:47 volumio5678 volumio[1402]: info: Creating Spotify config file Aug 27 19:40:47 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:40:47 volumio5678 volumio[1402]: info: Spotify config file written Aug 27 19:40:47 volumio5678 sudo[3483]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 27 19:40:47 volumio5678 sudo[3483]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:40:47 volumio5678 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 27 19:40:47 volumio5678 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 27 19:40:47 volumio5678 go-librespot[3485]: go-librespot daemon starting... Aug 27 19:40:47 volumio5678 sudo[3483]: pam_unix(sudo:session): session closed for user root Aug 27 19:40:47 volumio5678 go-librespot[3486]: time="2026-08-27T19:40:47-04:00" level=info msg="running go-librespot 0.7.1" Aug 27 19:40:47 volumio5678 go-librespot[3486]: time="2026-08-27T19:40:47-04:00" level=debug msg="app state loaded" Aug 27 19:40:47 volumio5678 go-librespot[3486]: time="2026-08-27T19:40:47-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 27 19:40:47 volumio5678 go-librespot[3486]: time="2026-08-27T19:40:47-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Aug 27 19:40:47 volumio5678 go-librespot[3486]: time="2026-08-27T19:40:47-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 27 19:40:47 volumio5678 go-librespot[3486]: time="2026-08-27T19:40:47-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 27 19:40:47 volumio5678 go-librespot[3486]: time="2026-08-27T19:40:47-04:00" level=info msg="zeroconf server listening on port 39229" Aug 27 19:40:47 volumio5678 go-librespot[3486]: time="2026-08-27T19:40:47-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 27 19:40:47 volumio5678 go-librespot[3486]: time="2026-08-27T19:40:47-04:00" level=debug msg="obtained new client token: AAFnFARWM8U2nQ/J6e2kjOFxOFZuJw2LQtF/OC7NpzcFWJGr8ehq1dbK5+56mSY4EYWcYONzc4j2SM4FqijCYrsu8uj1oBfhU+VbEgavUk0AVt0patYZa2u0ZJxPATfGytjN9oet/FVpMD7PgQWOUKRtNXaN+qo+e/RuVAfY2QvfvcDLaQ4VD9VLlTK4hz7wnIGKs0x0jx7GjKymWlUhhfM8JOaGzh4WUkhotKZXgPDouLPOVuIXsRXXuA==" Aug 27 19:40:47 volumio5678 go-librespot[3486]: time="2026-08-27T19:40:47-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 27 19:40:47 volumio5678 go-librespot[3486]: time="2026-08-27T19:40:47-04:00" level=debug msg="completed keyexchange" Aug 27 19:40:47 volumio5678 go-librespot[3486]: time="2026-08-27T19:40:47-04:00" level=debug msg="completed challenge" Aug 27 19:40:47 volumio5678 volumio[1402]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Aug 27 19:40:47 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Aug 27 19:40:47 volumio5678 volumio[1402]: info: Creating Spotify config file Aug 27 19:40:47 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:40:47 volumio5678 volumio[1402]: info: Spotify config file written Aug 27 19:40:47 volumio5678 sudo[3496]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 27 19:40:47 volumio5678 sudo[3496]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:40:47 volumio5678 systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Aug 27 19:40:47 volumio5678 systemd[1]: go-librespot-daemon.service: Killing process 3487 (go-librespot) with signal SIGKILL. Aug 27 19:40:47 volumio5678 systemd[1]: go-librespot-daemon.service: Killing process 3489 (go-librespot) with signal SIGKILL. Aug 27 19:40:47 volumio5678 systemd[1]: go-librespot-daemon.service: Killing process 3491 (go-librespot) with signal SIGKILL. Aug 27 19:40:47 volumio5678 systemd[1]: go-librespot-daemon.service: Deactivated successfully. Aug 27 19:40:47 volumio5678 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 27 19:40:47 volumio5678 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 27 19:40:47 volumio5678 go-librespot[3498]: go-librespot daemon starting... Aug 27 19:40:47 volumio5678 sudo[3496]: pam_unix(sudo:session): session closed for user root Aug 27 19:40:47 volumio5678 go-librespot[3499]: time="2026-08-27T19:40:47-04:00" level=info msg="running go-librespot 0.7.1" Aug 27 19:40:47 volumio5678 go-librespot[3499]: time="2026-08-27T19:40:47-04:00" level=debug msg="app state loaded" Aug 27 19:40:47 volumio5678 go-librespot[3499]: time="2026-08-27T19:40:47-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 27 19:40:47 volumio5678 go-librespot[3499]: time="2026-08-27T19:40:47-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 27 19:40:47 volumio5678 go-librespot[3499]: time="2026-08-27T19:40:47-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 27 19:40:47 volumio5678 go-librespot[3499]: time="2026-08-27T19:40:47-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 27 19:40:47 volumio5678 go-librespot[3499]: time="2026-08-27T19:40:47-04:00" level=info msg="zeroconf server listening on port 39865" Aug 27 19:40:47 volumio5678 go-librespot[3499]: time="2026-08-27T19:40:47-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 27 19:40:47 volumio5678 volumio[1402]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Aug 27 19:40:47 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Aug 27 19:40:47 volumio5678 volumio[1402]: info: Creating Spotify config file Aug 27 19:40:47 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:40:47 volumio5678 volumio[1402]: info: Spotify config file written Aug 27 19:40:48 volumio5678 sudo[3510]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 27 19:40:48 volumio5678 sudo[3510]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:40:48 volumio5678 systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Aug 27 19:40:48 volumio5678 systemd[1]: go-librespot-daemon.service: Deactivated successfully. Aug 27 19:40:48 volumio5678 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 27 19:40:48 volumio5678 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 27 19:40:48 volumio5678 go-librespot[3512]: go-librespot daemon starting... Aug 27 19:40:48 volumio5678 sudo[3510]: pam_unix(sudo:session): session closed for user root Aug 27 19:40:48 volumio5678 go-librespot[3513]: time="2026-08-27T19:40:48-04:00" level=info msg="running go-librespot 0.7.1" Aug 27 19:40:48 volumio5678 go-librespot[3513]: time="2026-08-27T19:40:48-04:00" level=debug msg="app state loaded" Aug 27 19:40:48 volumio5678 go-librespot[3513]: time="2026-08-27T19:40:48-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 27 19:40:48 volumio5678 go-librespot[3513]: time="2026-08-27T19:40:48-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Aug 27 19:40:48 volumio5678 go-librespot[3513]: time="2026-08-27T19:40:48-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 27 19:40:48 volumio5678 go-librespot[3513]: time="2026-08-27T19:40:48-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 27 19:40:48 volumio5678 go-librespot[3513]: time="2026-08-27T19:40:48-04:00" level=info msg="zeroconf server listening on port 36079" Aug 27 19:40:48 volumio5678 go-librespot[3513]: time="2026-08-27T19:40:48-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 27 19:40:48 volumio5678 volumio[1402]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Aug 27 19:40:48 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Aug 27 19:40:48 volumio5678 volumio[1402]: info: Creating Spotify config file Aug 27 19:40:48 volumio5678 volumio[1402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:40:48 volumio5678 volumio[1402]: info: Spotify config file written Aug 27 19:40:48 volumio5678 sudo[3523]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 27 19:40:48 volumio5678 sudo[3523]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:40:48 volumio5678 systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Aug 27 19:40:48 volumio5678 systemd[1]: go-librespot-daemon.service: Deactivated successfully. Aug 27 19:40:48 volumio5678 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 27 19:40:48 volumio5678 systemd[1]: go-librespot-daemon.service: Start request repeated too quickly. Aug 27 19:40:48 volumio5678 systemd[1]: go-librespot-daemon.service: Failed with result 'start-limit-hit'. Aug 27 19:40:48 volumio5678 systemd[1]: Failed to start go-librespot-daemon.service - go-librespot Daemon. Aug 27 19:40:48 volumio5678 sudo[3523]: pam_unix(sudo:session): session closed for user root Aug 27 19:40:48 volumio5678 volumio[1402]: error: Cannot start Go-librespot Daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service Aug 27 19:40:48 volumio5678 volumio[1402]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. Aug 27 19:40:48 volumio5678 volumio[1402]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. Aug 27 19:40:48 volumio5678 volumio[1402]: To force a start use "systemctl reset-failed go-librespot-daemon.service" Aug 27 19:40:48 volumio5678 volumio[1402]: followed by "systemctl start go-librespot-daemon.service" again. Aug 27 19:40:48 volumio5678 volumio[1402]: error: Error initializing go-librespot daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service Aug 27 19:40:48 volumio5678 volumio[1402]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. Aug 27 19:40:48 volumio5678 volumio[1402]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. Aug 27 19:40:48 volumio5678 volumio[1402]: To force a start use "systemctl reset-failed go-librespot-daemon.service" Aug 27 19:40:48 volumio5678 volumio[1402]: followed by "systemctl start go-librespot-daemon.service" again. Aug 27 19:40:48 volumio5678 volumio[1402]: info: go-librespot daemon successfully initialized Aug 27 19:40:48 volumio5678 volumio[1402]: info: Getting Spotify volume Aug 27 19:40:48 volumio5678 volumio[1402]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 27 19:40:48 volumio5678 volumio[1402]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 27 19:40:48 volumio5678 volumio[1402]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 27 19:40:48 volumio5678 volumio[1402]: errno: -111, Aug 27 19:40:48 volumio5678 volumio[1402]: code: 'ECONNREFUSED', Aug 27 19:40:48 volumio5678 volumio[1402]: syscall: 'connect', Aug 27 19:40:48 volumio5678 volumio[1402]: address: '127.0.0.1', Aug 27 19:40:48 volumio5678 volumio[1402]: port: 9879, Aug 27 19:40:48 volumio5678 volumio[1402]: response: undefined Aug 27 19:40:48 volumio5678 volumio[1402]: } Aug 27 19:40:48 volumio5678 volumio[1402]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 27 19:40:48 volumio5678 sudo[3540]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-27 19:39' Aug 27 19:40:48 volumio5678 sudo[3540]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"