Dec 29 12:15:29 volumio2 go-librespot[6887]: time="2025-12-29T12:15:29+13:00" level=trace msg="sent dealer ping" Dec 29 12:15:29 volumio2 go-librespot[6887]: time="2025-12-29T12:15:29+13:00" level=trace msg="received dealer pong" Dec 29 12:15:36 volumio2 xinit[6950]: [6950:7016:1229/121536.728377:ERROR:google_apis/gcm/engine/registration_request.cc:292] Registration response error message: DEPRECATED_ENDPOINT Dec 29 12:15:53 volumio2 sudo[8157]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 29 12:15:53 volumio2 sudo[8157]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:15:53 volumio2 sudo[8157]: pam_unix(sudo:session): session closed for user root Dec 29 12:15:53 volumio2 sudo[8159]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 29 12:15:53 volumio2 sudo[8159]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:15:53 volumio2 sudo[8159]: pam_unix(sudo:session): session closed for user root Dec 29 12:15:54 volumio2 volumio[6584]: verbose: New Socket.io Connection to 192.168.1.21 from 192.168.1.32 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Edg/143.0.0.0 Engine version: 3 Transport: polling Total Clients: 13 Dec 29 12:15:54 volumio2 sudo[8166]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 29 12:15:54 volumio2 sudo[8166]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:15:54 volumio2 sudo[8166]: pam_unix(sudo:session): session closed for user root Dec 29 12:15:54 volumio2 sudo[8168]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 29 12:15:54 volumio2 sudo[8168]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:15:54 volumio2 sudo[8168]: pam_unix(sudo:session): session closed for user root Dec 29 12:15:54 volumio2 volumio[6584]: verbose: New Socket.io Connection to 192.168.1.21 from 192.168.1.32 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Edg/143.0.0.0 Engine version: 3 Transport: polling Total Clients: 14 Dec 29 12:15:54 volumio2 volumio[6584]: info: CoreCommandRouter::volumioGetState Dec 29 12:15:54 volumio2 volumio[6584]: info: CorePlayQueue::getTrack 0 Dec 29 12:15:54 volumio2 volumio[6584]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 29 12:15:54 volumio2 volumio[6584]: info: Listing playlists Dec 29 12:15:54 volumio2 volumio[6584]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 29 12:15:54 volumio2 volumio[6584]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 29 12:15:54 volumio2 volumio[6584]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 29 12:15:54 volumio2 volumio[6584]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 29 12:15:56 volumio2 volumio[6584]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 29 12:15:56 volumio2 volumio[6584]: info: Received Get System Info Dec 29 12:15:56 volumio2 volumio[6584]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 29 12:15:56 volumio2 volumio[6584]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 29 12:15:56 volumio2 volumio[6584]: info: Discovery: Getting this device information Dec 29 12:15:56 volumio2 volumio[6584]: info: CoreCommandRouter::volumioGetState Dec 29 12:15:56 volumio2 volumio[6584]: info: CorePlayQueue::getTrack 0 Dec 29 12:15:56 volumio2 volumio[6584]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 29 12:15:56 volumio2 volumio[6584]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 29 12:15:59 volumio2 go-librespot[6887]: time="2025-12-29T12:15:59+13:00" level=trace msg="sent dealer ping" Dec 29 12:15:59 volumio2 go-librespot[6887]: time="2025-12-29T12:15:59+13:00" level=trace msg="received dealer pong" Dec 29 12:16:01 volumio2 volumio[6584]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 29 12:16:01 volumio2 volumio[6584]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 29 12:16:01 volumio2 volumio[6584]: info: Received Get System Info Dec 29 12:16:01 volumio2 volumio[6584]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 29 12:16:01 volumio2 volumio[6584]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 29 12:16:01 volumio2 volumio[6584]: info: Discovery: Getting this device information Dec 29 12:16:01 volumio2 volumio[6584]: info: CoreCommandRouter::volumioGetState Dec 29 12:16:01 volumio2 volumio[6584]: info: CorePlayQueue::getTrack 0 Dec 29 12:16:01 volumio2 volumio[6584]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 29 12:16:01 volumio2 volumio[6584]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Dec 29 12:16:01 volumio2 volumio[6584]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Dec 29 12:16:01 volumio2 sudo[8185]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Dec 29 12:16:01 volumio2 sudo[8185]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:16:01 volumio2 sudo[8180]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Dec 29 12:16:01 volumio2 sudo[8180]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:16:01 volumio2 sudo[8191]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Dec 29 12:16:01 volumio2 sudo[8191]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:16:01 volumio2 sudo[8185]: pam_unix(sudo:session): session closed for user root Dec 29 12:16:01 volumio2 sudo[8180]: pam_unix(sudo:session): session closed for user root Dec 29 12:16:01 volumio2 sudo[8191]: pam_unix(sudo:session): session closed for user root Dec 29 12:16:01 volumio2 sudo[8195]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Dec 29 12:16:01 volumio2 sudo[8195]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:16:01 volumio2 volumio[6584]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Dec 29 12:16:01 volumio2 sudo[8207]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 29 12:16:01 volumio2 sudo[8207]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:16:01 volumio2 volumio[6584]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Dec 29 12:16:01 volumio2 sudo[8202]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 29 12:16:01 volumio2 sudo[8202]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:16:01 volumio2 sudo[8202]: pam_unix(sudo:session): session closed for user root Dec 29 12:16:01 volumio2 sudo[8207]: pam_unix(sudo:session): session closed for user root Dec 29 12:16:01 volumio2 sudo[8195]: pam_unix(sudo:session): session closed for user root Dec 29 12:16:01 volumio2 sudo[8212]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 29 12:16:01 volumio2 sudo[8212]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:16:02 volumio2 sudo[8212]: pam_unix(sudo:session): session closed for user root Dec 29 12:16:13 volumio2 volumio[6584]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 29 12:16:13 volumio2 volumio[6584]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Dec 29 12:16:13 volumio2 volumio[6584]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Dec 29 12:16:13 volumio2 volumio[6584]: info: Received Get System Version Dec 29 12:16:13 volumio2 volumio[6584]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 29 12:16:13 volumio2 volumio[6584]: info: Received Get System Info Dec 29 12:16:13 volumio2 volumio[6584]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 29 12:16:13 volumio2 volumio[6584]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 29 12:16:13 volumio2 volumio[6584]: info: Discovery: Getting this device information Dec 29 12:16:13 volumio2 volumio[6584]: info: CoreCommandRouter::volumioGetState Dec 29 12:16:13 volumio2 volumio[6584]: info: CorePlayQueue::getTrack 0 Dec 29 12:16:13 volumio2 volumio[6584]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 29 12:16:16 volumio2 volumio[6584]: info: CALLMETHOD: system_controller network saveWirelessNet [object Object] Dec 29 12:16:16 volumio2 volumio[6584]: info: CoreCommandRouter::executeOnPlugin: network , saveWirelessNet Dec 29 12:16:16 volumio2 sudo[8248]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/network/interfaces Dec 29 12:16:16 volumio2 sudo[8248]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:16:16 volumio2 sudo[8248]: pam_unix(sudo:session): session closed for user root Dec 29 12:16:17 volumio2 sudo[8250]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/dhcpcd.conf Dec 29 12:16:17 volumio2 sudo[8250]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:16:17 volumio2 sudo[8250]: pam_unix(sudo:session): session closed for user root Dec 29 12:16:17 volumio2 volumio[6584]: info: Permissions for /etc/network/interfaces set Dec 29 12:16:17 volumio2 volumio[6584]: info: Restarting Wireless Network Dec 29 12:16:17 volumio2 volumio[6584]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , onNetworkingRestart Dec 29 12:16:17 volumio2 volumio[6584]: info: Discovery: Restarting Advertising due to device name change Dec 29 12:16:17 volumio2 sudo[8253]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart wireless.service Dec 29 12:16:17 volumio2 sudo[8253]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:16:17 volumio2 systemd[1]: Stopping wireless.service - Wireless Services... Dec 29 12:16:17 volumio2 systemd[1]: wireless.service: Killing process 1179 (wpa_supplicant) with signal SIGKILL. Dec 29 12:16:17 volumio2 systemd[1]: wireless.service: Deactivated successfully. Dec 29 12:16:17 volumio2 systemd[1]: Stopped wireless.service - Wireless Services. Dec 29 12:16:17 volumio2 systemd[1]: wireless.service: Consumed 6min 20.493s CPU time. Dec 29 12:16:17 volumio2 systemd[1]: Starting wireless.service - Wireless Services... Dec 29 12:16:18 volumio2 volumio[6584]: info: Discovery: A device disappeared from network Dec 29 12:16:18 volumio2 volumio[6584]: info: Discovery: Device volumio2 disappeared from network Dec 29 12:16:18 volumio2 volumio[6584]: info: Discovery: A device disappeared from network Dec 29 12:16:21 volumio2 wireless.js[8259]: WIRELESS.JS: Single Network Mode enabled, only one network device can be active at a time between ethernet and wireless Dec 29 12:16:21 volumio2 wireless.js[8259]: WIRELESS.JS: Wireless.js initializing wireless flow Dec 29 12:16:21 volumio2 wireless.js[8259]: WIRELESS.JS: Cleaning previous... Dec 29 12:16:21 volumio2 sudo[8280]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ip addr flush dev wlan0 Dec 29 12:16:21 volumio2 sudo[8280]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 29 12:16:21 volumio2 dhcpcd[849]: wlan0: pid 8281 deleted IP address 192.168.1.21/24 Dec 29 12:16:21 volumio2 dhcpcd[849]: wlan0: deleting route to 192.168.1.0/24 Dec 29 12:16:21 volumio2 dhcpcd[849]: wlan0: deleting default route via 192.168.1.1 Dec 29 12:16:21 volumio2 sudo[8280]: pam_unix(sudo:session): session closed for user root Dec 29 12:16:21 volumio2 avahi-daemon[1261]: Withdrawing address record for 192.168.1.21 on wlan0. Dec 29 12:16:21 volumio2 avahi-daemon[1261]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.21. Dec 29 12:16:21 volumio2 avahi-daemon[1261]: Interface wlan0.IPv4 no longer relevant for mDNS. Dec 29 12:16:21 volumio2 volumio[6584]: info: Discovery: A device disappeared from network Dec 29 12:16:21 volumio2 volumio[6584]: info: Discovery: Device volumio disappeared from network Dec 29 12:16:21 volumio2 volumio[6584]: info: Discovery: Disconnected from remote: 192.168.1.62 Dec 29 12:16:21 volumio2 sudo[8282]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ifconfig wlan0 down Dec 29 12:16:21 volumio2 sudo[8282]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 29 12:16:21 volumio2 systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Dec 29 12:16:21 volumio2 systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Dec 29 12:16:21 volumio2 systemd[1]: welcome.service: Deactivated successfully. Dec 29 12:16:21 volumio2 systemd[1]: Stopped welcome.service - Show a welcome message on console. Dec 29 12:16:21 volumio2 systemd[1]: Stopping welcome.service - Show a welcome message on console... Dec 29 12:16:21 volumio2 dhcpcd[849]: wlan0: rebinding lease of 192.168.1.21 Dec 29 12:16:21 volumio2 systemd[1]: Starting welcome.service - Show a welcome message on console... Dec 29 12:16:22 volumio2 dhcpcd[849]: wlan0: carrier lost Dec 29 12:16:22 volumio2 sudo[8282]: pam_unix(sudo:session): session closed for user root Dec 29 12:16:22 volumio2 welcome[8296]: Resolved ip:[0] Dec 29 12:16:22 volumio2 systemd[1]: Finished welcome.service - Show a welcome message on console. Dec 29 12:16:22 volumio2 volumio[6584]: info: Discovery: Started advertising with name: Volumio2 Dec 29 12:16:22 volumio2 systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Dec 29 12:16:22 volumio2 volumio[6584]: compat.c: read() failed: Resource temporarily unavailable Dec 29 12:16:22 volumio2 volumio[6584]: info: Discovery: mDNS temporarily unavailable during network transition Dec 29 12:16:22 volumio2 wireless.js[8259]: WIRELESS.JS: Stopped aP Dec 29 12:16:22 volumio2 sudo[8323]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Dec 29 12:16:22 volumio2 sudo[8323]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:16:22 volumio2 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Dec 29 12:16:22 volumio2 sudo[8323]: pam_unix(sudo:session): session closed for user root Dec 29 12:16:22 volumio2 sudo[8325]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Dec 29 12:16:22 volumio2 sudo[8325]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:16:22 volumio2 sudo[8325]: pam_unix(sudo:session): session closed for user root Dec 29 12:16:22 volumio2 sudo[8334]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Dec 29 12:16:22 volumio2 sudo[8334]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:16:22 volumio2 sudo[8334]: pam_unix(sudo:session): session closed for user root Dec 29 12:16:22 volumio2 sudo[8336]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Dec 29 12:16:22 volumio2 sudo[8336]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:16:23 volumio2 volumio[6584]: info: Volumio Network Manager: Network status updated: 0 Dec 29 12:16:23 volumio2 sudo[8336]: pam_unix(sudo:session): session closed for user root Dec 29 12:16:23 volumio2 wireless.js[8259]: WIRELESS.JS: SETTING APPROPRIATE REG DOMAIN: US Dec 29 12:16:23 volumio2 sudo[8356]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Dec 29 12:16:23 volumio2 sudo[8356]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:16:23 volumio2 sudo[8356]: pam_unix(sudo:session): session closed for user root Dec 29 12:16:23 volumio2 sudo[8358]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set US Dec 29 12:16:23 volumio2 sudo[8358]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:16:23 volumio2 sudo[8358]: pam_unix(sudo:session): session closed for user root Dec 29 12:16:23 volumio2 wireless.js[8259]: WIRELESS.JS: SUCCESSFULLY SET NEW REGDOMAIN: US Dec 29 12:16:23 volumio2 wireless.js[8259]: WIRELESS.JS: Start wireless flow Dec 29 12:16:23 volumio2 wireless.js[8259]: WIRELESS.JS: Stopped hotspot (if there).. Dec 29 12:16:23 volumio2 sudo[8366]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ip addr flush dev wlan0 Dec 29 12:16:23 volumio2 sudo[8366]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 29 12:16:23 volumio2 sudo[8366]: pam_unix(sudo:session): session closed for user root Dec 29 12:16:23 volumio2 sudo[8368]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ifconfig wlan0 down Dec 29 12:16:23 volumio2 sudo[8368]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 29 12:16:24 volumio2 sudo[8368]: pam_unix(sudo:session): session closed for user root Dec 29 12:16:24 volumio2 wireless.js[8259]: WIRELESS.JS: DHCP IP fallback Dec 29 12:16:24 volumio2 wireless.js[8259]: WIRELESS.JS: Start ap Dec 29 12:16:24 volumio2 sudo[8374]: root : PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Dec 29 12:16:24 volumio2 sudo[8374]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 29 12:16:24 volumio2 dhcpcd[849]: ps_ctl_dispatch: cannot handle another client Dec 29 12:16:24 volumio2 dhcpcd[849]: control_free: No such file or directory Dec 29 12:16:24 volumio2 sudo[8374]: pam_unix(sudo:session): session closed for user root Dec 29 12:16:24 volumio2 wpa_supplicant[8373]: Successfully initialized wpa_supplicant Dec 29 12:16:24 volumio2 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Dec 29 12:16:25 volumio2 wpa_supplicant[8378]: wlan0: Trying to associate with e8:48:b8:22:28:86 (SSID='IP_FREELY' freq=2417 MHz) Dec 29 12:16:25 volumio2 wpa_supplicant[8378]: FT: Invalid key management type (2) Dec 29 12:16:25 volumio2 wireless.js[8259]: WIRELESS.JS: trying... Dec 29 12:16:25 volumio2 sudo[8381]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 29 12:16:25 volumio2 sudo[8381]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:16:25 volumio2 sudo[8381]: pam_unix(sudo:session): session closed for user root Dec 29 12:16:25 volumio2 wpa_supplicant[8378]: wlan0: Associated with e8:48:b8:22:28:86 Dec 29 12:16:25 volumio2 wpa_supplicant[8378]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Dec 29 12:16:25 volumio2 wpa_supplicant[8378]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US Dec 29 12:16:25 volumio2 wpa_supplicant[8378]: wlan0: WPA: Key negotiation completed with e8:48:b8:22:28:86 [PTK=CCMP GTK=CCMP] Dec 29 12:16:25 volumio2 wpa_supplicant[8378]: wlan0: CTRL-EVENT-CONNECTED - Connection to e8:48:b8:22:28:86 completed [id=0 id_str=] Dec 29 12:16:25 volumio2 dhcpcd[849]: wlan0: carrier acquired Dec 29 12:16:25 volumio2 dhcpcd[849]: wlan0: config file changed, expiring leases Dec 29 12:16:25 volumio2 dhcpcd[849]: wlan0: IAID eb:df:78:8c Dec 29 12:16:25 volumio2 dhcpcd[849]: wlan0: soliciting an IPv6 router Dec 29 12:16:26 volumio2 wireless.js[8259]: WIRELESS.JS: trying... Dec 29 12:16:26 volumio2 sudo[8386]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 29 12:16:26 volumio2 sudo[8386]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:16:26 volumio2 sudo[8386]: pam_unix(sudo:session): session closed for user root Dec 29 12:16:26 volumio2 dhcpcd[849]: wlan0: rebinding lease of 192.168.1.21 Dec 29 12:16:26 volumio2 dhcpcd[849]: wlan0: probing address 192.168.1.21/24 Dec 29 12:16:26 volumio2 ntpd[918]: IO: Deleting interface #3 wlan0, 192.168.1.21#123, interface stats: received=200, sent=292, dropped=2, active_time=1734 secs Dec 29 12:16:26 volumio2 ntpd[918]: PROTO: 103.158.134.33 unlink local addr 192.168.1.21 -> Dec 29 12:16:26 volumio2 ntpd[918]: PROTO: 114.110.37.123 unlink local addr 192.168.1.21 -> Dec 29 12:16:26 volumio2 ntpd[918]: PROTO: 121.98.11.157 unlink local addr 192.168.1.21 -> Dec 29 12:16:26 volumio2 ntpd[918]: PROTO: 103.106.65.219 unlink local addr 192.168.1.21 -> Dec 29 12:16:26 volumio2 ntpd[918]: PROTO: 162.159.200.123 unlink local addr 192.168.1.21 -> Dec 29 12:16:26 volumio2 ntpd[918]: PROTO: 132.181.2.72 unlink local addr 192.168.1.21 -> Dec 29 12:16:26 volumio2 ntpd[918]: PROTO: 203.190.212.96 unlink local addr 192.168.1.21 -> Dec 29 12:16:27 volumio2 wireless.js[8259]: WIRELESS.JS: trying... Dec 29 12:16:27 volumio2 sudo[8392]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 29 12:16:27 volumio2 sudo[8392]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:16:27 volumio2 sudo[8392]: pam_unix(sudo:session): session closed for user root Dec 29 12:16:28 volumio2 wireless.js[8259]: WIRELESS.JS: trying... Dec 29 12:16:28 volumio2 sudo[8396]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 29 12:16:28 volumio2 sudo[8396]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:16:28 volumio2 sudo[8396]: pam_unix(sudo:session): session closed for user root Dec 29 12:16:29 volumio2 wireless.js[8259]: WIRELESS.JS: trying... Dec 29 12:16:29 volumio2 sudo[8400]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 29 12:16:29 volumio2 sudo[8400]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:16:29 volumio2 sudo[8400]: pam_unix(sudo:session): session closed for user root Dec 29 12:16:29 volumio2 go-librespot[6887]: time="2025-12-29T12:16:29+13:00" level=trace msg="sent dealer ping" Dec 29 12:16:29 volumio2 go-librespot[6887]: time="2025-12-29T12:16:29+13:00" level=error msg="did not receive last pong ack from accesspoint, 121s passed" Dec 29 12:16:29 volumio2 go-librespot[6887]: time="2025-12-29T12:16:29+13:00" level=error msg="failed receiving packet" error="failed reading packet header: read tcp 192.168.1.21:43190->104.199.241.202:4070: use of closed network connection" Dec 29 12:16:29 volumio2 go-librespot[6887]: time="2025-12-29T12:16:29+13:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp: lookup ap-gae2.spotify.com: device or resource busy" Dec 29 12:16:29 volumio2 go-librespot[6887]: time="2025-12-29T12:16:29+13:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:80, retrying with a different AP" error="dial tcp: lookup ap-gae2.spotify.com: device or resource busy" Dec 29 12:16:29 volumio2 go-librespot[6887]: time="2025-12-29T12:16:29+13:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp: lookup ap-guc3.spotify.com: device or resource busy" Dec 29 12:16:29 volumio2 go-librespot[6887]: time="2025-12-29T12:16:29+13:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:443, retrying with a different AP" error="dial tcp: lookup ap-gue1.spotify.com: device or resource busy" Dec 29 12:16:29 volumio2 go-librespot[6887]: time="2025-12-29T12:16:29+13:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:80, retrying with a different AP" error="dial tcp: lookup ap-gew4.spotify.com: device or resource busy" Dec 29 12:16:29 volumio2 go-librespot[6887]: time="2025-12-29T12:16:29+13:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp: lookup ap-gae2.spotify.com: device or resource busy" Dec 29 12:16:29 volumio2 go-librespot[6887]: time="2025-12-29T12:16:29+13:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:80, retrying with a different AP" error="dial tcp: lookup ap-gae2.spotify.com: device or resource busy" Dec 29 12:16:29 volumio2 go-librespot[6887]: time="2025-12-29T12:16:29+13:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp: lookup ap-guc3.spotify.com: device or resource busy" Dec 29 12:16:29 volumio2 go-librespot[6887]: time="2025-12-29T12:16:29+13:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:443, retrying with a different AP" error="dial tcp: lookup ap-gue1.spotify.com: device or resource busy" Dec 29 12:16:29 volumio2 go-librespot[6887]: time="2025-12-29T12:16:29+13:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:80, retrying with a different AP" error="dial tcp: lookup ap-gew4.spotify.com: device or resource busy" Dec 29 12:16:30 volumio2 wireless.js[8259]: WIRELESS.JS: trying... Dec 29 12:16:30 volumio2 sudo[8404]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 29 12:16:30 volumio2 sudo[8404]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:16:30 volumio2 sudo[8404]: pam_unix(sudo:session): session closed for user root Dec 29 12:16:30 volumio2 go-librespot[6887]: time="2025-12-29T12:16:30+13:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp: lookup ap-gae2.spotify.com: device or resource busy" Dec 29 12:16:30 volumio2 go-librespot[6887]: time="2025-12-29T12:16:30+13:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:80, retrying with a different AP" error="dial tcp: lookup ap-gae2.spotify.com: device or resource busy" Dec 29 12:16:30 volumio2 go-librespot[6887]: time="2025-12-29T12:16:30+13:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp: lookup ap-guc3.spotify.com: device or resource busy" Dec 29 12:16:30 volumio2 go-librespot[6887]: time="2025-12-29T12:16:30+13:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:443, retrying with a different AP" error="dial tcp: lookup ap-gue1.spotify.com: device or resource busy" Dec 29 12:16:30 volumio2 go-librespot[6887]: time="2025-12-29T12:16:30+13:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:80, retrying with a different AP" error="dial tcp: lookup ap-gew4.spotify.com: device or resource busy" Dec 29 12:16:31 volumio2 wireless.js[8259]: WIRELESS.JS: trying... Dec 29 12:16:31 volumio2 sudo[8408]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 29 12:16:31 volumio2 sudo[8408]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:16:31 volumio2 sudo[8408]: pam_unix(sudo:session): session closed for user root Dec 29 12:16:31 volumio2 dhcpcd[849]: wlan0: leased 192.168.1.21 for 86400 seconds Dec 29 12:16:31 volumio2 avahi-daemon[1261]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.21. Dec 29 12:16:31 volumio2 dhcpcd[849]: wlan0: adding route to 192.168.1.0/24 Dec 29 12:16:31 volumio2 avahi-daemon[1261]: New relevant interface wlan0.IPv4 for mDNS. Dec 29 12:16:31 volumio2 avahi-daemon[1261]: Registering new address record for 192.168.1.21 on wlan0.IPv4. Dec 29 12:16:31 volumio2 systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Dec 29 12:16:31 volumio2 systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Dec 29 12:16:31 volumio2 systemd[1]: welcome.service: Deactivated successfully. Dec 29 12:16:31 volumio2 systemd[1]: Stopped welcome.service - Show a welcome message on console. Dec 29 12:16:31 volumio2 systemd[1]: Stopping welcome.service - Show a welcome message on console... Dec 29 12:16:31 volumio2 dhcpcd[849]: wlan0: adding default route via 192.168.1.1 Dec 29 12:16:31 volumio2 systemd[1]: Starting welcome.service - Show a welcome message on console... Dec 29 12:16:31 volumio2 welcome[8422]: Resolved ip:[1] 192.168.1.21 Dec 29 12:16:31 volumio2 systemd[1]: Finished welcome.service - Show a welcome message on console. Dec 29 12:16:31 volumio2 systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Dec 29 12:16:31 volumio2 volumio[6584]: compat.c: read() failed: Resource temporarily unavailable Dec 29 12:16:31 volumio2 volumio[6584]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 29 12:16:31 volumio2 volumio[6584]: Error: dns service error: unknown Dec 29 12:16:31 volumio2 volumio[6584]: at MDNSService.self.watcher.callback (/volumio/node_modules/mdns/lib/mdns_service.js:18:40) { Dec 29 12:16:31 volumio2 volumio[6584]: errorCode: -65537 Dec 29 12:16:31 volumio2 volumio[6584]: } Dec 29 12:16:31 volumio2 volumio[6584]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 29 12:16:31 volumio2 go-librespot[6887]: time="2025-12-29T12:16:31+13:00" level=debug msg="connected to ap-gae2.spotify.com:443" Dec 29 12:16:32 volumio2 go-librespot[6887]: time="2025-12-29T12:16:32+13:00" level=debug msg="completed keyexchange" Dec 29 12:16:32 volumio2 go-librespot[6887]: time="2025-12-29T12:16:32+13:00" level=debug msg="completed challenge" Dec 29 12:16:32 volumio2 wireless.js[8259]: WIRELESS.JS: trying... Dec 29 12:16:32 volumio2 sudo[8451]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 29 12:16:32 volumio2 sudo[8451]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:16:32 volumio2 sudo[8451]: pam_unix(sudo:session): session closed for user root Dec 29 12:16:32 volumio2 wireless.js[8259]: WIRELESS.JS: Connected to: ----IP_FREELY---- Dec 29 12:16:32 volumio2 sudo[8454]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 29 12:16:32 volumio2 sudo[8454]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 29 12:16:32 volumio2 sudo[8454]: pam_unix(sudo:session): session closed for user root Dec 29 12:16:32 volumio2 wireless.js[8259]: WIRELESS.JS: ... joined AP, wlan0 IPv4 is 192.168.1.21, ipV6 is undefined Dec 29 12:16:32 volumio2 wireless.js[8259]: WIRELESS.JS: It's done! AP Dec 29 12:16:32 volumio2 wireless.js[8259]: WIRELESS.JS: Restarting avahi-daemon... Dec 29 12:16:32 volumio2 go-librespot[6887]: time="2025-12-29T12:16:32+13:00" level=info msg="authenticated AP" username="31************************vm" Dec 29 12:16:32 volumio2 go-librespot[6887]: time="2025-12-29T12:16:32+13:00" level=debug msg="re-established accesspoint connection" Dec 29 12:16:32 volumio2 go-librespot[6887]: time="2025-12-29T12:16:32+13:00" level=trace msg="received accesspoint ping" Dec 29 12:16:32 volumio2 go-librespot[6887]: time="2025-12-29T12:16:32+13:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 29 12:16:32 volumio2 go-librespot[6887]: time="2025-12-29T12:16:32+13:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 29 12:16:32 volumio2 go-librespot[6887]: time="2025-12-29T12:16:32+13:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 29 12:16:32 volumio2 go-librespot[6887]: time="2025-12-29T12:16:32+13:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 29 12:16:32 volumio2 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 29 12:16:32 volumio2 systemd[1]: shairport-sync.service: Deactivated successfully. Dec 29 12:16:32 volumio2 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 29 12:16:32 volumio2 systemd[1]: shairport-sync.service: Consumed 4.734s CPU time. Dec 29 12:16:32 volumio2 avahi-daemon[1261]: Got SIGTERM, quitting. Dec 29 12:16:32 volumio2 systemd[1]: Stopping avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Dec 29 12:16:32 volumio2 avahi-daemon[1261]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.21. Dec 29 12:16:32 volumio2 avahi-daemon[1261]: Leaving mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Dec 29 12:16:32 volumio2 avahi-daemon[1261]: avahi-daemon 0.8 exiting. Dec 29 12:16:32 volumio2 systemd[1]: avahi-daemon.service: Deactivated successfully. Dec 29 12:16:32 volumio2 systemd[1]: Stopped avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Dec 29 12:16:32 volumio2 systemd[1]: avahi-daemon.service: Consumed 2.410s CPU time. Dec 29 12:16:32 volumio2 go-librespot[6887]: time="2025-12-29T12:16:32+13:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 29 12:16:32 volumio2 ntpd[918]: IO: Listen normally on 4 wlan0 192.168.1.21:123 Dec 29 12:16:32 volumio2 ntpd[918]: IO: new interface(s) found: waking up resolver Dec 29 12:16:32 volumio2 systemd[1]: Starting avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Dec 29 12:16:32 volumio2 wireless.js[8259]: WIRELESS.JS: Notified systemd about wireless ready Dec 29 12:16:32 volumio2 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Dec 29 12:16:32 volumio2 systemd[1]: Started wireless.service - Wireless Services. Dec 29 12:16:32 volumio2 sudo[8253]: pam_unix(sudo:session): session closed for user root Dec 29 12:16:32 volumio2 avahi-daemon[8460]: Process 1261 died: No such process; trying to remove PID file. (/run/avahi-daemon//pid) Dec 29 12:16:32 volumio2 sudo[8467]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-29 12:15' Dec 29 12:16:32 volumio2 sudo[8467]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:16:32 volumio2 avahi-daemon[8460]: Found user 'avahi' (UID 103) and group 'avahi' (GID 109). Dec 29 12:16:32 volumio2 avahi-daemon[8460]: Successfully dropped root privileges. Dec 29 12:16:32 volumio2 avahi-daemon[8460]: avahi-daemon 0.8 starting up. Dec 29 12:16:32 volumio2 systemd[1]: Started avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Dec 29 12:16:32 volumio2 avahi-daemon[8460]: Successfully called chroot(). Dec 29 12:16:32 volumio2 avahi-daemon[8460]: Successfully dropped remaining capabilities. Dec 29 12:16:32 volumio2 avahi-daemon[8460]: Loading service file /services/volumio.service. Dec 29 12:16:32 volumio2 avahi-daemon[8460]: *** WARNING: Detected another IPv4 mDNS stack running on this host. This makes mDNS unreliable and is thus not recommended. *** Dec 29 12:16:32 volumio2 avahi-daemon[8460]: *** WARNING: Detected another IPv6 mDNS stack running on this host. This makes mDNS unreliable and is thus not recommended. *** Dec 29 12:16:32 volumio2 go-librespot[6887]: time="2025-12-29T12:16:32+13:00" level=trace msg="received accesspoint pong ack" Dec 29 12:16:32 volumio2 avahi-daemon[8460]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.21. Dec 29 12:16:32 volumio2 avahi-daemon[8460]: New relevant interface wlan0.IPv4 for mDNS. Dec 29 12:16:32 volumio2 avahi-daemon[8460]: Joining mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Dec 29 12:16:32 volumio2 avahi-daemon[8460]: New relevant interface lo.IPv4 for mDNS. Dec 29 12:16:32 volumio2 avahi-daemon[8460]: Network interface enumeration completed. Dec 29 12:16:32 volumio2 avahi-daemon[8460]: Registering new address record for 192.168.1.21 on wlan0.IPv4. Dec 29 12:16:32 volumio2 avahi-daemon[8460]: Registering new address record for 127.0.0.1 on lo.IPv4. Dec 29 12:16:32 volumio2 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"