Dec 07 17:33:02 volumio-pool volumio[1269]: info: CoreCommandRouter::volumioGetState Dec 07 17:33:02 volumio-pool volumio[1269]: info: CorePlayQueue::getTrack 0 Dec 07 17:33:02 volumio-pool volumio[1269]: info: Listing playlists Dec 07 17:33:02 volumio-pool volumio[1269]: info: Listing playlists Dec 07 17:33:04 volumio-pool wpa_supplicant[1167]: RRM: Ignoring radio measurement request: Not RRM network Dec 07 17:33:10 volumio-pool wpa_supplicant[1167]: RRM: Ignoring radio measurement request: Not RRM network Dec 07 17:33:12 volumio-pool volumio[1269]: info: CoreCommandRouter::volumioGetState Dec 07 17:33:12 volumio-pool volumio[1269]: info: CorePlayQueue::getTrack 0 Dec 07 17:33:16 volumio-pool wpa_supplicant[1167]: RRM: Ignoring radio measurement request: Not RRM network Dec 07 17:33:22 volumio-pool volumio[1269]: info: CoreCommandRouter::volumioGetState Dec 07 17:33:22 volumio-pool volumio[1269]: info: CorePlayQueue::getTrack 0 Dec 07 17:33:22 volumio-pool volumio[1269]: info: Listing playlists Dec 07 17:33:22 volumio-pool volumio[1269]: info: Listing playlists Dec 07 17:33:22 volumio-pool wpa_supplicant[1167]: RRM: Ignoring radio measurement request: Not RRM network Dec 07 17:33:28 volumio-pool wpa_supplicant[1167]: RRM: Ignoring radio measurement request: Not RRM network Dec 07 17:33:32 volumio-pool volumio[1269]: info: CoreCommandRouter::volumioGetState Dec 07 17:33:32 volumio-pool volumio[1269]: info: CorePlayQueue::getTrack 0 Dec 07 17:33:34 volumio-pool wpa_supplicant[1167]: RRM: Ignoring radio measurement request: Not RRM network Dec 07 17:33:40 volumio-pool wpa_supplicant[1167]: RRM: Ignoring radio measurement request: Not RRM network Dec 07 17:33:40 volumio-pool wpa_supplicant[1167]: wlan0: WNM: Preferred List Available Dec 07 17:33:40 volumio-pool wpa_supplicant[1167]: wlan0: Trying to associate with 34:60:f9:e0:af:1b (SSID='NETGEAR44' freq=5200 MHz) Dec 07 17:33:40 volumio-pool dhcpcd[841]: wlan0: carrier lost - roaming Dec 07 17:33:40 volumio-pool dhcpcd[841]: wlan0: changing route to 192.168.1.0/24 Dec 07 17:33:40 volumio-pool dhcpcd[841]: wlan0: changing default route via 192.168.1.1 Dec 07 17:33:40 volumio-pool kernel: ieee80211 phy0: brcmf_p2p_send_action_frame: Unknown Frame: category 0xa, action 0x8 Dec 07 17:33:41 volumio-pool wpa_supplicant[1167]: wlan0: Associated with 34:60:f9:e0:af:1b Dec 07 17:33:41 volumio-pool wpa_supplicant[1167]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Dec 07 17:33:41 volumio-pool wpa_supplicant[1167]: wlan0: WPA: Key negotiation completed with 34:60:f9:e0:af:1b [PTK=CCMP GTK=CCMP] Dec 07 17:33:41 volumio-pool wpa_supplicant[1167]: wlan0: CTRL-EVENT-CONNECTED - Connection to 34:60:f9:e0:af:1b completed [id=0 id_str=] Dec 07 17:33:41 volumio-pool dhcpcd[841]: wlan0: carrier acquired Dec 07 17:33:41 volumio-pool dhcpcd[841]: wlan0: IAID dd:bb:13:59 Dec 07 17:33:41 volumio-pool dhcpcd[841]: wlan0: soliciting an IPv6 router Dec 07 17:33:41 volumio-pool wpa_supplicant[1167]: RRM: Ignoring radio measurement request: Not RRM network Dec 07 17:33:42 volumio-pool dhcpcd[841]: wlan0: rebinding lease of 192.168.1.125 Dec 07 17:33:42 volumio-pool dhcpcd[841]: wlan0: leased 192.168.1.125 for 7200 seconds Dec 07 17:33:42 volumio-pool dhcpcd[841]: wlan0: changing route to 192.168.1.0/24 Dec 07 17:33:42 volumio-pool dhcpcd[841]: wlan0: changing default route via 192.168.1.1 Dec 07 17:33:42 volumio-pool systemd[1]: Starting apt-daily-upgrade.service - Daily apt upgrade and clean activities... Dec 07 17:33:42 volumio-pool systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Dec 07 17:33:42 volumio-pool systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Dec 07 17:33:42 volumio-pool systemd[1]: welcome.service: Deactivated successfully. Dec 07 17:33:42 volumio-pool systemd[1]: Stopped welcome.service - Show a welcome message on console. Dec 07 17:33:42 volumio-pool systemd[1]: Stopping welcome.service - Show a welcome message on console... Dec 07 17:33:42 volumio-pool systemd[1]: Starting welcome.service - Show a welcome message on console... Dec 07 17:33:42 volumio-pool welcome[3000]: Resolved ip:[1] 192.168.1.125 Dec 07 17:33:42 volumio-pool systemd[1]: Finished welcome.service - Show a welcome message on console. Dec 07 17:33:42 volumio-pool systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Dec 07 17:33:42 volumio-pool volumio[1269]: info: CoreCommandRouter::volumioGetState Dec 07 17:33:42 volumio-pool volumio[1269]: info: CorePlayQueue::getTrack 0 Dec 07 17:33:42 volumio-pool volumio[1269]: info: Listing playlists Dec 07 17:33:42 volumio-pool volumio[1269]: info: Listing playlists Dec 07 17:33:43 volumio-pool systemd[1]: apt-daily-upgrade.service: Deactivated successfully. Dec 07 17:33:43 volumio-pool systemd[1]: Finished apt-daily-upgrade.service - Daily apt upgrade and clean activities. Dec 07 17:33:47 volumio-pool wpa_supplicant[1167]: RRM: Ignoring radio measurement request: Not RRM network Dec 07 17:33:52 volumio-pool volumio[1269]: info: CoreCommandRouter::volumioGetState Dec 07 17:33:52 volumio-pool volumio[1269]: info: CorePlayQueue::getTrack 0 Dec 07 17:33:53 volumio-pool wpa_supplicant[1167]: RRM: Ignoring radio measurement request: Not RRM network Dec 07 17:33:59 volumio-pool wpa_supplicant[1167]: RRM: Ignoring radio measurement request: Not RRM network Dec 07 17:33:59 volumio-pool wpa_supplicant[1167]: wlan0: WNM: Preferred List Available Dec 07 17:33:59 volumio-pool wpa_supplicant[1167]: wlan0: Trying to associate with 34:60:f9:e0:c9:1f (SSID='NETGEAR44' freq=5200 MHz) Dec 07 17:33:59 volumio-pool dhcpcd[841]: wlan0: carrier lost - roaming Dec 07 17:33:59 volumio-pool dhcpcd[841]: wlan0: changing route to 192.168.1.0/24 Dec 07 17:33:59 volumio-pool dhcpcd[841]: wlan0: changing default route via 192.168.1.1 Dec 07 17:33:59 volumio-pool kernel: ieee80211 phy0: brcmf_p2p_send_action_frame: Unknown Frame: category 0xa, action 0x8 Dec 07 17:34:01 volumio-pool ntpd[1008]: IO: Deleting interface #7 wlan0, 192.168.1.125#123, interface stats: received=32, sent=32, dropped=0, active_time=131 secs Dec 07 17:34:01 volumio-pool ntpd[1008]: PROTO: 27.100.36.46 unlink local addr 192.168.1.125 -> Dec 07 17:34:01 volumio-pool ntpd[1008]: PROTO: 159.196.178.7 unlink local addr 192.168.1.125 -> Dec 07 17:34:01 volumio-pool ntpd[1008]: PROTO: 172.105.179.71 unlink local addr 192.168.1.125 -> Dec 07 17:34:01 volumio-pool ntpd[1008]: PROTO: 162.159.200.1 unlink local addr 192.168.1.125 -> Dec 07 17:34:01 volumio-pool ntpd[1008]: PROTO: 220.158.215.21 unlink local addr 192.168.1.125 -> Dec 07 17:34:01 volumio-pool ntpd[1008]: PROTO: 27.124.125.250 unlink local addr 192.168.1.125 -> Dec 07 17:34:01 volumio-pool ntpd[1008]: PROTO: 144.6.228.171 unlink local addr 192.168.1.125 -> Dec 07 17:34:01 volumio-pool ntpd[1008]: PROTO: 180.150.8.191 unlink local addr 192.168.1.125 -> Dec 07 17:34:01 volumio-pool ntpd[1008]: PROTO: 193.177.220.128 unlink local addr 192.168.1.125 -> Dec 07 17:34:01 volumio-pool ntpd[1008]: PROTO: 194.195.249.28 unlink local addr 192.168.1.125 -> Dec 07 17:34:01 volumio-pool ntpd[1008]: PROTO: 27.124.125.251 unlink local addr 192.168.1.125 -> Dec 07 17:34:01 volumio-pool ntpd[1008]: PROTO: 67.219.100.202 unlink local addr 192.168.1.125 -> Dec 07 17:34:01 volumio-pool ntpd[1008]: PROTO: 119.18.6.37 unlink local addr 192.168.1.125 -> Dec 07 17:34:01 volumio-pool ntpd[1008]: PROTO: 180.150.84.241 unlink local addr 192.168.1.125 -> Dec 07 17:34:01 volumio-pool ntpd[1008]: PROTO: 162.159.200.123 unlink local addr 192.168.1.125 -> Dec 07 17:34:01 volumio-pool ntpd[1008]: PROTO: 103.126.53.123 unlink local addr 192.168.1.125 -> Dec 07 17:34:02 volumio-pool volumio[1269]: info: CoreCommandRouter::volumioGetState Dec 07 17:34:02 volumio-pool volumio[1269]: info: CorePlayQueue::getTrack 0 Dec 07 17:34:02 volumio-pool volumio[1269]: info: Listing playlists Dec 07 17:34:02 volumio-pool volumio[1269]: info: Listing playlists Dec 07 17:34:08 volumio-pool wpa_supplicant[1167]: RRM: Ignoring radio measurement request: Not associated Dec 07 17:34:09 volumio-pool wpa_supplicant[1167]: wlan0: Authentication with 34:60:f9:e0:c9:1f timed out. Dec 07 17:34:09 volumio-pool wpa_supplicant[1167]: wlan0: CTRL-EVENT-DISCONNECTED bssid=34:60:f9:e0:c9:1f reason=3 locally_generated=1 Dec 07 17:34:09 volumio-pool wpa_supplicant[1167]: BSSID 34:60:f9:e0:c9:1f ignore list count incremented to 2, ignoring for 10 seconds Dec 07 17:34:09 volumio-pool wpa_supplicant[1167]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all Dec 07 17:34:09 volumio-pool wpa_supplicant[1167]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Dec 07 17:34:09 volumio-pool wpa_supplicant[1167]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=US Dec 07 17:34:12 volumio-pool wpa_supplicant[1167]: wlan0: Trying to associate with 34:60:f9:e0:c9:1e (SSID='NETGEAR44' freq=2417 MHz) Dec 07 17:34:13 volumio-pool wpa_supplicant[1167]: wlan0: Associated with 34:60:f9:e0:c9:1e Dec 07 17:34:13 volumio-pool wpa_supplicant[1167]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Dec 07 17:34:13 volumio-pool wpa_supplicant[1167]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US Dec 07 17:34:13 volumio-pool wpa_supplicant[1167]: wlan0: WPA: Key negotiation completed with 34:60:f9:e0:c9:1e [PTK=CCMP GTK=CCMP] Dec 07 17:34:13 volumio-pool wpa_supplicant[1167]: wlan0: CTRL-EVENT-CONNECTED - Connection to 34:60:f9:e0:c9:1e completed [id=0 id_str=] Dec 07 17:34:13 volumio-pool dhcpcd[841]: wlan0: carrier acquired Dec 07 17:34:13 volumio-pool dhcpcd[841]: wlan0: IAID dd:bb:13:59 Dec 07 17:34:13 volumio-pool dhcpcd[841]: wlan0: soliciting an IPv6 router Dec 07 17:34:13 volumio-pool volumio[1269]: info: CoreCommandRouter::volumioGetState Dec 07 17:34:13 volumio-pool volumio[1269]: info: CorePlayQueue::getTrack 0 Dec 07 17:34:13 volumio-pool wpa_supplicant[1167]: RRM: Ignoring radio measurement request: Not RRM network Dec 07 17:34:14 volumio-pool wpa_supplicant[1167]: wlan0: WNM: Preferred List Available Dec 07 17:34:14 volumio-pool kernel: ieee80211 phy0: brcmf_p2p_send_action_frame: Unknown Frame: category 0xa, action 0x8 Dec 07 17:34:14 volumio-pool dhcpcd[841]: wlan0: rebinding lease of 192.168.1.125 Dec 07 17:34:14 volumio-pool dhcpcd[841]: wlan0: leased 192.168.1.125 for 7200 seconds Dec 07 17:34:14 volumio-pool dhcpcd[841]: wlan0: changing route to 192.168.1.0/24 Dec 07 17:34:14 volumio-pool dhcpcd[841]: wlan0: changing default route via 192.168.1.1 Dec 07 17:34:14 volumio-pool systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Dec 07 17:34:14 volumio-pool systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Dec 07 17:34:14 volumio-pool systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Dec 07 17:34:14 volumio-pool systemd[1]: welcome.service: Deactivated successfully. Dec 07 17:34:14 volumio-pool systemd[1]: Stopped welcome.service - Show a welcome message on console. Dec 07 17:34:14 volumio-pool systemd[1]: Stopping welcome.service - Show a welcome message on console... Dec 07 17:34:14 volumio-pool systemd[1]: Starting welcome.service - Show a welcome message on console... Dec 07 17:34:14 volumio-pool welcome[3141]: Resolved ip:[1] 192.168.1.125 Dec 07 17:34:14 volumio-pool systemd[1]: Finished welcome.service - Show a welcome message on console. Dec 07 17:34:14 volumio-pool systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Dec 07 17:34:15 volumio-pool systemd[1]: setdatetime-helper.service: Deactivated successfully. Dec 07 17:34:15 volumio-pool systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Dec 07 17:34:15 volumio-pool ntpd[1008]: IO: Listen normally on 8 wlan0 192.168.1.125:123 Dec 07 17:34:15 volumio-pool ntpd[1008]: IO: new interface(s) found: waking up resolver Dec 07 17:34:22 volumio-pool volumio[1269]: info: CoreCommandRouter::volumioGetState Dec 07 17:34:22 volumio-pool volumio[1269]: info: CorePlayQueue::getTrack 0 Dec 07 17:34:22 volumio-pool volumio[1269]: info: Listing playlists Dec 07 17:34:22 volumio-pool volumio[1269]: info: Listing playlists Dec 07 17:34:23 volumio-pool wpa_supplicant[1167]: RRM: Ignoring radio measurement request: Not RRM network Dec 07 17:34:23 volumio-pool wpa_supplicant[1167]: wlan0: WNM: Preferred List Available Dec 07 17:34:23 volumio-pool wpa_supplicant[1167]: wlan0: Trying to associate with 34:60:f9:e0:c9:1f (SSID='NETGEAR44' freq=5200 MHz) Dec 07 17:34:23 volumio-pool dhcpcd[841]: wlan0: carrier lost - roaming Dec 07 17:34:23 volumio-pool dhcpcd[841]: wlan0: changing route to 192.168.1.0/24 Dec 07 17:34:23 volumio-pool kernel: ieee80211 phy0: brcmf_p2p_send_action_frame: Unknown Frame: category 0xa, action 0x8 Dec 07 17:34:23 volumio-pool dhcpcd[841]: wlan0: changing default route via 192.168.1.1 Dec 07 17:34:23 volumio-pool wpa_supplicant[1167]: wlan0: Associated with 34:60:f9:e0:c9:1f Dec 07 17:34:23 volumio-pool wpa_supplicant[1167]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Dec 07 17:34:23 volumio-pool wpa_supplicant[1167]: wlan0: WPA: Key negotiation completed with 34:60:f9:e0:c9:1f [PTK=CCMP GTK=CCMP] Dec 07 17:34:23 volumio-pool wpa_supplicant[1167]: wlan0: CTRL-EVENT-CONNECTED - Connection to 34:60:f9:e0:c9:1f completed [id=0 id_str=] Dec 07 17:34:23 volumio-pool dhcpcd[841]: wlan0: carrier acquired Dec 07 17:34:23 volumio-pool dhcpcd[841]: wlan0: IAID dd:bb:13:59 Dec 07 17:34:24 volumio-pool dhcpcd[841]: wlan0: soliciting an IPv6 router Dec 07 17:34:24 volumio-pool dhcpcd[841]: wlan0: rebinding lease of 192.168.1.125 Dec 07 17:34:24 volumio-pool dhcpcd[841]: wlan0: leased 192.168.1.125 for 7200 seconds Dec 07 17:34:24 volumio-pool dhcpcd[841]: wlan0: changing route to 192.168.1.0/24 Dec 07 17:34:24 volumio-pool dhcpcd[841]: wlan0: changing default route via 192.168.1.1 Dec 07 17:34:24 volumio-pool systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Dec 07 17:34:24 volumio-pool systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Dec 07 17:34:24 volumio-pool systemd[1]: welcome.service: Deactivated successfully. Dec 07 17:34:24 volumio-pool systemd[1]: Stopped welcome.service - Show a welcome message on console. Dec 07 17:34:24 volumio-pool systemd[1]: Stopping welcome.service - Show a welcome message on console... Dec 07 17:34:25 volumio-pool systemd[1]: Starting welcome.service - Show a welcome message on console... Dec 07 17:34:25 volumio-pool welcome[3221]: Resolved ip:[1] 192.168.1.125 Dec 07 17:34:25 volumio-pool systemd[1]: Finished welcome.service - Show a welcome message on console. Dec 07 17:34:25 volumio-pool systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Dec 07 17:34:30 volumio-pool wpa_supplicant[1167]: RRM: Ignoring radio measurement request: Not RRM network Dec 07 17:34:32 volumio-pool volumio[1269]: info: CoreCommandRouter::volumioGetState Dec 07 17:34:32 volumio-pool volumio[1269]: info: CorePlayQueue::getTrack 0 Dec 07 17:34:36 volumio-pool wpa_supplicant[1167]: RRM: Ignoring radio measurement request: Not RRM network Dec 07 17:34:40 volumio-pool go-librespot[1545]: time="2025-12-07T17:34:40+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Dec 07 17:34:40 volumio-pool systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 17:34:40 volumio-pool systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 17:34:40 volumio-pool volumio[1269]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Dec 07 17:34:40 volumio-pool volumio[1269]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 07 17:34:40 volumio-pool volumio[1269]: Error: socket hang up Dec 07 17:34:40 volumio-pool volumio[1269]: at connResetException (node:internal/errors:720:14) Dec 07 17:34:40 volumio-pool volumio[1269]: at Socket.socketOnEnd (node:_http_client:519:23) Dec 07 17:34:40 volumio-pool volumio[1269]: at Socket.emit (node:events:526:35) Dec 07 17:34:40 volumio-pool volumio[1269]: at endReadableNT (node:internal/streams/readable:1376:12) Dec 07 17:34:40 volumio-pool volumio[1269]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Dec 07 17:34:40 volumio-pool volumio[1269]: code: 'ECONNRESET', Dec 07 17:34:40 volumio-pool volumio[1269]: response: undefined Dec 07 17:34:40 volumio-pool volumio[1269]: } Dec 07 17:34:40 volumio-pool volumio[1269]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 07 17:34:41 volumio-pool sudo[3273]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-07 17:33' Dec 07 17:34:41 volumio-pool sudo[3273]: 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="ec1ce6b3390e13e82b9cc0453f957c4f5298419e" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="8bcc10c3dbcbcb349e9887dc0527d54876b32688" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon Nov 17 16:31:40 UTC 2025" VOLUMIO_VERSION="4.071" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5fbe1bcf6936184712979c0bfaf061f2"