Dec 05 21:50:00 volumio volumio[4442]: info: CALLMETHOD: system_controller network saveHotspotSettings [object Object] Dec 05 21:50:00 volumio volumio[4442]: info: CoreCommandRouter::executeOnPlugin: network , saveHotspotSettings Dec 05 21:50:01 volumio volumio[4442]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 05 21:50:01 volumio volumio[4442]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Dec 05 21:50:01 volumio volumio[4442]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:01 volumio volumio[4442]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:01 volumio sudo[4868]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/hostapd/hostapd.conf Dec 05 21:50:01 volumio sudo[4868]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:01 volumio sudo[4868]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:01 volumio volumio[4442]: info: Permissions for /etc/hostapd/hostapd.conf Dec 05 21:50:01 volumio volumio[4442]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , onNetworkingRestart Dec 05 21:50:01 volumio volumio[4442]: info: Discovery: Restarting Advertising due to device name change Dec 05 21:50:01 volumio sudo[4871]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart wireless.service Dec 05 21:50:01 volumio sudo[4871]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:01 volumio systemd[1]: Stopping wireless.service - Wireless Services... Dec 05 21:50:01 volumio systemd[1]: wireless.service: Killing process 2970 (wpa_supplicant) with signal SIGKILL. Dec 05 21:50:01 volumio systemd[1]: wireless.service: Deactivated successfully. Dec 05 21:50:01 volumio systemd[1]: Stopped wireless.service - Wireless Services. Dec 05 21:50:01 volumio systemd[1]: wireless.service: Consumed 1min 12.293s CPU time. Dec 05 21:50:02 volumio systemd[1]: Starting wireless.service - Wireless Services... Dec 05 21:50:02 volumio volumio[4442]: info: Getting Spotify volume Dec 05 21:50:02 volumio volumio[4442]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Dec 05 21:50:02 volumio volumio[4442]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:02 volumio volumio[4442]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:02 volumio volumio[4442]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Dec 05 21:50:02 volumio volumio[4442]: SPOTIFY: SPOTIFY VOLUME undefined Dec 05 21:50:02 volumio volumio[4442]: SPOTIFY: VOLUMIO VOLUME 86 Dec 05 21:50:02 volumio volumio[4442]: info: Aligning Spotify Volume to Volumio Volume Dec 05 21:50:02 volumio volumio[4442]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:02 volumio volumio[4442]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:02 volumio volumio[4442]: info: Setting Spotify Volume from Volumio: 86 Dec 05 21:50:02 volumio volumio[4442]: info: Discovery: A device disappeared from network Dec 05 21:50:02 volumio volumio[4442]: info: Discovery: Device volumio disappeared from network Dec 05 21:50:02 volumio volumio[4442]: info: Discovery: A device disappeared from network Dec 05 21:50:02 volumio wireless.js[4873]: WIRELESS.JS: Single Network Mode enabled, only one network device can be active at a time between ethernet and wireless Dec 05 21:50:02 volumio wireless.js[4873]: WIRELESS.JS: Wireless.js initializing wireless flow Dec 05 21:50:02 volumio wireless.js[4873]: WIRELESS.JS: Cleaning previous... Dec 05 21:50:02 volumio sudo[4891]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ip addr flush dev wlan0 Dec 05 21:50:02 volumio sudo[4891]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 05 21:50:02 volumio avahi-daemon[3057]: Withdrawing address record for 192.168.178.87 on wlan0. Dec 05 21:50:02 volumio dhcpcd[800]: wlan0: pid 4892 deleted IP address 192.168.178.87/24 Dec 05 21:50:02 volumio dhcpcd[800]: wlan0: deleting route to 192.168.178.0/24 Dec 05 21:50:02 volumio avahi-daemon[3057]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.178.87. Dec 05 21:50:02 volumio avahi-daemon[3057]: Interface wlan0.IPv4 no longer relevant for mDNS. Dec 05 21:50:02 volumio sudo[4891]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:02 volumio dhcpcd[800]: wlan0: deleting default route via 192.168.178.1 Dec 05 21:50:02 volumio sudo[4894]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ifconfig wlan0 down Dec 05 21:50:02 volumio sudo[4894]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 05 21:50:02 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Dec 05 21:50:02 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Dec 05 21:50:02 volumio systemd[1]: welcome.service: Deactivated successfully. Dec 05 21:50:02 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Dec 05 21:50:02 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... Dec 05 21:50:02 volumio dhcpcd[800]: wlan0: rebinding lease of 192.168.178.87 Dec 05 21:50:03 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Dec 05 21:50:03 volumio volumio[4442]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 05 21:50:03 volumio volumio[4442]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:50:03 volumio volumio[4442]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 05 21:50:03 volumio dhcpcd[800]: wlan0: carrier lost Dec 05 21:50:03 volumio sudo[4894]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:03 volumio welcome[4907]: Resolved ip:[0] Dec 05 21:50:03 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Dec 05 21:50:03 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Dec 05 21:50:03 volumio go-librespot[4858]: time="2025-12-05T21:50:03+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Dec 05 21:50:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 21:50:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 21:50:03 volumio volumio[4442]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 05 21:50:03 volumio wireless.js[4873]: WIRELESS.JS: Stopped aP Dec 05 21:50:03 volumio volumio[4442]: Error: socket hang up Dec 05 21:50:03 volumio volumio[4442]: at connResetException (node:internal/errors:720:14) Dec 05 21:50:03 volumio volumio[4442]: at Socket.socketOnEnd (node:_http_client:519:23) Dec 05 21:50:03 volumio volumio[4442]: at Socket.emit (node:events:526:35) Dec 05 21:50:03 volumio volumio[4442]: at endReadableNT (node:internal/streams/readable:1376:12) Dec 05 21:50:03 volumio volumio[4442]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Dec 05 21:50:03 volumio volumio[4442]: code: 'ECONNRESET', Dec 05 21:50:03 volumio volumio[4442]: response: undefined Dec 05 21:50:03 volumio volumio[4442]: } Dec 05 21:50:03 volumio volumio[4442]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 05 21:50:03 volumio sudo[4935]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Dec 05 21:50:03 volumio sudo[4935]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:03 volumio sudo[4935]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:03 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Dec 05 21:50:03 volumio sudo[4940]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Dec 05 21:50:03 volumio sudo[4940]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:03 volumio sudo[4940]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:03 volumio sudo[4956]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Dec 05 21:50:03 volumio sudo[4956]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:03 volumio sudo[4956]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:03 volumio sudo[4959]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Dec 05 21:50:03 volumio sudo[4959]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:04 volumio sudo[4959]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:04 volumio wireless.js[4873]: WIRELESS.JS: SETTING APPROPRIATE REG DOMAIN: DE Dec 05 21:50:04 volumio sudo[4965]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-05 21:49' Dec 05 21:50:04 volumio sudo[4965]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:04 volumio sudo[4968]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Dec 05 21:50:04 volumio sudo[4968]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:04 volumio sudo[4968]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:04 volumio sudo[4971]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set DE Dec 05 21:50:04 volumio sudo[4971]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:04 volumio sudo[4971]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:04 volumio wireless.js[4873]: WIRELESS.JS: SUCCESSFULLY SET NEW REGDOMAIN: DE Dec 05 21:50:04 volumio wireless.js[4873]: WIRELESS.JS: Start wireless flow Dec 05 21:50:04 volumio wireless.js[4873]: WIRELESS.JS: Stopped hotspot (if there).. Dec 05 21:50:04 volumio sudo[4979]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ip addr flush dev wlan0 Dec 05 21:50:04 volumio sudo[4979]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 05 21:50:04 volumio sudo[4979]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:04 volumio sudo[4981]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ifconfig wlan0 down Dec 05 21:50:04 volumio sudo[4981]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 05 21:50:04 volumio sudo[4965]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:05 volumio volumio-remote-updater[2115]: [2025-12-05 21:50:05] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 05 21:50:05 volumio volumio-remote-updater[2115]: [2025-12-05 21:50:05] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 05 21:50:05 volumio sudo[4981]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:05 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 05 21:50:05 volumio sudo[4871]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:05 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 05 21:50:05 volumio systemd[1]: volumio.service: Consumed 30.771s CPU time. Dec 05 21:50:05 volumio wireless.js[4873]: WIRELESS.JS: DHCP IP fallback Dec 05 21:50:05 volumio wireless.js[4873]: WIRELESS.JS: Start ap Dec 05 21:50:05 volumio wpa_supplicant[4998]: Successfully initialized wpa_supplicant Dec 05 21:50:05 volumio sudo[5000]: root : PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Dec 05 21:50:05 volumio sudo[5000]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 05 21:50:05 volumio dhcpcd[800]: ps_ctl_dispatch: cannot handle another client Dec 05 21:50:05 volumio dhcpcd[800]: control_free: No such file or directory Dec 05 21:50:05 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Dec 05 21:50:05 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 05 21:50:05 volumio sudo[5000]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:05 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Dec 05 21:50:05 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 4. Dec 05 21:50:05 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 05 21:50:05 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 05 21:50:05 volumio systemd[1]: volumio.service: Consumed 30.771s CPU time. Dec 05 21:50:05 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Dec 05 21:50:05 volumio wpa_supplicant[5009]: wlan0: Trying to associate with 74:42:7f:6e:2f:72 (SSID='FRITZ!Box 7530 VV' freq=2472 MHz) Dec 05 21:50:06 volumio wpa_supplicant[5009]: wlan0: Associated with 74:42:7f:6e:2f:72 Dec 05 21:50:06 volumio wpa_supplicant[5009]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Dec 05 21:50:06 volumio wpa_supplicant[5009]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=DE Dec 05 21:50:06 volumio wpa_supplicant[5009]: wlan0: WPA: Key negotiation completed with 74:42:7f:6e:2f:72 [PTK=CCMP GTK=CCMP] Dec 05 21:50:06 volumio wpa_supplicant[5009]: wlan0: CTRL-EVENT-CONNECTED - Connection to 74:42:7f:6e:2f:72 completed [id=0 id_str=] Dec 05 21:50:06 volumio dhcpcd[800]: wlan0: carrier acquired Dec 05 21:50:06 volumio dhcpcd[800]: wlan0: IAID eb:d1:85:6e Dec 05 21:50:06 volumio wireless.js[4873]: WIRELESS.JS: trying... Dec 05 21:50:06 volumio sudo[5019]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 05 21:50:06 volumio sudo[5019]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:06 volumio sudo[5019]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Dec 05 21:50:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 21:50:07 volumio dhcpcd[800]: wlan0: soliciting an IPv6 router Dec 05 21:50:07 volumio dhcpcd[800]: wlan0: rebinding lease of 192.168.178.87 Dec 05 21:50:07 volumio dhcpcd[800]: wlan0: probing address 192.168.178.87/24 Dec 05 21:50:07 volumio wireless.js[4873]: WIRELESS.JS: trying... Dec 05 21:50:07 volumio sudo[5025]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 05 21:50:07 volumio sudo[5025]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:07 volumio sudo[5025]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:07 volumio ntpd[952]: IO: Deleting interface #5 wlan0, 192.168.178.87#123, interface stats: received=33, sent=121, dropped=2, active_time=216 secs Dec 05 21:50:07 volumio ntpd[952]: PROTO: 185.232.69.65 unlink local addr 192.168.178.87 -> Dec 05 21:50:07 volumio ntpd[952]: PROTO: 88.198.200.96 unlink local addr 192.168.178.87 -> Dec 05 21:50:07 volumio ntpd[952]: PROTO: 5.75.181.179 unlink local addr 192.168.178.87 -> Dec 05 21:50:07 volumio ntpd[952]: PROTO: 213.209.109.44 unlink local addr 192.168.178.87 -> Dec 05 21:50:07 volumio ntpd[952]: PROTO: 162.19.170.154 unlink local addr 192.168.178.87 -> Dec 05 21:50:07 volumio ntpd[952]: PROTO: 94.130.184.193 unlink local addr 192.168.178.87 -> Dec 05 21:50:07 volumio ntpd[952]: PROTO: 162.159.200.123 unlink local addr 192.168.178.87 -> Dec 05 21:50:07 volumio ntpd[952]: PROTO: 193.32.222.35 unlink local addr 192.168.178.87 -> Dec 05 21:50:07 volumio ntpd[952]: PROTO: 185.233.107.180 unlink local addr 192.168.178.87 -> Dec 05 21:50:07 volumio ntpd[952]: PROTO: 91.98.67.74 unlink local addr 192.168.178.87 -> Dec 05 21:50:07 volumio ntpd[952]: PROTO: 157.230.98.101 unlink local addr 192.168.178.87 -> Dec 05 21:50:07 volumio ntpd[952]: PROTO: 5.1.73.50 unlink local addr 192.168.178.87 -> Dec 05 21:50:07 volumio ntpd[952]: PROTO: 144.91.126.59 unlink local addr 192.168.178.87 -> Dec 05 21:50:07 volumio ntpd[952]: PROTO: 152.53.191.142 unlink local addr 192.168.178.87 -> Dec 05 21:50:07 volumio ntpd[952]: PROTO: 62.113.219.231 unlink local addr 192.168.178.87 -> Dec 05 21:50:07 volumio ntpd[952]: PROTO: 212.132.108.186 unlink local addr 192.168.178.87 -> Dec 05 21:50:08 volumio wireless.js[4873]: WIRELESS.JS: trying... Dec 05 21:50:08 volumio sudo[5029]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 05 21:50:08 volumio sudo[5029]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:08 volumio sudo[5029]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:09 volumio wireless.js[4873]: WIRELESS.JS: trying... Dec 05 21:50:09 volumio sudo[5033]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 05 21:50:09 volumio sudo[5033]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:09 volumio sudo[5033]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:10 volumio volumio-remote-updater[2115]: [2025-12-05 21:50:10] [info] asio async_connect error: asio.system:111 (Connection refused) Dec 05 21:50:10 volumio volumio-remote-updater[2115]: [2025-12-05 21:50:10] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected) Dec 05 21:50:10 volumio volumio-remote-updater[2115]: [2025-12-05 21:50:10] [error] handle_connect error: Connection refused Dec 05 21:50:10 volumio wireless.js[4873]: WIRELESS.JS: trying... Dec 05 21:50:10 volumio sudo[5037]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 05 21:50:10 volumio sudo[5037]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:10 volumio sudo[5037]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:11 volumio wireless.js[4873]: WIRELESS.JS: trying... Dec 05 21:50:11 volumio sudo[5041]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 05 21:50:11 volumio sudo[5041]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:11 volumio sudo[5041]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:11 volumio dhcpcd[800]: wlan0: leased 192.168.178.87 for 864000 seconds Dec 05 21:50:11 volumio avahi-daemon[3057]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.178.87. Dec 05 21:50:11 volumio avahi-daemon[3057]: New relevant interface wlan0.IPv4 for mDNS. Dec 05 21:50:11 volumio avahi-daemon[3057]: Registering new address record for 192.168.178.87 on wlan0.IPv4. Dec 05 21:50:11 volumio dhcpcd[800]: wlan0: adding route to 192.168.178.0/24 Dec 05 21:50:11 volumio dhcpcd[800]: wlan0: adding default route via 192.168.178.1 Dec 05 21:50:11 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Dec 05 21:50:11 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Dec 05 21:50:11 volumio systemd[1]: welcome.service: Deactivated successfully. Dec 05 21:50:11 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Dec 05 21:50:11 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... Dec 05 21:50:11 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Dec 05 21:50:11 volumio welcome[5061]: Resolved ip:[1] 192.168.178.87 Dec 05 21:50:11 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Dec 05 21:50:11 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Dec 05 21:50:12 volumio wireless.js[4873]: WIRELESS.JS: trying... Dec 05 21:50:12 volumio sudo[5071]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 05 21:50:12 volumio sudo[5071]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:12 volumio sudo[5071]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:12 volumio wireless.js[4873]: WIRELESS.JS: Connected to: ----FRITZ!Box 7530 VV---- Dec 05 21:50:12 volumio sudo[5074]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 05 21:50:12 volumio sudo[5074]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 05 21:50:12 volumio sudo[5074]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:12 volumio wireless.js[4873]: WIRELESS.JS: ... joined AP, wlan0 IPv4 is 192.168.178.87, ipV6 is undefined Dec 05 21:50:12 volumio wireless.js[4873]: WIRELESS.JS: It's done! AP Dec 05 21:50:12 volumio wireless.js[4873]: WIRELESS.JS: Restarting avahi-daemon... Dec 05 21:50:12 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 05 21:50:12 volumio wireless.js[4873]: WIRELESS.JS: Notified systemd about wireless ready Dec 05 21:50:12 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 05 21:50:12 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 05 21:50:12 volumio systemd[1]: shairport-sync.service: Consumed 1.813s CPU time. Dec 05 21:50:12 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Dec 05 21:50:12 volumio systemd[1]: Started wireless.service - Wireless Services. Dec 05 21:50:12 volumio avahi-daemon[3057]: Got SIGTERM, quitting. Dec 05 21:50:12 volumio systemd[1]: Stopping avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Dec 05 21:50:12 volumio avahi-daemon[3057]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.178.87. Dec 05 21:50:12 volumio avahi-daemon[3057]: Leaving mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Dec 05 21:50:12 volumio avahi-daemon[3057]: avahi-daemon 0.8 exiting. Dec 05 21:50:12 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Dec 05 21:50:12 volumio dbus-daemon[709]: [system] Activating via systemd: service name='org.freedesktop.Avahi' unit='dbus-org.freedesktop.Avahi.service' requested by ':1.52' (uid=0 pid=1167 comm="/usr/sbin/smbd --foreground --no-process-group") Dec 05 21:50:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 21:50:12 volumio systemd[1]: avahi-daemon.service: Deactivated successfully. Dec 05 21:50:12 volumio systemd[1]: Stopped avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Dec 05 21:50:12 volumio go-librespot[5083]: go-librespot daemon starting... Dec 05 21:50:12 volumio systemd[1]: Starting avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Dec 05 21:50:12 volumio avahi-daemon[5086]: Process 3057 died: No such process; trying to remove PID file. (/run/avahi-daemon//pid) Dec 05 21:50:12 volumio avahi-daemon[5086]: Found user 'avahi' (UID 103) and group 'avahi' (GID 109). Dec 05 21:50:12 volumio avahi-daemon[5086]: Successfully dropped root privileges. Dec 05 21:50:12 volumio avahi-daemon[5086]: avahi-daemon 0.8 starting up. Dec 05 21:50:12 volumio go-librespot[5084]: time="2025-12-05T21:50:12+01:00" level=info msg="running go-librespot 0.4.0" Dec 05 21:50:12 volumio go-librespot[5084]: time="2025-12-05T21:50:12+01:00" level=debug msg="app state loaded" Dec 05 21:50:12 volumio go-librespot[5084]: time="2025-12-05T21:50:12+01:00" level=debug msg="stored credentials not found" Dec 05 21:50:12 volumio go-librespot[5084]: time="2025-12-05T21:50:12+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 21:50:12 volumio dbus-daemon[709]: [system] Successfully activated service 'org.freedesktop.Avahi' Dec 05 21:50:12 volumio systemd[1]: Started avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Dec 05 21:50:12 volumio avahi-daemon[5086]: Successfully called chroot(). Dec 05 21:50:12 volumio avahi-daemon[5086]: Successfully dropped remaining capabilities. Dec 05 21:50:12 volumio avahi-daemon[5086]: No service file found in /etc/avahi/services. Dec 05 21:50:12 volumio avahi-daemon[5086]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.178.87. Dec 05 21:50:12 volumio avahi-daemon[5086]: New relevant interface wlan0.IPv4 for mDNS. Dec 05 21:50:12 volumio avahi-daemon[5086]: Joining mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Dec 05 21:50:12 volumio avahi-daemon[5086]: New relevant interface lo.IPv4 for mDNS. Dec 05 21:50:12 volumio avahi-daemon[5086]: Network interface enumeration completed. Dec 05 21:50:12 volumio avahi-daemon[5086]: Registering new address record for 192.168.178.87 on wlan0.IPv4. Dec 05 21:50:12 volumio avahi-daemon[5086]: Registering new address record for 127.0.0.1 on lo.IPv4. Dec 05 21:50:12 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 05 21:50:12 volumio go-librespot[5084]: time="2025-12-05T21:50:12+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2025-12-05T21:50:12+01:00 is before 2025-12-08T00:00:00Z" Dec 05 21:50:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 21:50:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 21:50:13 volumio avahi-daemon[5086]: Server startup complete. Host name is volumio.local. Local service cookie is 2209325401. Dec 05 21:50:13 volumio ntpd[952]: IO: Listen normally on 6 wlan0 192.168.178.87:123 Dec 05 21:50:13 volumio ntpd[952]: IO: new interface(s) found: waking up resolver Dec 05 21:50:14 volumio volumio[5082]: info: ------------------------------------------- Dec 05 21:50:14 volumio volumio[5082]: info: ----- Volumio3 ---- Dec 05 21:50:14 volumio volumio[5082]: info: ------------------------------------------- Dec 05 21:50:14 volumio volumio[5082]: info: ----- System startup ---- Dec 05 21:50:14 volumio volumio[5082]: info: ------------------------------------------- Dec 05 21:50:15 volumio volumio[5082]: info: MYVOLUMIO Environment detected Dec 05 21:50:15 volumio volumio[5082]: info: Plugin folders cleanup Dec 05 21:50:15 volumio volumio[5082]: info: Scanning into folder /volumio/app/plugins/ Dec 05 21:50:15 volumio volumio[5082]: info: Scanning category audio_interface Dec 05 21:50:15 volumio volumio[5082]: info: Scanning category miscellanea Dec 05 21:50:15 volumio volumio[5082]: info: Scanning category music_service Dec 05 21:50:15 volumio volumio[5082]: info: Scanning category plugins.json Dec 05 21:50:15 volumio volumio[5082]: info: Scanning category system_controller Dec 05 21:50:15 volumio volumio[5082]: info: Scanning category user_interface Dec 05 21:50:15 volumio volumio[5082]: info: Scanning into folder /data/plugins/ Dec 05 21:50:15 volumio volumio[5082]: info: Scanning category music_service Dec 05 21:50:15 volumio volumio[5082]: info: Plugin folders cleanup completed Dec 05 21:50:15 volumio volumio[5082]: info: ------------------------------------------- Dec 05 21:50:15 volumio volumio[5082]: info: ----- Core plugins startup ---- Dec 05 21:50:15 volumio volumio[5082]: info: ------------------------------------------- Dec 05 21:50:15 volumio volumio[5082]: info: Loading plugins from folder /volumio/app/plugins/ Dec 05 21:50:15 volumio volumio[5082]: info: Adding plugin upnp to MyMusic Plugins Dec 05 21:50:15 volumio volumio[5082]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 05 21:50:15 volumio volumio[5082]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 05 21:50:15 volumio volumio[5082]: info: Loading plugins from folder /data/plugins/ Dec 05 21:50:15 volumio volumio[5082]: info: Loading plugin "system"... Dec 05 21:50:15 volumio volumio[5082]: info: Loading plugin "appearance"... Dec 05 21:50:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Dec 05 21:50:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 21:50:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 21:50:16 volumio go-librespot[5129]: go-librespot daemon starting... Dec 05 21:50:16 volumio go-librespot[5130]: time="2025-12-05T21:50:16+01:00" level=info msg="running go-librespot 0.4.0" Dec 05 21:50:16 volumio go-librespot[5130]: time="2025-12-05T21:50:16+01:00" level=debug msg="app state loaded" Dec 05 21:50:16 volumio go-librespot[5130]: time="2025-12-05T21:50:16+01:00" level=debug msg="stored credentials not found" Dec 05 21:50:16 volumio go-librespot[5130]: time="2025-12-05T21:50:16+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 21:50:16 volumio go-librespot[5130]: time="2025-12-05T21:50:16+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2025-12-05T21:50:16+01:00 is before 2025-12-08T00:00:00Z" Dec 05 21:50:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 21:50:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 21:50:16 volumio volumio[5082]: info: Loading plugin "network"... Dec 05 21:50:16 volumio volumio[5082]: info: Refreshing Cached IP Addresses Dec 05 21:50:16 volumio sudo[5139]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 05 21:50:16 volumio sudo[5139]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:16 volumio sudo[5141]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 05 21:50:16 volumio sudo[5139]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:16 volumio sudo[5141]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:16 volumio volumio[5082]: info: Loading plugin "services"... Dec 05 21:50:16 volumio volumio[5082]: info: Loading plugin "alsa_controller"... Dec 05 21:50:16 volumio sudo[5141]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:16 volumio sudo[5149]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 05 21:50:16 volumio sudo[5149]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:16 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 05 21:50:16 volumio volumio[5082]: info: Loading plugin "wizard"... Dec 05 21:50:16 volumio volumio[5082]: info: Loading plugin "networkfs"... Dec 05 21:50:16 volumio volumio[5082]: info: Starting Udev Watcher for removable devices Dec 05 21:50:16 volumio volumio[5082]: info: Ignoring mount for partition: boot Dec 05 21:50:16 volumio volumio[5082]: info: Ignoring mount for partition: volumio Dec 05 21:50:16 volumio volumio[5082]: info: Ignoring mount for partition: volumio_data Dec 05 21:50:16 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 05 21:50:16 volumio volumio[5082]: info: Loading plugin "volumio_command_line_client"... Dec 05 21:50:16 volumio volumio[5082]: info: Loading plugin "upnp"... Dec 05 21:50:16 volumio volumio[5082]: info: [1764967816826] Starting Upmpd Daemon Dec 05 21:50:16 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 05 21:50:16 volumio volumio[5082]: info: Loading plugin "my_music"... Dec 05 21:50:16 volumio volumio[5082]: info: Loading plugin "mpd"... Dec 05 21:50:17 volumio volumio[5082]: info: Loading plugin "upnp_browser"... Dec 05 21:50:17 volumio volumio-remote-updater[2115]: [2025-12-05 21:50:17] [connect] Successful connection Dec 05 21:50:17 volumio sudo[5149]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:18 volumio volumio[5082]: info: Starting UPNP Browser Dec 05 21:50:18 volumio volumio[5082]: info: Loading plugin "alarm-clock"... Dec 05 21:50:18 volumio volumio[5082]: info: Loading plugin "airplay_emulation"... Dec 05 21:50:18 volumio volumio[5082]: info: Starting Shairport Sync Dec 05 21:50:18 volumio volumio[5082]: info: Loading plugin "last_100"... Dec 05 21:50:18 volumio volumio[5082]: info: Loading plugin "webradio"... Dec 05 21:50:19 volumio volumio[5082]: info: Loading plugin "i2s_dacs"... Dec 05 21:50:19 volumio volumio[5082]: info: I2S DAC not set, start Auto-detection Dec 05 21:50:19 volumio volumio[5082]: info: Loading plugin "volumiodiscovery"... Dec 05 21:50:19 volumio volumio[5082]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 05 21:50:19 volumio volumio[5082]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 05 21:50:19 volumio volumio[5082]: *** WARNING *** For more information see Dec 05 21:50:19 volumio volumio[5082]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 05 21:50:19 volumio volumio[5082]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 05 21:50:19 volumio volumio[5082]: *** WARNING *** For more information see Dec 05 21:50:19 volumio node[5082]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 05 21:50:19 volumio node[5082]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 05 21:50:19 volumio node[5082]: *** WARNING *** For more information see Dec 05 21:50:19 volumio node[5082]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 05 21:50:19 volumio node[5082]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 05 21:50:19 volumio node[5082]: *** WARNING *** For more information see Dec 05 21:50:19 volumio volumio[5082]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 05 21:50:19 volumio volumio[5082]: info: Discovery: Started advertising with name: Volumio Dec 05 21:50:19 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 05 21:50:19 volumio volumio[5082]: info: Loading plugin "spop"... Dec 05 21:50:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Dec 05 21:50:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 21:50:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 21:50:19 volumio go-librespot[5174]: go-librespot daemon starting... Dec 05 21:50:19 volumio go-librespot[5175]: time="2025-12-05T21:50:19+01:00" level=info msg="running go-librespot 0.4.0" Dec 05 21:50:19 volumio go-librespot[5175]: time="2025-12-05T21:50:19+01:00" level=debug msg="app state loaded" Dec 05 21:50:19 volumio go-librespot[5175]: time="2025-12-05T21:50:19+01:00" level=debug msg="stored credentials not found" Dec 05 21:50:19 volumio go-librespot[5175]: time="2025-12-05T21:50:19+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 21:50:20 volumio volumio[5082]: info: Loading plugin "outputs"... Dec 05 21:50:20 volumio volumio[5082]: info: Loading plugin "albumart"... Dec 05 21:50:20 volumio volumio[5082]: info: Plugin example_plugin is not enabled Dec 05 21:50:20 volumio volumio[5082]: info: Loading plugin "inputs"... Dec 05 21:50:20 volumio volumio[5082]: info: Loading plugin "updater_comm"... Dec 05 21:50:20 volumio volumio[5082]: info: Plugin mpdemulation is not enabled Dec 05 21:50:20 volumio volumio[5082]: info: Loading plugin "rest_api"... Dec 05 21:50:20 volumio volumio[5082]: info: Loading plugin "websocket"... Dec 05 21:50:20 volumio volumio[5082]: info: Starting Socket.io Server version 1.7.4 Dec 05 21:50:20 volumio volumio[5082]: info: Loading i18n strings for locale en Dec 05 21:50:20 volumio volumio[5082]: Updating browse sources language Dec 05 21:50:20 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 21:50:20 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 05 21:50:20 volumio volumio[5082]: info: CoreCommandRouter::initPlayerControls Dec 05 21:50:20 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:50:20 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:50:20 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:50:20 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:50:20 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:50:20 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:50:20 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:50:20 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:50:20 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 05 21:50:20 volumio volumio[5082]: Express server listening on port 3000 Dec 05 21:50:20 volumio volumio[5082]: [Metrics] WebUI: 6s 523.58ms Dec 05 21:50:20 volumio volumio[5082]: info: CoreStateMachine::resetVolumioState Dec 05 21:50:20 volumio volumio[5082]: info: CoreStateMachine::getcurrentVolume Dec 05 21:50:20 volumio volumio[5082]: info: CoreCommandRouter::volumioRetrievevolume Dec 05 21:50:20 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:50:20 volumio volumio[5082]: info: Cannot read play queue from file Dec 05 21:50:20 volumio volumio[5082]: info: Volumio Network Manager: Network status updated: 2 Dec 05 21:50:20 volumio volumio[5184]: Forking 3 albumart workers Dec 05 21:50:20 volumio volumio[5082]: verbose: New Socket.io Connection to 192.168.178.87 from 192.168.178.29 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/142.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Dec 05 21:50:20 volumio volumio-remote-updater[2115]: [2025-12-05 21:50:20] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1764967817 101 Dec 05 21:50:20 volumio volumio[5082]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 2 Dec 05 21:50:20 volumio volumio[5082]: info: VolumeController:: Volume=86 Mute =false Dec 05 21:50:20 volumio volumio[5082]: info: CoreStateMachine::pushState Dec 05 21:50:20 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:20 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 05 21:50:20 volumio volumio[5082]: info: CoreCommandRouter::volumioPushState Dec 05 21:50:20 volumio volumio[5082]: info: CoreStateMachine::updateTrackBlock Dec 05 21:50:20 volumio volumio[5082]: info: CorePlayQueue::getTrackBlock Dec 05 21:50:20 volumio volumio[5082]: info: CoreCommandRouter::volumioRetrievevolume Dec 05 21:50:21 volumio volumio[5082]: info: CoreStateMachine::setRepeat null single undefined Dec 05 21:50:21 volumio volumio[5082]: info: CoreStateMachine::pushState Dec 05 21:50:21 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:21 volumio volumio[5082]: info: CoreCommandRouter::volumioPushState Dec 05 21:50:21 volumio volumio[5082]: info: CoreStateMachine::setRandom null Dec 05 21:50:21 volumio volumio[5082]: info: CoreStateMachine::pushState Dec 05 21:50:21 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:21 volumio volumio[5082]: info: CoreCommandRouter::volumioPushState Dec 05 21:50:21 volumio volumio[5082]: info: Setting Device type: Raspberry PI Dec 05 21:50:21 volumio volumio[5082]: info: Completed loading Core Plugins Dec 05 21:50:21 volumio volumio[5082]: info: Preparing to generate the ALSA configuration file Dec 05 21:50:21 volumio volumio[5082]: info: VolumeController:: Volume=86 Mute =false Dec 05 21:50:21 volumio volumio[5082]: info: CoreStateMachine::pushState Dec 05 21:50:21 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:21 volumio volumio[5082]: info: CoreCommandRouter::volumioPushState Dec 05 21:50:21 volumio volumio[5082]: info: Asound.conf file unchanged, so no further update is needed Dec 05 21:50:21 volumio volumio[5082]: info: Output device has changed, restarting MPD Dec 05 21:50:21 volumio volumio[5082]: info: Output device has changed, restarting Shairport Sync Dec 05 21:50:21 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:50:21 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:50:21 volumio sudo[5240]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 05 21:50:21 volumio sudo[5240]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:21 volumio volumio[5082]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 05 21:50:21 volumio volumio[5082]: info: ___________ START PLUGINS ___________ Dec 05 21:50:21 volumio sudo[5242]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 05 21:50:21 volumio sudo[5242]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:21 volumio volumio[5082]: info: ControllerMpd::onStart: Initializing MPD Dec 05 21:50:21 volumio volumio[5082]: info: Creating MPD Configuration file Dec 05 21:50:21 volumio sudo[5240]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:21 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 05 21:50:21 volumio volumio[5082]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 05 21:50:21 volumio volumio[5082]: info: [1764967821309] CoreMusicLibrary::Adding element Media Servers Dec 05 21:50:21 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 21:50:21 volumio volumio[5082]: info: UPNP Browser: Client initialized successfully Dec 05 21:50:21 volumio sudo[5250]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 05 21:50:21 volumio sudo[5250]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:21 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:50:21 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:50:21 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 05 21:50:21 volumio sudo[5250]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:21 volumio sudo[5252]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 05 21:50:21 volumio sudo[5252]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:21 volumio volumio[5082]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 05 21:50:21 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:50:21 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:50:21 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 05 21:50:21 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 05 21:50:21 volumio systemd[1]: mpd.service: Consumed 4.079s CPU time. Dec 05 21:50:21 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 05 21:50:21 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 05 21:50:21 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 05 21:50:21 volumio volumio[5082]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 05 21:50:21 volumio volumio[5082]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 05 21:50:21 volumio volumio[5082]: info: [1764967821474] CoreMusicLibrary::Adding element Last_100 Dec 05 21:50:21 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 21:50:21 volumio volumio[5082]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 05 21:50:21 volumio volumio[5082]: info: [1764967821487] CoreMusicLibrary::Adding element Webradio Dec 05 21:50:21 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 21:50:21 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 05 21:50:21 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 05 21:50:21 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 05 21:50:21 volumio volumio[5082]: info: Initializing BBC Radios Dec 05 21:50:21 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 05 21:50:21 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:50:21 volumio volumio[5082]: info: Creating Spotify config file Dec 05 21:50:21 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:50:21 volumio sudo[5264]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 05 21:50:21 volumio sudo[5264]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 05 21:50:21 volumio sudo[5264]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:22 volumio volumio[5198]: Starting albumart workers Dec 05 21:50:22 volumio volumio[5082]: info: Volumio Calling Home Dec 05 21:50:22 volumio volumio[5200]: Starting albumart workers Dec 05 21:50:22 volumio volumio[5199]: Starting albumart workers Dec 05 21:50:22 volumio volumio[5082]: info: MPD Permissions set Dec 05 21:50:22 volumio volumio[5082]: info: MPD Permissions set Dec 05 21:50:22 volumio volumio[5082]: info: Spotify config file written Dec 05 21:50:23 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:50:23 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:50:23 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:50:23 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:50:23 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:50:23 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:50:23 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:50:23 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:50:23 volumio sudo[5284]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 05 21:50:23 volumio sudo[5284]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:23 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:50:23 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:50:23 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:50:23 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:50:23 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:50:23 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:50:23 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:50:23 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:50:23 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:50:23 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:50:23 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 05 21:50:23 volumio systemd[1]: go-librespot-daemon.service: Killing process 5180 (go-librespot) with signal SIGKILL. Dec 05 21:50:23 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 05 21:50:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 21:50:23 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:50:23 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:50:23 volumio volumio[5082]: info: No need to fix Spotify hosts Dec 05 21:50:23 volumio volumio[5082]: info: Starting Shairport Sync Dec 05 21:50:23 volumio volumio[5082]: info: Starting Shairport Sync Dec 05 21:50:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 21:50:23 volumio go-librespot[5296]: go-librespot daemon starting... Dec 05 21:50:23 volumio volumio[5082]: info: Starting Shairport Sync Dec 05 21:50:23 volumio sudo[5284]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:23 volumio go-librespot[5300]: time="2025-12-05T21:50:23+01:00" level=info msg="running go-librespot 0.4.0" Dec 05 21:50:23 volumio go-librespot[5300]: time="2025-12-05T21:50:23+01:00" level=debug msg="app state loaded" Dec 05 21:50:23 volumio go-librespot[5300]: time="2025-12-05T21:50:23+01:00" level=debug msg="stored credentials not found" Dec 05 21:50:23 volumio go-librespot[5300]: time="2025-12-05T21:50:23+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 21:50:23 volumio sudo[5301]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 05 21:50:23 volumio sudo[5299]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 05 21:50:23 volumio sudo[5299]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:23 volumio sudo[5301]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:23 volumio volumio[5082]: verbose: New Socket.io Connection to 192.168.178.87 from 192.168.178.29 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/142.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Dec 05 21:50:23 volumio sudo[5308]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 05 21:50:23 volumio sudo[5308]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:23 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 05 21:50:23 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 05 21:50:23 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 05 21:50:23 volumio systemd[1]: shairport-sync.service: Consumed 1.744s CPU time. Dec 05 21:50:23 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 05 21:50:23 volumio sudo[5301]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:23 volumio volumio[5082]: info: Shairport-Sync Started Dec 05 21:50:23 volumio volumio[5082]: Error adding Membership: Error: addMembership EINVAL Dec 05 21:50:23 volumio sudo[5299]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:23 volumio volumio[5082]: info: Shairport-Sync Started Dec 05 21:50:23 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 05 21:50:23 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 05 21:50:23 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 05 21:50:23 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 05 21:50:23 volumio sudo[5308]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:23 volumio volumio[5082]: info: Shairport-Sync Started Dec 05 21:50:24 volumio volumio[5082]: info: Volumio called home Dec 05 21:50:24 volumio go-librespot[5300]: time="2025-12-05T21:50:24+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2025-12-05T21:50:24+01:00 is before 2025-12-08T00:00:00Z" Dec 05 21:50:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 21:50:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 21:50:25 volumio volumio[5082]: verbose: New Socket.io Connection to 192.168.178.87 from 192.168.178.29 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/142.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Dec 05 21:50:25 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 05 21:50:25 volumio volumio[5082]: info: CoreCommandRouter::volumioGetVisibleSources Dec 05 21:50:25 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 21:50:25 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:25 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:25 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:25 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:25 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 05 21:50:25 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 05 21:50:25 volumio volumio[5082]: info: Received Get System Info Dec 05 21:50:25 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 05 21:50:25 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 05 21:50:25 volumio volumio[5082]: info: Discovery: Getting this device information Dec 05 21:50:25 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:25 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:25 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 05 21:50:25 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:25 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:25 volumio volumio[5082]: info: Listing playlists Dec 05 21:50:26 volumio volumio[5082]: info: Discovery: adding 8d974fe2-35f1-46b1-815d-b73a3d8dcd47 Dec 05 21:50:26 volumio volumio[5082]: info: Discovery: Found device Volumio Dec 05 21:50:26 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:26 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:26 volumio volumio[5082]: info: Discovery: this is already registered, 8d974fe2-35f1-46b1-815d-b73a3d8dcd47 Dec 05 21:50:26 volumio volumio[5082]: info: Discovery: Found device Volumio Dec 05 21:50:26 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:26 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:26 volumio volumio[5082]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Dec 05 21:50:26 volumio kernel: hwmon hwmon1: Undervoltage detected! Dec 05 21:50:26 volumio volumio[5082]: info: go-librespot daemon successfully initialized Dec 05 21:50:26 volumio volumio[5082]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 05 21:50:26 volumio volumio[5082]: SPOTIFY: BQCjhzWELWhZfc_mT9pDHrymU8cGveFQmglmOiYjvb2u8vqpiEJRoyhPDuWdNQoBGvWNghA6CTJQm7WjkuEaOXzHz96l9wesC_l6eDdumzUF_rM1NQ1xaa1Q5uTZfbW9OhIGaXcQtfzDUN2PYe2F6CNcYsDiQKCs-YP9y_Bbl2MLEJcHYkX81TyrlPXI5EK9ixH6ggPDPeKrD0sVF12N5V9011oYsfRk7ENF7IEF9AjZB0EyNChCgmsy3Bir4RnVuROERDOAs_nR862MlaaUSh85nGbmfO--nDx4 Dec 05 21:50:26 volumio volumio[5082]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 05 21:50:26 volumio volumio[5082]: info: New Spotify access token = BQCjhzWELWhZfc_mT9pDHrymU8cGveFQmglmOiYjvb2u8vqpiEJRoyhPDuWdNQoBGvWNghA6CTJQm7WjkuEaOXzHz96l9wesC_l6eDdumzUF_rM1NQ1xaa1Q5uTZfbW9OhIGaXcQtfzDUN2PYe2F6CNcYsDiQKCs-YP9y_Bbl2MLEJcHYkX81TyrlPXI5EK9ixH6ggPDPeKrD0sVF12N5V9011oYsfRk7ENF7IEF9AjZB0EyNChCgmsy3Bir4RnVuROERDOAs_nR862MlaaUSh85nGbmfO--nDx4 Dec 05 21:50:26 volumio volumio[5082]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 05 21:50:26 volumio volumio[5082]: error: Failed to retrieve user informations: Error: certificate is not yet valid Dec 05 21:50:26 volumio volumio[5082]: error: Spotify credentials failed to read user data: Dec 05 21:50:26 volumio volumio[5082]: info: An error occurred while initializing Spotify Browsing facility: Dec 05 21:50:26 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:26 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:26 volumio sudo[5367]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 05 21:50:26 volumio sudo[5367]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:26 volumio sudo[5367]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:26 volumio sudo[5369]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 05 21:50:26 volumio sudo[5369]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:26 volumio sudo[5369]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:26 volumio sudo[5372]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 05 21:50:26 volumio sudo[5372]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:27 volumio sudo[5372]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:27 volumio volumio[5082]: info: Upmpdcli Daemon Started Dec 05 21:50:27 volumio mpd[5279]: 2025-12-05T21:50:27 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 05 21:50:27 volumio systemd[1]: Started mpd.service - Music Player Daemon. Dec 05 21:50:27 volumio sudo[5252]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:27 volumio sudo[5242]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:27 volumio volumio[5082]: info: Completed starting Core Plugins Dec 05 21:50:27 volumio volumio[5082]: info: ------------------------------------------- Dec 05 21:50:27 volumio volumio[5082]: info: ----- MyVolumio plugins startup ---- Dec 05 21:50:27 volumio volumio[5082]: info: ------------------------------------------- Dec 05 21:50:27 volumio volumio[5082]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 05 21:50:27 volumio volumio[5082]: error: MPD error: The expression evaluated to a falsy value: Dec 05 21:50:27 volumio volumio[5082]: assert.ok(self.idling) Dec 05 21:50:27 volumio volumio[5082]: error: The expression evaluated to a falsy value: Dec 05 21:50:27 volumio volumio[5082]: assert.ok(self.idling) Dec 05 21:50:27 volumio volumio[5082]: info: MPD running with PID5279 Dec 05 21:50:27 volumio volumio[5082]: ,establishing connection Dec 05 21:50:27 volumio volumio[5082]: error: updateQueue error: null Dec 05 21:50:27 volumio volumio[5082]: error: updateQueue error: null Dec 05 21:50:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 05 21:50:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 21:50:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 21:50:28 volumio go-librespot[5381]: go-librespot daemon starting... Dec 05 21:50:28 volumio go-librespot[5382]: time="2025-12-05T21:50:28+01:00" level=info msg="running go-librespot 0.4.0" Dec 05 21:50:28 volumio go-librespot[5382]: time="2025-12-05T21:50:28+01:00" level=debug msg="app state loaded" Dec 05 21:50:28 volumio go-librespot[5382]: time="2025-12-05T21:50:28+01:00" level=debug msg="stored credentials not found" Dec 05 21:50:28 volumio go-librespot[5382]: time="2025-12-05T21:50:28+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 21:50:28 volumio go-librespot[5382]: time="2025-12-05T21:50:28+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2025-12-05T21:50:28+01:00 is before 2025-12-08T00:00:00Z" Dec 05 21:50:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 21:50:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 21:50:29 volumio volumio[5082]: info: Initializing connection to go-librespot Websocket Dec 05 21:50:29 volumio volumio[5082]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 21:50:30 volumio sudo[5393]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 05 21:50:30 volumio sudo[5393]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:30 volumio sudo[5395]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 05 21:50:30 volumio sudo[5395]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:30 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 05 21:50:30 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 05 21:50:30 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 05 21:50:30 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 05 21:50:30 volumio sudo[5393]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:30 volumio mpd_monitor.sh[5398]: MPD Monitor Service: Starting MPD Monitor Service Dec 05 21:50:30 volumio volumio[5082]: info: Successfully started MPD Monitor Dec 05 21:50:30 volumio sudo[5395]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:30 volumio volumio[5082]: info: Successfully started MPD Monitor Dec 05 21:50:30 volumio kernel: hwmon hwmon1: Voltage normalised Dec 05 21:50:31 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:31 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 05 21:50:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 21:50:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 21:50:31 volumio go-librespot[5404]: go-librespot daemon starting... Dec 05 21:50:31 volumio go-librespot[5405]: time="2025-12-05T21:50:31+01:00" level=info msg="running go-librespot 0.4.0" Dec 05 21:50:31 volumio go-librespot[5405]: time="2025-12-05T21:50:31+01:00" level=debug msg="app state loaded" Dec 05 21:50:31 volumio go-librespot[5405]: time="2025-12-05T21:50:31+01:00" level=debug msg="stored credentials not found" Dec 05 21:50:31 volumio go-librespot[5405]: time="2025-12-05T21:50:31+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 21:50:31 volumio go-librespot[5405]: time="2025-12-05T21:50:31+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2025-12-05T21:50:31+01:00 is before 2025-12-08T00:00:00Z" Dec 05 21:50:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 21:50:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 21:50:32 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 05 21:50:32 volumio volumio[5082]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 05 21:50:32 volumio volumio[5082]: info: Initializing connection to go-librespot Websocket Dec 05 21:50:32 volumio volumio[5082]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 21:50:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Dec 05 21:50:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 21:50:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 21:50:35 volumio go-librespot[5412]: go-librespot daemon starting... Dec 05 21:50:35 volumio go-librespot[5413]: time="2025-12-05T21:50:35+01:00" level=info msg="running go-librespot 0.4.0" Dec 05 21:50:35 volumio go-librespot[5413]: time="2025-12-05T21:50:35+01:00" level=debug msg="app state loaded" Dec 05 21:50:35 volumio go-librespot[5413]: time="2025-12-05T21:50:35+01:00" level=debug msg="stored credentials not found" Dec 05 21:50:35 volumio go-librespot[5413]: time="2025-12-05T21:50:35+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 21:50:35 volumio go-librespot[5413]: time="2025-12-05T21:50:35+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2025-12-05T21:50:35+01:00 is before 2025-12-08T00:00:00Z" Dec 05 21:50:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 21:50:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 21:50:35 volumio volumio[5082]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 05 21:50:35 volumio volumio[5082]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 05 21:50:35 volumio volumio[5082]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 05 21:50:35 volumio volumio[5082]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 05 21:50:35 volumio volumio[5082]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 05 21:50:35 volumio volumio[5082]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 05 21:50:35 volumio volumio[5082]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 05 21:50:35 volumio volumio[5082]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 05 21:50:35 volumio volumio[5082]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 05 21:50:35 volumio volumio[5082]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 05 21:50:35 volumio volumio[5082]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 05 21:50:35 volumio volumio[5082]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 05 21:50:35 volumio volumio[5082]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 05 21:50:35 volumio volumio[5082]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 05 21:50:35 volumio volumio[5082]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 05 21:50:35 volumio volumio[5082]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 05 21:50:35 volumio volumio[5082]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 05 21:50:35 volumio volumio[5082]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 05 21:50:35 volumio volumio[5082]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 05 21:50:35 volumio volumio[5082]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 05 21:50:35 volumio volumio[5082]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 05 21:50:35 volumio volumio[5082]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 05 21:50:35 volumio volumio[5082]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 05 21:50:35 volumio volumio[5082]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 05 21:50:35 volumio volumio[5082]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 05 21:50:35 volumio volumio[5082]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 05 21:50:35 volumio volumio[5082]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 05 21:50:35 volumio volumio[5082]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 05 21:50:35 volumio volumio[5082]: info: Adding plugin bluetooth to MyMusic Plugins Dec 05 21:50:35 volumio volumio[5082]: info: Adding plugin multiroom to MyMusic Plugins Dec 05 21:50:35 volumio volumio[5082]: info: Adding plugin metavolumio to MyMusic Plugins Dec 05 21:50:35 volumio volumio[5082]: info: Adding plugin cd_controller to MyMusic Plugins Dec 05 21:50:35 volumio volumio[5082]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 05 21:50:35 volumio volumio[5082]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 05 21:50:35 volumio volumio[5082]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 05 21:50:35 volumio volumio[5082]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 05 21:50:36 volumio volumio[5082]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 05 21:50:36 volumio volumio[5082]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 05 21:50:36 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:50:36 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:50:36 volumio volumio[5082]: info: Starting MyVolumio Remote Streaming Endpoints Dec 05 21:50:36 volumio volumio[5082]: info: MyVolumio login type: Token Dec 05 21:50:36 volumio volumio[5082]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 05 21:50:36 volumio volumio[5082]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 05 21:50:37 volumio volumio[5082]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 05 21:50:37 volumio volumio[5082]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 05 21:50:37 volumio volumio[5082]: info: Streaming services startup Dec 05 21:50:37 volumio volumio[5082]: info: Starting Streaming Daemon Dec 05 21:50:37 volumio sudo[5436]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 05 21:50:37 volumio sudo[5436]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:37 volumio volumio[5082]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 05 21:50:37 volumio sudo[5436]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:37 volumio volumio[5082]: info: Initializing connection to go-librespot Websocket Dec 05 21:50:37 volumio volumio[5082]: error: Cannot start Volumio Streaming Daemon Dec 05 21:50:37 volumio volumio[5082]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 05 21:50:37 volumio volumio[5082]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 05 21:50:37 volumio volumio[5082]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 21:50:37 volumio sudo[5444]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 05 21:50:37 volumio sudo[5444]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:37 volumio sudo[5444]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:37 volumio sudo[5446]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 05 21:50:37 volumio sudo[5446]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:37 volumio sudo[5446]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:37 volumio volumio[5082]: verbose: New Socket.io Connection to 192.168.178.87 from 192.168.178.29 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/142.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Dec 05 21:50:37 volumio sudo[5450]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 05 21:50:37 volumio sudo[5450]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:37 volumio sudo[5450]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:37 volumio sudo[5452]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 05 21:50:37 volumio sudo[5452]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:37 volumio sudo[5452]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:37 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:37 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:37 volumio volumio[5082]: info: Received Get System Info Dec 05 21:50:37 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 05 21:50:37 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 05 21:50:37 volumio volumio[5082]: info: Discovery: Getting this device information Dec 05 21:50:37 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:37 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:37 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 05 21:50:37 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:37 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:37 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 05 21:50:37 volumio volumio[5082]: info: CoreCommandRouter::volumioGetVisibleSources Dec 05 21:50:37 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 21:50:37 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:37 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:37 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:37 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:37 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 05 21:50:37 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 05 21:50:37 volumio volumio[5082]: info: Received Get System Info Dec 05 21:50:37 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 05 21:50:37 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 05 21:50:37 volumio volumio[5082]: info: Discovery: Getting this device information Dec 05 21:50:37 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:37 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:37 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 05 21:50:37 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:37 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:37 volumio volumio[5082]: info: Listing playlists Dec 05 21:50:38 volumio volumio[5082]: verbose: New Socket.io Connection to 192.168.178.87 from 192.168.178.29 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/142.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Dec 05 21:50:38 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:38 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:38 volumio volumio[5082]: info: Received Get System Info Dec 05 21:50:38 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 05 21:50:38 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 05 21:50:38 volumio volumio[5082]: info: Discovery: Getting this device information Dec 05 21:50:38 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:38 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:38 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 05 21:50:38 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:38 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:38 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 05 21:50:38 volumio volumio[5082]: info: CoreCommandRouter::volumioGetVisibleSources Dec 05 21:50:38 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 21:50:38 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:38 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:38 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:38 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:38 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 05 21:50:38 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 05 21:50:38 volumio volumio[5082]: info: Received Get System Info Dec 05 21:50:38 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 05 21:50:38 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 05 21:50:38 volumio volumio[5082]: info: Discovery: Getting this device information Dec 05 21:50:38 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:38 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:38 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 05 21:50:38 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:38 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:38 volumio volumio[5082]: info: Listing playlists Dec 05 21:50:38 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 05 21:50:38 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 05 21:50:38 volumio volumio[5082]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 05 21:50:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Dec 05 21:50:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 21:50:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 21:50:38 volumio go-librespot[5460]: go-librespot daemon starting... Dec 05 21:50:38 volumio go-librespot[5461]: time="2025-12-05T21:50:38+01:00" level=info msg="running go-librespot 0.4.0" Dec 05 21:50:38 volumio go-librespot[5461]: time="2025-12-05T21:50:38+01:00" level=debug msg="app state loaded" Dec 05 21:50:38 volumio go-librespot[5461]: time="2025-12-05T21:50:38+01:00" level=debug msg="stored credentials not found" Dec 05 21:50:38 volumio go-librespot[5461]: time="2025-12-05T21:50:38+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 21:50:38 volumio go-librespot[5461]: time="2025-12-05T21:50:38+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2025-12-05T21:50:38+01:00 is before 2025-12-08T00:00:00Z" Dec 05 21:50:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 21:50:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 21:50:38 volumio volumio[5082]: info: MyVolumio token set successfully Dec 05 21:50:38 volumio volumio[5082]: info: MYVOLUMIO: Adding device Dec 05 21:50:38 volumio volumio[5082]: info: MYVOLUMIO: Evaluating Server Dec 05 21:50:39 volumio volumio[5082]: info: MyVolumio status changed Dec 05 21:50:39 volumio volumio[5082]: info: Streaming services startup Dec 05 21:50:39 volumio volumio[5082]: info: Starting Streaming Daemon Dec 05 21:50:39 volumio volumio[5082]: info: Removing browser output: myVolumio user plan is not superstar Dec 05 21:50:39 volumio volumio[5082]: info: Removing audio output: Dec 05 21:50:39 volumio volumio[5082]: info: Stoppping Tunnel 1 Dec 05 21:50:39 volumio sudo[5489]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 05 21:50:39 volumio sudo[5489]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:39 volumio sudo[5491]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Dec 05 21:50:39 volumio sudo[5491]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:39 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 05 21:50:39 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 05 21:50:39 volumio sudo[5489]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:39 volumio volumio[5082]: error: Cannot start Volumio Streaming Daemon Dec 05 21:50:39 volumio volumio[5082]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 05 21:50:39 volumio volumio[5082]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 05 21:50:39 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 05 21:50:39 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 05 21:50:39 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 05 21:50:39 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 05 21:50:39 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 05 21:50:39 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 05 21:50:39 volumio sudo[5491]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:39 volumio volumio[5082]: info: Remote SSH Stopped Dec 05 21:50:39 volumio volumio[5082]: info: Setting Geolocation for MyVolumio to eu10 Dec 05 21:50:39 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:50:39 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:50:39 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:50:39 volumio volumio[5082]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Dec 05 21:50:39 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 05 21:50:39 volumio volumio[5082]: info: Received Get System Info Dec 05 21:50:39 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 05 21:50:39 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 05 21:50:39 volumio volumio[5082]: info: Discovery: Getting this device information Dec 05 21:50:39 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:39 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:39 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 05 21:50:40 volumio volumio[5082]: info: Updating MyVolumio device info Dec 05 21:50:40 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:50:40 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:50:40 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:50:40 volumio volumio[5082]: info: Initializing connection to go-librespot Websocket Dec 05 21:50:40 volumio volumio[5082]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 21:50:40 volumio volumio[5082]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Dec 05 21:50:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Dec 05 21:50:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 21:50:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 21:50:42 volumio go-librespot[5494]: go-librespot daemon starting... Dec 05 21:50:42 volumio go-librespot[5495]: time="2025-12-05T21:50:42+01:00" level=info msg="running go-librespot 0.4.0" Dec 05 21:50:42 volumio go-librespot[5495]: time="2025-12-05T21:50:42+01:00" level=debug msg="app state loaded" Dec 05 21:50:42 volumio go-librespot[5495]: time="2025-12-05T21:50:42+01:00" level=debug msg="stored credentials not found" Dec 05 21:50:42 volumio go-librespot[5495]: time="2025-12-05T21:50:42+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 21:50:42 volumio go-librespot[5495]: time="2025-12-05T21:50:42+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2025-12-05T21:50:42+01:00 is before 2025-12-08T00:00:00Z" Dec 05 21:50:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 21:50:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 21:50:43 volumio volumio[5082]: info: Initializing connection to go-librespot Websocket Dec 05 21:50:43 volumio volumio[5082]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 21:50:43 volumio volumio[5082]: info: MYVOLUMIO: Adding device Dec 05 21:50:43 volumio volumio[5082]: info: MYVOLUMIO: Evaluating Server Dec 05 21:50:44 volumio volumio[5082]: info: Setting Geolocation for MyVolumio to eu4 Dec 05 21:50:44 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:50:44 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:50:44 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:50:44 volumio volumio[5082]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Dec 05 21:50:45 volumio volumio[5082]: info: Updating MyVolumio device info Dec 05 21:50:45 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:50:45 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:50:45 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:50:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Dec 05 21:50:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 21:50:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 21:50:45 volumio go-librespot[5522]: go-librespot daemon starting... Dec 05 21:50:45 volumio go-librespot[5523]: time="2025-12-05T21:50:45+01:00" level=info msg="running go-librespot 0.4.0" Dec 05 21:50:45 volumio go-librespot[5523]: time="2025-12-05T21:50:45+01:00" level=debug msg="app state loaded" Dec 05 21:50:45 volumio go-librespot[5523]: time="2025-12-05T21:50:45+01:00" level=debug msg="stored credentials not found" Dec 05 21:50:45 volumio go-librespot[5523]: time="2025-12-05T21:50:45+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 21:50:45 volumio volumio[5082]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Dec 05 21:50:45 volumio go-librespot[5523]: time="2025-12-05T21:50:45+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2025-12-05T21:50:45+01:00 is before 2025-12-08T00:00:00Z" Dec 05 21:50:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 21:50:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 21:50:46 volumio volumio[5082]: info: Initializing connection to go-librespot Websocket Dec 05 21:50:46 volumio volumio[5082]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 21:50:47 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Dec 05 21:50:47 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Dec 05 21:50:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Dec 05 21:50:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 21:50:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 21:50:49 volumio go-librespot[5544]: go-librespot daemon starting... Dec 05 21:50:49 volumio go-librespot[5545]: time="2025-12-05T21:50:49+01:00" level=info msg="running go-librespot 0.4.0" Dec 05 21:50:49 volumio go-librespot[5545]: time="2025-12-05T21:50:49+01:00" level=debug msg="app state loaded" Dec 05 21:50:49 volumio go-librespot[5545]: time="2025-12-05T21:50:49+01:00" level=debug msg="stored credentials not found" Dec 05 21:50:49 volumio go-librespot[5545]: time="2025-12-05T21:50:49+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 21:50:49 volumio go-librespot[5545]: time="2025-12-05T21:50:49+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2025-12-05T21:50:49+01:00 is before 2025-12-08T00:00:00Z" Dec 05 21:50:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 21:50:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 21:50:49 volumio volumio[5082]: info: Initializing connection to go-librespot Websocket Dec 05 21:50:49 volumio volumio[5082]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 21:50:51 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 05 21:50:51 volumio volumio[5082]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Dec 05 21:50:51 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:51 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:52 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 05 21:50:52 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:50:52 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 05 21:50:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Dec 05 21:50:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 21:50:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 21:50:52 volumio go-librespot[5558]: go-librespot daemon starting... Dec 05 21:50:52 volumio go-librespot[5559]: time="2025-12-05T21:50:52+01:00" level=info msg="running go-librespot 0.4.0" Dec 05 21:50:52 volumio go-librespot[5559]: time="2025-12-05T21:50:52+01:00" level=debug msg="app state loaded" Dec 05 21:50:52 volumio go-librespot[5559]: time="2025-12-05T21:50:52+01:00" level=debug msg="stored credentials not found" Dec 05 21:50:52 volumio volumio-remote-updater[2115]: Test mode disabled Dec 05 21:50:52 volumio volumio-remote-updater[2115]: Alpha mode disabled Dec 05 21:50:52 volumio volumio-remote-updater[2115]: Alpha legacy test mode disabled Dec 05 21:50:52 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Dec 05 21:50:52 volumio go-librespot[5559]: time="2025-12-05T21:50:52+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 21:50:52 volumio volumio[5082]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Dec 05 21:50:52 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 05 21:50:52 volumio volumio[5082]: info: Initializing connection to go-librespot Websocket Dec 05 21:50:52 volumio go-librespot[5559]: time="2025-12-05T21:50:52+01:00" level=debug msg="new websocket client" Dec 05 21:50:52 volumio volumio[5082]: info: Connection to go-librespot Websocket established Dec 05 21:50:52 volumio go-librespot[5559]: time="2025-12-05T21:50:52+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2025-12-05T21:50:52+01:00 is before 2025-12-08T00:00:00Z" Dec 05 21:50:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 21:50:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 21:50:52 volumio volumio[5082]: info: Connection to go-librespot Websocket closed Dec 05 21:50:53 volumio sudo[5568]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 05 21:50:53 volumio sudo[5568]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:53 volumio sudo[5570]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 05 21:50:53 volumio sudo[5568]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:53 volumio sudo[5570]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:53 volumio sudo[5570]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:53 volumio volumio[5082]: verbose: New Socket.io Connection to 192.168.178.87 from 192.168.178.29 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/142.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Dec 05 21:50:53 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:53 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:53 volumio volumio[5082]: info: Received Get System Info Dec 05 21:50:53 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 05 21:50:53 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 05 21:50:53 volumio volumio[5082]: info: Discovery: Getting this device information Dec 05 21:50:53 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:53 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:53 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 05 21:50:53 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:53 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:53 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 05 21:50:53 volumio volumio[5082]: info: CoreCommandRouter::volumioGetVisibleSources Dec 05 21:50:53 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 21:50:53 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:53 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:53 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:53 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:53 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 05 21:50:53 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 05 21:50:53 volumio volumio[5082]: info: Received Get System Info Dec 05 21:50:53 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 05 21:50:53 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 05 21:50:53 volumio volumio[5082]: info: Discovery: Getting this device information Dec 05 21:50:53 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:53 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:53 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 05 21:50:53 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:53 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:53 volumio volumio[5082]: info: Listing playlists Dec 05 21:50:53 volumio volumio[5082]: info: Received Get System Info Dec 05 21:50:53 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 05 21:50:53 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 05 21:50:53 volumio volumio[5082]: info: Discovery: Getting this device information Dec 05 21:50:53 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:53 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:53 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 05 21:50:53 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:53 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:53 volumio volumio[5082]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 05 21:50:54 volumio volumio[5082]: info: CoreCommandRouter::volumioGetState Dec 05 21:50:54 volumio volumio[5082]: info: CorePlayQueue::getTrack 0 Dec 05 21:50:55 volumio volumio[5082]: info: Getting Spotify volume Dec 05 21:50:55 volumio volumio[5082]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 05 21:50:55 volumio volumio[5082]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 21:50:55 volumio volumio[5082]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 05 21:50:55 volumio volumio[5082]: errno: -111, Dec 05 21:50:55 volumio volumio[5082]: code: 'ECONNREFUSED', Dec 05 21:50:55 volumio volumio[5082]: syscall: 'connect', Dec 05 21:50:55 volumio volumio[5082]: address: '127.0.0.1', Dec 05 21:50:55 volumio volumio[5082]: port: 9879, Dec 05 21:50:55 volumio volumio[5082]: response: undefined Dec 05 21:50:55 volumio volumio[5082]: } Dec 05 21:50:55 volumio volumio[5082]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 05 21:50:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Dec 05 21:50:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 21:50:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 21:50:56 volumio go-librespot[5589]: go-librespot daemon starting... Dec 05 21:50:56 volumio go-librespot[5590]: time="2025-12-05T21:50:56+01:00" level=info msg="running go-librespot 0.4.0" Dec 05 21:50:56 volumio go-librespot[5590]: time="2025-12-05T21:50:56+01:00" level=debug msg="app state loaded" Dec 05 21:50:56 volumio go-librespot[5590]: time="2025-12-05T21:50:56+01:00" level=debug msg="stored credentials not found" Dec 05 21:50:56 volumio go-librespot[5590]: time="2025-12-05T21:50:56+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 21:50:56 volumio sudo[5600]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-05 21:49' Dec 05 21:50:56 volumio sudo[5600]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:50:56 volumio sudo[5600]: pam_unix(sudo:session): session closed for user root Dec 05 21:50:56 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 05 21:50:56 volumio volumio-remote-updater[2115]: [2025-12-05 21:50:56] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 05 21:50:56 volumio volumio-remote-updater[2115]: [2025-12-05 21:50:56] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 05 21:50:56 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 05 21:50:56 volumio systemd[1]: volumio.service: Consumed 31.747s CPU time. Dec 05 21:50:56 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 05 21:50:56 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Dec 05 21:50:57 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 5. Dec 05 21:50:57 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 05 21:50:57 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 05 21:50:57 volumio systemd[1]: volumio.service: Consumed 31.747s CPU time. Dec 05 21:50:57 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Dec 05 21:50:57 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Dec 05 21:50:59 volumio volumio[5626]: info: ------------------------------------------- Dec 05 21:50:59 volumio volumio[5626]: info: ----- Volumio3 ---- Dec 05 21:50:59 volumio volumio[5626]: info: ------------------------------------------- Dec 05 21:50:59 volumio volumio[5626]: info: ----- System startup ---- Dec 05 21:50:59 volumio volumio[5626]: info: ------------------------------------------- Dec 05 21:50:59 volumio volumio[5626]: info: MYVOLUMIO Environment detected Dec 05 21:50:59 volumio volumio[5626]: info: Plugin folders cleanup Dec 05 21:50:59 volumio volumio[5626]: info: Scanning into folder /volumio/app/plugins/ Dec 05 21:50:59 volumio volumio[5626]: info: Scanning category audio_interface Dec 05 21:50:59 volumio volumio[5626]: info: Scanning category miscellanea Dec 05 21:50:59 volumio volumio[5626]: info: Scanning category music_service Dec 05 21:50:59 volumio volumio[5626]: info: Scanning category plugins.json Dec 05 21:50:59 volumio volumio[5626]: info: Scanning category system_controller Dec 05 21:50:59 volumio volumio[5626]: info: Scanning category user_interface Dec 05 21:50:59 volumio volumio[5626]: info: Scanning into folder /data/plugins/ Dec 05 21:50:59 volumio volumio[5626]: info: Scanning category music_service Dec 05 21:50:59 volumio volumio[5626]: info: Plugin folders cleanup completed Dec 05 21:50:59 volumio volumio[5626]: info: ------------------------------------------- Dec 05 21:50:59 volumio volumio[5626]: info: ----- Core plugins startup ---- Dec 05 21:50:59 volumio volumio[5626]: info: ------------------------------------------- Dec 05 21:50:59 volumio volumio[5626]: info: Loading plugins from folder /volumio/app/plugins/ Dec 05 21:50:59 volumio volumio[5626]: info: Adding plugin upnp to MyMusic Plugins Dec 05 21:50:59 volumio volumio[5626]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 05 21:50:59 volumio volumio[5626]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 05 21:50:59 volumio volumio[5626]: info: Loading plugins from folder /data/plugins/ Dec 05 21:50:59 volumio volumio[5626]: info: Loading plugin "system"... Dec 05 21:50:59 volumio volumio[5626]: info: Loading plugin "appearance"... Dec 05 21:51:01 volumio volumio[5626]: info: Loading plugin "network"... Dec 05 21:51:01 volumio volumio[5626]: info: Refreshing Cached IP Addresses Dec 05 21:51:01 volumio sudo[5654]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 05 21:51:01 volumio sudo[5654]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:51:01 volumio sudo[5654]: pam_unix(sudo:session): session closed for user root Dec 05 21:51:01 volumio sudo[5656]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 05 21:51:01 volumio sudo[5656]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:51:01 volumio sudo[5656]: pam_unix(sudo:session): session closed for user root Dec 05 21:51:01 volumio volumio[5626]: info: Loading plugin "services"... Dec 05 21:51:01 volumio volumio[5626]: info: Loading plugin "alsa_controller"... Dec 05 21:51:01 volumio sudo[5664]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 05 21:51:01 volumio sudo[5664]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:51:01 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 05 21:51:01 volumio volumio[5626]: info: Loading plugin "wizard"... Dec 05 21:51:01 volumio volumio[5626]: info: Loading plugin "networkfs"... Dec 05 21:51:01 volumio volumio[5626]: info: Starting Udev Watcher for removable devices Dec 05 21:51:01 volumio volumio[5626]: info: Ignoring mount for partition: boot Dec 05 21:51:01 volumio volumio[5626]: info: Ignoring mount for partition: volumio Dec 05 21:51:01 volumio volumio[5626]: info: Ignoring mount for partition: volumio_data Dec 05 21:51:01 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 05 21:51:01 volumio volumio[5626]: info: Loading plugin "volumio_command_line_client"... Dec 05 21:51:01 volumio volumio[5626]: info: Loading plugin "upnp"... Dec 05 21:51:01 volumio volumio[5626]: info: [1764967861299] Starting Upmpd Daemon Dec 05 21:51:01 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 05 21:51:01 volumio volumio[5626]: info: Loading plugin "my_music"... Dec 05 21:51:01 volumio volumio[5626]: info: Loading plugin "mpd"... Dec 05 21:51:01 volumio volumio[5626]: info: Loading plugin "upnp_browser"... Dec 05 21:51:01 volumio volumio-remote-updater[2115]: [2025-12-05 21:51:01] [connect] Successful connection Dec 05 21:51:02 volumio sudo[5664]: pam_unix(sudo:session): session closed for user root Dec 05 21:51:03 volumio volumio[5626]: info: Starting UPNP Browser Dec 05 21:51:03 volumio volumio[5626]: info: Loading plugin "alarm-clock"... Dec 05 21:51:03 volumio volumio[5626]: info: Loading plugin "airplay_emulation"... Dec 05 21:51:03 volumio volumio[5626]: info: Starting Shairport Sync Dec 05 21:51:03 volumio volumio[5626]: info: Loading plugin "last_100"... Dec 05 21:51:03 volumio volumio[5626]: info: Loading plugin "webradio"... Dec 05 21:51:03 volumio volumio[5626]: info: Loading plugin "i2s_dacs"... Dec 05 21:51:03 volumio volumio[5626]: info: I2S DAC not set, start Auto-detection Dec 05 21:51:03 volumio volumio[5626]: info: Loading plugin "volumiodiscovery"... Dec 05 21:51:03 volumio volumio[5626]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 05 21:51:03 volumio volumio[5626]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 05 21:51:03 volumio volumio[5626]: *** WARNING *** For more information see Dec 05 21:51:03 volumio volumio[5626]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 05 21:51:03 volumio volumio[5626]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 05 21:51:03 volumio volumio[5626]: *** WARNING *** For more information see Dec 05 21:51:03 volumio node[5626]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 05 21:51:03 volumio node[5626]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 05 21:51:03 volumio node[5626]: *** WARNING *** For more information see Dec 05 21:51:03 volumio node[5626]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 05 21:51:03 volumio node[5626]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 05 21:51:03 volumio node[5626]: *** WARNING *** For more information see Dec 05 21:51:03 volumio volumio[5626]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 05 21:51:03 volumio volumio[5626]: info: Discovery: Started advertising with name: Volumio Dec 05 21:51:03 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 05 21:51:03 volumio volumio[5626]: info: Loading plugin "spop"... Dec 05 21:51:04 volumio volumio[5626]: info: Loading plugin "outputs"... Dec 05 21:51:04 volumio volumio[5626]: info: Loading plugin "albumart"... Dec 05 21:51:04 volumio volumio[5626]: info: Plugin example_plugin is not enabled Dec 05 21:51:04 volumio volumio[5626]: info: Loading plugin "inputs"... Dec 05 21:51:04 volumio volumio[5626]: info: Loading plugin "updater_comm"... Dec 05 21:51:04 volumio volumio[5626]: info: Plugin mpdemulation is not enabled Dec 05 21:51:04 volumio volumio[5626]: info: Loading plugin "rest_api"... Dec 05 21:51:04 volumio volumio[5626]: info: Loading plugin "websocket"... Dec 05 21:51:04 volumio volumio[5626]: info: Starting Socket.io Server version 1.7.4 Dec 05 21:51:04 volumio volumio[5626]: info: Loading i18n strings for locale en Dec 05 21:51:04 volumio volumio[5626]: Updating browse sources language Dec 05 21:51:04 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 21:51:05 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 05 21:51:05 volumio volumio[5626]: info: CoreCommandRouter::initPlayerControls Dec 05 21:51:05 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:51:05 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:51:05 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:51:05 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:51:05 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:51:05 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:51:05 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:51:05 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:51:05 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 05 21:51:05 volumio volumio[5626]: Express server listening on port 3000 Dec 05 21:51:05 volumio volumio[5626]: [Metrics] WebUI: 6s 523.63ms Dec 05 21:51:05 volumio volumio[5626]: info: CoreStateMachine::resetVolumioState Dec 05 21:51:05 volumio volumio[5626]: info: CoreStateMachine::getcurrentVolume Dec 05 21:51:05 volumio volumio[5626]: info: CoreCommandRouter::volumioRetrievevolume Dec 05 21:51:05 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:51:05 volumio volumio[5626]: info: Cannot read play queue from file Dec 05 21:51:05 volumio volumio[5626]: info: Volumio Network Manager: Network status updated: 2 Dec 05 21:51:05 volumio volumio[5689]: Forking 3 albumart workers Dec 05 21:51:05 volumio volumio[5626]: verbose: New Socket.io Connection to 192.168.178.87 from 192.168.178.29 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/142.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Dec 05 21:51:05 volumio volumio-remote-updater[2115]: [2025-12-05 21:51:05] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1764967861 101 Dec 05 21:51:05 volumio volumio[5626]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 2 Dec 05 21:51:05 volumio volumio[5626]: info: VolumeController:: Volume=86 Mute =false Dec 05 21:51:05 volumio volumio[5626]: info: CoreStateMachine::pushState Dec 05 21:51:05 volumio volumio[5626]: info: CorePlayQueue::getTrack 0 Dec 05 21:51:05 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 05 21:51:05 volumio volumio[5626]: info: CoreCommandRouter::volumioPushState Dec 05 21:51:05 volumio volumio[5626]: info: CoreStateMachine::updateTrackBlock Dec 05 21:51:05 volumio volumio[5626]: info: CorePlayQueue::getTrackBlock Dec 05 21:51:05 volumio volumio[5626]: info: CoreCommandRouter::volumioRetrievevolume Dec 05 21:51:05 volumio volumio[5626]: info: CoreStateMachine::setRepeat null single undefined Dec 05 21:51:05 volumio volumio[5626]: info: CoreStateMachine::pushState Dec 05 21:51:05 volumio volumio[5626]: info: CorePlayQueue::getTrack 0 Dec 05 21:51:05 volumio volumio[5626]: info: CoreCommandRouter::volumioPushState Dec 05 21:51:05 volumio volumio[5626]: info: CoreStateMachine::setRandom null Dec 05 21:51:05 volumio volumio[5626]: info: CoreStateMachine::pushState Dec 05 21:51:05 volumio volumio[5626]: info: CorePlayQueue::getTrack 0 Dec 05 21:51:05 volumio volumio[5626]: info: CoreCommandRouter::volumioPushState Dec 05 21:51:05 volumio volumio[5626]: info: Setting Device type: Raspberry PI Dec 05 21:51:05 volumio volumio[5626]: verbose: New Socket.io Connection to 192.168.178.87 from 192.168.178.29 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/142.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Dec 05 21:51:05 volumio volumio[5626]: info: Completed loading Core Plugins Dec 05 21:51:05 volumio volumio[5626]: info: Preparing to generate the ALSA configuration file Dec 05 21:51:05 volumio volumio[5626]: info: Discovery: adding 8d974fe2-35f1-46b1-815d-b73a3d8dcd47 Dec 05 21:51:05 volumio volumio[5626]: info: Discovery: Found device Volumio Dec 05 21:51:05 volumio volumio[5626]: info: CoreCommandRouter::volumioGetState Dec 05 21:51:05 volumio volumio[5626]: info: CorePlayQueue::getTrack 0 Dec 05 21:51:05 volumio volumio[5626]: info: Discovery: this is already registered, 8d974fe2-35f1-46b1-815d-b73a3d8dcd47 Dec 05 21:51:05 volumio volumio[5626]: info: Discovery: Found device Volumio Dec 05 21:51:05 volumio volumio[5626]: info: CoreCommandRouter::volumioGetState Dec 05 21:51:05 volumio volumio[5626]: info: CorePlayQueue::getTrack 0 Dec 05 21:51:05 volumio volumio[5626]: info: VolumeController:: Volume=86 Mute =false Dec 05 21:51:05 volumio volumio[5626]: info: CoreStateMachine::pushState Dec 05 21:51:05 volumio volumio[5626]: info: CorePlayQueue::getTrack 0 Dec 05 21:51:05 volumio volumio[5626]: info: CoreCommandRouter::volumioPushState Dec 05 21:51:05 volumio kernel: hwmon hwmon1: Undervoltage detected! Dec 05 21:51:05 volumio volumio[5626]: info: Asound.conf file unchanged, so no further update is needed Dec 05 21:51:05 volumio volumio[5626]: info: Output device has changed, restarting MPD Dec 05 21:51:05 volumio volumio[5626]: info: Output device has changed, restarting Shairport Sync Dec 05 21:51:05 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:51:05 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:51:05 volumio sudo[5746]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 05 21:51:05 volumio sudo[5746]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:51:05 volumio sudo[5746]: pam_unix(sudo:session): session closed for user root Dec 05 21:51:05 volumio sudo[5748]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 05 21:51:05 volumio sudo[5748]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:51:06 volumio volumio[5626]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 05 21:51:06 volumio volumio[5626]: info: ___________ START PLUGINS ___________ Dec 05 21:51:06 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 05 21:51:06 volumio volumio[5626]: info: ControllerMpd::onStart: Initializing MPD Dec 05 21:51:06 volumio volumio[5626]: info: Creating MPD Configuration file Dec 05 21:51:06 volumio go-librespot[5590]: time="2025-12-05T21:51:06+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2025-12-05T21:51:05+01:00 is before 2025-12-08T00:00:00Z" Dec 05 21:51:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 21:51:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 21:51:06 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 05 21:51:06 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 05 21:51:06 volumio systemd[1]: mpd.service: Consumed 5.558s CPU time. Dec 05 21:51:06 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 05 21:51:06 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 05 21:51:06 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 05 21:51:06 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 05 21:51:06 volumio volumio[5626]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 05 21:51:06 volumio volumio[5626]: info: [1764967866226] CoreMusicLibrary::Adding element Media Servers Dec 05 21:51:06 volumio sudo[5757]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 05 21:51:06 volumio sudo[5757]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:51:06 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 05 21:51:06 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 21:51:06 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 05 21:51:06 volumio sudo[5757]: pam_unix(sudo:session): session closed for user root Dec 05 21:51:06 volumio volumio[5626]: info: UPNP Browser: Client initialized successfully Dec 05 21:51:06 volumio sudo[5759]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 05 21:51:06 volumio sudo[5759]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:51:06 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:51:06 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:51:06 volumio volumio[5626]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 05 21:51:06 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:51:06 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:51:06 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 05 21:51:06 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 05 21:51:06 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 05 21:51:06 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 05 21:51:06 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 05 21:51:06 volumio volumio[5626]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 05 21:51:06 volumio volumio[5626]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 05 21:51:06 volumio volumio[5626]: info: [1764967866559] CoreMusicLibrary::Adding element Last_100 Dec 05 21:51:06 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 21:51:06 volumio volumio[5626]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 05 21:51:06 volumio volumio[5626]: info: [1764967866566] CoreMusicLibrary::Adding element Webradio Dec 05 21:51:06 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 21:51:06 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 05 21:51:06 volumio volumio[5626]: info: Initializing BBC Radios Dec 05 21:51:06 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 05 21:51:06 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 05 21:51:06 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 05 21:51:06 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:51:06 volumio volumio[5626]: info: Creating Spotify config file Dec 05 21:51:06 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:51:07 volumio sudo[5775]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 05 21:51:07 volumio sudo[5775]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 05 21:51:07 volumio sudo[5775]: pam_unix(sudo:session): session closed for user root Dec 05 21:51:07 volumio volumio[5626]: info: Volumio Calling Home Dec 05 21:51:08 volumio volumio[5626]: verbose: New Socket.io Connection to 192.168.178.87 from 192.168.178.29 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/142.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Dec 05 21:51:08 volumio volumio[5626]: info: MPD Permissions set Dec 05 21:51:08 volumio volumio[5626]: info: MPD Permissions set Dec 05 21:51:08 volumio volumio[5626]: info: Spotify config file written Dec 05 21:51:08 volumio volumio[5626]: info: CoreCommandRouter::volumioGetState Dec 05 21:51:08 volumio volumio[5626]: info: CorePlayQueue::getTrack 0 Dec 05 21:51:08 volumio sudo[5792]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 05 21:51:08 volumio sudo[5792]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:51:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 21:51:08 volumio volumio[5706]: Starting albumart workers Dec 05 21:51:08 volumio volumio[5705]: Starting albumart workers Dec 05 21:51:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 21:51:08 volumio go-librespot[5794]: go-librespot daemon starting... Dec 05 21:51:08 volumio sudo[5792]: pam_unix(sudo:session): session closed for user root Dec 05 21:51:08 volumio volumio[5704]: Starting albumart workers Dec 05 21:51:08 volumio volumio[5626]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Dec 05 21:51:08 volumio go-librespot[5795]: time="2025-12-05T21:51:08+01:00" level=info msg="running go-librespot 0.4.0" Dec 05 21:51:08 volumio go-librespot[5795]: time="2025-12-05T21:51:08+01:00" level=debug msg="app state loaded" Dec 05 21:51:08 volumio go-librespot[5795]: time="2025-12-05T21:51:08+01:00" level=debug msg="stored credentials not found" Dec 05 21:51:08 volumio volumio[5626]: info: Volumio called home Dec 05 21:51:08 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:51:08 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:51:08 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:51:08 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:51:08 volumio go-librespot[5795]: time="2025-12-05T21:51:08+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 21:51:08 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:51:08 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:51:08 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:51:08 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:51:09 volumio volumio[5626]: info: No need to fix Spotify hosts Dec 05 21:51:09 volumio go-librespot[5795]: time="2025-12-05T21:51:09+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2025-12-05T21:51:09+01:00 is before 2025-12-08T00:00:00Z" Dec 05 21:51:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 21:51:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 21:51:09 volumio volumio[5626]: info: Received Get System Info Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 05 21:51:09 volumio volumio[5626]: info: Discovery: Getting this device information Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::volumioGetState Dec 05 21:51:09 volumio volumio[5626]: info: CorePlayQueue::getTrack 0 Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::volumioGetState Dec 05 21:51:09 volumio volumio[5626]: info: CorePlayQueue::getTrack 0 Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::volumioGetVisibleSources Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::volumioGetState Dec 05 21:51:09 volumio volumio[5626]: info: CorePlayQueue::getTrack 0 Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::volumioGetState Dec 05 21:51:09 volumio volumio[5626]: info: CorePlayQueue::getTrack 0 Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 05 21:51:09 volumio volumio[5626]: info: Received Get System Info Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 05 21:51:09 volumio volumio[5626]: info: Discovery: Getting this device information Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::volumioGetState Dec 05 21:51:09 volumio volumio[5626]: info: CorePlayQueue::getTrack 0 Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::volumioGetState Dec 05 21:51:09 volumio volumio[5626]: info: CorePlayQueue::getTrack 0 Dec 05 21:51:09 volumio volumio[5626]: info: Listing playlists Dec 05 21:51:09 volumio volumio[5626]: info: Received Get System Info Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 05 21:51:09 volumio volumio[5626]: info: Discovery: Getting this device information Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::volumioGetState Dec 05 21:51:09 volumio volumio[5626]: info: CorePlayQueue::getTrack 0 Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::volumioGetState Dec 05 21:51:09 volumio volumio[5626]: info: CorePlayQueue::getTrack 0 Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::volumioGetVisibleSources Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::volumioGetState Dec 05 21:51:09 volumio volumio[5626]: info: CorePlayQueue::getTrack 0 Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::volumioGetState Dec 05 21:51:09 volumio volumio[5626]: info: CorePlayQueue::getTrack 0 Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 05 21:51:09 volumio volumio[5626]: info: Received Get System Info Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 05 21:51:09 volumio volumio[5626]: info: Discovery: Getting this device information Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::volumioGetState Dec 05 21:51:09 volumio volumio[5626]: info: CorePlayQueue::getTrack 0 Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::volumioGetState Dec 05 21:51:09 volumio volumio[5626]: info: CorePlayQueue::getTrack 0 Dec 05 21:51:09 volumio volumio[5626]: info: Listing playlists Dec 05 21:51:09 volumio volumio[5626]: info: Received Get System Info Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 05 21:51:09 volumio volumio[5626]: info: Discovery: Getting this device information Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::volumioGetState Dec 05 21:51:09 volumio volumio[5626]: info: CorePlayQueue::getTrack 0 Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::volumioGetState Dec 05 21:51:09 volumio volumio[5626]: info: CorePlayQueue::getTrack 0 Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::volumioGetVisibleSources Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::volumioGetState Dec 05 21:51:09 volumio volumio[5626]: info: CorePlayQueue::getTrack 0 Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::volumioGetState Dec 05 21:51:09 volumio volumio[5626]: info: CorePlayQueue::getTrack 0 Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 05 21:51:09 volumio volumio[5626]: info: Received Get System Info Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 05 21:51:09 volumio volumio[5626]: info: Discovery: Getting this device information Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::volumioGetState Dec 05 21:51:09 volumio volumio[5626]: info: CorePlayQueue::getTrack 0 Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::volumioGetState Dec 05 21:51:09 volumio volumio[5626]: info: CorePlayQueue::getTrack 0 Dec 05 21:51:09 volumio volumio[5626]: info: Listing playlists Dec 05 21:51:09 volumio volumio[5626]: info: Received Get System Info Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 05 21:51:09 volumio volumio[5626]: info: Discovery: Getting this device information Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::volumioGetState Dec 05 21:51:09 volumio volumio[5626]: info: CorePlayQueue::getTrack 0 Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 05 21:51:09 volumio volumio[5626]: info: CoreCommandRouter::volumioGetState Dec 05 21:51:09 volumio volumio[5626]: info: CorePlayQueue::getTrack 0 Dec 05 21:51:10 volumio volumio[5626]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 05 21:51:10 volumio volumio[5626]: SPOTIFY: BQCVG4FX8RKFtSvcVM2ICmli_fCWoScasco0YfDDCxKZJlFxmC3JUySXOA84wg9zErdnD_zpwCK80Ate8-8FCBMwMsZw2WGWiBKHrWtJIFXQeoQoQeLTZwJZfXNMaIzeFqSOhRKe4EHJJH-_Nnt9wg14te9pn4b5N537ZA25j1QDZtJOmbG1DNw5VdgDgM_OTwMgPlFg5RX5u5RaCRWV-Bk4D2-NP8n2nbWyY5Te36tJhzHqJ9NjniIm0LOb1UmXeirr1AZ_KSE9GPLVvzBatBOyYzRlMv162sL0 Dec 05 21:51:10 volumio volumio[5626]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 05 21:51:10 volumio volumio[5626]: info: New Spotify access token = BQCVG4FX8RKFtSvcVM2ICmli_fCWoScasco0YfDDCxKZJlFxmC3JUySXOA84wg9zErdnD_zpwCK80Ate8-8FCBMwMsZw2WGWiBKHrWtJIFXQeoQoQeLTZwJZfXNMaIzeFqSOhRKe4EHJJH-_Nnt9wg14te9pn4b5N537ZA25j1QDZtJOmbG1DNw5VdgDgM_OTwMgPlFg5RX5u5RaCRWV-Bk4D2-NP8n2nbWyY5Te36tJhzHqJ9NjniIm0LOb1UmXeirr1AZ_KSE9GPLVvzBatBOyYzRlMv162sL0 Dec 05 21:51:10 volumio volumio[5626]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 05 21:51:10 volumio volumio[5626]: info: Starting Shairport Sync Dec 05 21:51:10 volumio volumio[5626]: info: Starting Shairport Sync Dec 05 21:51:10 volumio volumio[5626]: info: Starting Shairport Sync Dec 05 21:51:10 volumio sudo[5832]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 05 21:51:10 volumio sudo[5832]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:51:10 volumio sudo[5834]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 05 21:51:10 volumio sudo[5834]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:51:10 volumio sudo[5837]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 05 21:51:10 volumio sudo[5837]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:51:10 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 05 21:51:10 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 05 21:51:10 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 05 21:51:10 volumio systemd[1]: shairport-sync.service: Consumed 1.953s CPU time. Dec 05 21:51:10 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 05 21:51:10 volumio sudo[5832]: pam_unix(sudo:session): session closed for user root Dec 05 21:51:10 volumio sudo[5837]: pam_unix(sudo:session): session closed for user root Dec 05 21:51:10 volumio sudo[5834]: pam_unix(sudo:session): session closed for user root Dec 05 21:51:10 volumio volumio[5626]: info: Shairport-Sync Started Dec 05 21:51:10 volumio volumio[5626]: Error adding Membership: Error: addMembership EINVAL Dec 05 21:51:10 volumio volumio[5626]: info: Shairport-Sync Started Dec 05 21:51:10 volumio volumio[5626]: info: Shairport-Sync Started Dec 05 21:51:11 volumio volumio[5626]: error: Failed to retrieve user informations: Error: certificate is not yet valid Dec 05 21:51:11 volumio volumio[5626]: error: Spotify credentials failed to read user data: Dec 05 21:51:11 volumio volumio[5626]: info: An error occurred while initializing Spotify Browsing facility: Dec 05 21:51:11 volumio volumio[5626]: info: CoreCommandRouter::volumioGetState Dec 05 21:51:11 volumio volumio[5626]: info: CorePlayQueue::getTrack 0 Dec 05 21:51:11 volumio sudo[5873]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 05 21:51:11 volumio sudo[5873]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:51:11 volumio sudo[5873]: pam_unix(sudo:session): session closed for user root Dec 05 21:51:11 volumio sudo[5875]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 05 21:51:11 volumio sudo[5875]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:51:11 volumio sudo[5875]: pam_unix(sudo:session): session closed for user root Dec 05 21:51:11 volumio sudo[5879]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 05 21:51:11 volumio sudo[5879]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:51:11 volumio sudo[5879]: pam_unix(sudo:session): session closed for user root Dec 05 21:51:11 volumio volumio[5626]: info: Upmpdcli Daemon Started Dec 05 21:51:11 volumio mpd[5787]: 2025-12-05T21:51:11 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 05 21:51:11 volumio systemd[1]: Started mpd.service - Music Player Daemon. Dec 05 21:51:11 volumio sudo[5748]: pam_unix(sudo:session): session closed for user root Dec 05 21:51:11 volumio sudo[5759]: pam_unix(sudo:session): session closed for user root Dec 05 21:51:11 volumio volumio[5626]: info: Completed starting Core Plugins Dec 05 21:51:11 volumio volumio[5626]: info: ------------------------------------------- Dec 05 21:51:11 volumio volumio[5626]: info: ----- MyVolumio plugins startup ---- Dec 05 21:51:11 volumio volumio[5626]: info: ------------------------------------------- Dec 05 21:51:11 volumio volumio[5626]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 05 21:51:12 volumio kernel: hwmon hwmon1: Voltage normalised Dec 05 21:51:12 volumio volumio[5626]: error: MPD error: The expression evaluated to a falsy value: Dec 05 21:51:12 volumio volumio[5626]: assert.ok(self.idling) Dec 05 21:51:12 volumio volumio[5626]: error: The expression evaluated to a falsy value: Dec 05 21:51:12 volumio volumio[5626]: assert.ok(self.idling) Dec 05 21:51:12 volumio volumio[5626]: info: MPD running with PID5787 Dec 05 21:51:12 volumio volumio[5626]: ,establishing connection Dec 05 21:51:12 volumio volumio[5626]: error: updateQueue error: null Dec 05 21:51:12 volumio volumio[5626]: error: updateQueue error: null Dec 05 21:51:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Dec 05 21:51:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 21:51:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 21:51:12 volumio go-librespot[5889]: go-librespot daemon starting... Dec 05 21:51:12 volumio go-librespot[5890]: time="2025-12-05T21:51:12+01:00" level=info msg="running go-librespot 0.4.0" Dec 05 21:51:12 volumio go-librespot[5890]: time="2025-12-05T21:51:12+01:00" level=debug msg="app state loaded" Dec 05 21:51:12 volumio go-librespot[5890]: time="2025-12-05T21:51:12+01:00" level=debug msg="stored credentials not found" Dec 05 21:51:12 volumio go-librespot[5890]: time="2025-12-05T21:51:12+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 21:51:13 volumio volumio[5626]: info: go-librespot daemon successfully initialized Dec 05 21:51:14 volumio sudo[5899]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 05 21:51:14 volumio sudo[5899]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:51:14 volumio sudo[5901]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 05 21:51:14 volumio sudo[5901]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:51:15 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 05 21:51:15 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 05 21:51:15 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 05 21:51:15 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 05 21:51:15 volumio sudo[5899]: pam_unix(sudo:session): session closed for user root Dec 05 21:51:15 volumio sudo[5901]: pam_unix(sudo:session): session closed for user root Dec 05 21:51:15 volumio mpd_monitor.sh[5904]: MPD Monitor Service: Starting MPD Monitor Service Dec 05 21:51:15 volumio volumio[5626]: info: Successfully started MPD Monitor Dec 05 21:51:15 volumio volumio[5626]: info: Successfully started MPD Monitor Dec 05 21:51:15 volumio volumio[5626]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 05 21:51:16 volumio volumio[5626]: info: Initializing connection to go-librespot Websocket Dec 05 21:51:16 volumio go-librespot[5890]: time="2025-12-05T21:51:16+01:00" level=debug msg="new websocket client" Dec 05 21:51:16 volumio volumio[5626]: info: Connection to go-librespot Websocket established Dec 05 21:51:16 volumio volumio[5626]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 05 21:51:18 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 05 21:51:19 volumio volumio[5626]: info: Getting Spotify volume Dec 05 21:51:19 volumio volumio[5626]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Dec 05 21:51:19 volumio volumio[5626]: info: CoreCommandRouter::volumioGetState Dec 05 21:51:19 volumio volumio[5626]: info: CorePlayQueue::getTrack 0 Dec 05 21:51:19 volumio volumio[5626]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Dec 05 21:51:19 volumio volumio[5626]: SPOTIFY: SPOTIFY VOLUME undefined Dec 05 21:51:19 volumio volumio[5626]: SPOTIFY: VOLUMIO VOLUME 86 Dec 05 21:51:19 volumio volumio[5626]: info: Aligning Spotify Volume to Volumio Volume Dec 05 21:51:19 volumio volumio[5626]: info: CoreCommandRouter::volumioGetState Dec 05 21:51:19 volumio volumio[5626]: info: CorePlayQueue::getTrack 0 Dec 05 21:51:19 volumio volumio[5626]: info: Setting Spotify Volume from Volumio: 86 Dec 05 21:51:20 volumio volumio[5626]: SPOTIFY: SETTING SPOTIFY VOLUME 86 Dec 05 21:51:20 volumio volumio[5626]: info: Sending Spotify command with payload to local API: /player/volume Dec 05 21:51:23 volumio volumio[5626]: info: CoreCommandRouter::Close All Modals sent Dec 05 21:51:25 volumio go-librespot[5890]: time="2025-12-05T21:51:25+01:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Dec 05 21:51:25 volumio volumio[5626]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesSpotify Dec 05 21:51:25 volumio volumio[5626]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 21:51:25 volumio volumio[5626]: info: Disabling plugin spop Dec 05 21:51:25 volumio volumio[5626]: info: Done. Dec 05 21:51:25 volumio volumio[5626]: info: Connection to go-librespot Websocket closed Dec 05 21:51:25 volumio sudo[5926]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop go-librespot-daemon.service Dec 05 21:51:25 volumio sudo[5926]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 21:51:25 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 05 21:51:25 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 05 21:51:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 21:51:25 volumio volumio[5626]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Dec 05 21:51:25 volumio volumio[5626]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 05 21:51:25 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 05 21:51:25 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 05 21:51:25 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 05 21:51:25 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 05 21:51:25 volumio volumio[5626]: Error: socket hang up Dec 05 21:51:25 volumio volumio[5626]: at connResetException (node:internal/errors:720:14) Dec 05 21:51:25 volumio volumio[5626]: at Socket.socketOnEnd (node:_http_client:519:23) Dec 05 21:51:25 volumio volumio[5626]: at Socket.emit (node:events:526:35) Dec 05 21:51:25 volumio volumio[5626]: at endReadableNT (node:internal/streams/readable:1376:12) Dec 05 21:51:25 volumio volumio[5626]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Dec 05 21:51:25 volumio volumio[5626]: code: 'ECONNRESET', Dec 05 21:51:25 volumio volumio[5626]: response: undefined Dec 05 21:51:25 volumio volumio[5626]: } Dec 05 21:51:25 volumio volumio[5626]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 05 21:51:25 volumio sudo[5926]: pam_unix(sudo:session): session closed for user root Dec 05 21:51:26 volumio sudo[5942]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-05 21:50' Dec 05 21:51:26 volumio sudo[5942]: 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="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"