Dec 30 15:47:00 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:00 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 15:47:00 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:00 volumio sudo[28179]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Dec 30 15:47:00 volumio sudo[28179]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:00 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Dec 30 15:47:00 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Dec 30 15:47:00 volumio sudo[28179]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:00 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.24.122 Dec 30 15:47:00 volumio volumio[27586]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 30 15:47:00 volumio sudo[28196]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 30 15:47:00 volumio sudo[28196]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:00 volumio volumio[27586]: info: Initializing connection to go-librespot Websocket Dec 30 15:47:01 volumio volumio[27586]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 30 15:47:01 volumio sudo[28196]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:01 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.24.122 Dec 30 15:47:01 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.24.122 Dec 30 15:47:01 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Dec 30 15:47:01 volumio avahi-daemon[664]: Withdrawing address record for 169.254.24.122 on eth0. Dec 30 15:47:01 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:01 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 15:47:01 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:01 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Dec 30 15:47:01 volumio volumio[27586]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 30 15:47:01 volumio sudo[28215]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 30 15:47:01 volumio sudo[28215]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:01 volumio sudo[28215]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:02 volumio volumio[27586]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 30 15:47:02 volumio sudo[28218]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 30 15:47:02 volumio sudo[28218]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:02 volumio sudo[28218]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:02 volumio volumio-remote-updater[702]: [2025-12-30 15:47:02] [connect] Successful connection Dec 30 15:47:02 volumio volumio-remote-updater[702]: [2025-12-30 15:47:02] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1767131222 101 Dec 30 15:47:02 volumio volumio[27586]: 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: 3 Dec 30 15:47:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Dec 30 15:47:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:47:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:47:02 volumio go-librespot[28220]: go-librespot daemon starting... Dec 30 15:47:02 volumio go-librespot[28221]: time="2025-12-30T15:47:02-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 15:47:02 volumio go-librespot[28221]: time="2025-12-30T15:47:02-06:00" level=debug msg="app state loaded" Dec 30 15:47:02 volumio go-librespot[28221]: time="2025-12-30T15:47:02-06:00" level=debug msg="stored credentials not found" Dec 30 15:47:02 volumio go-librespot[28221]: time="2025-12-30T15:47:02-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 15:47:02 volumio volumio[27586]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 30 15:47:02 volumio sudo[28228]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 30 15:47:02 volumio sudo[28228]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:03 volumio sudo[28228]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:03 volumio go-librespot[28221]: time="2025-12-30T15:47:03-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 30 15:47:03 volumio go-librespot[28221]: time="2025-12-30T15:47:03-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 30 15:47:03 volumio go-librespot[28221]: time="2025-12-30T15:47:03-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 30 15:47:03 volumio go-librespot[28221]: time="2025-12-30T15:47:03-06:00" level=info msg="zeroconf server listening on port 41357" Dec 30 15:47:03 volumio go-librespot[28221]: time="2025-12-30T15:47:03-06:00" level=debug msg="obtained new client token: AABUjQImnmFHuWlqXKvEMulGTiT18Gqc6vcAVhJo1uNzgOegV4nK2aocxm0O8rUIGkzZS3zy37gA8bJjN6buZa6vpk7N4YNcE06Q7P8+79AS4ykO8EpCoE1/nElWyloopCWy/Srg2orAjmyP7TLnrFpc1VWkKo3ipl1D1SyOhWw4uinMVB3DuGlu/houNDCM5kiQGrT4sAJemMYwYyEdB6qczTDNU8Olnn1G3qWbRMOEpRA5Ju+EXps=" Dec 30 15:47:03 volumio go-librespot[28221]: time="2025-12-30T15:47:03-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 15:47:03 volumio go-librespot[28221]: time="2025-12-30T15:47:03-06:00" level=debug msg="completed keyexchange" Dec 30 15:47:03 volumio go-librespot[28221]: time="2025-12-30T15:47:03-06:00" level=debug msg="completed challenge" Dec 30 15:47:03 volumio mpd[28134]: 2025-12-30T15:47:03 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 30 15:47:03 volumio go-librespot[28221]: time="2025-12-30T15:47:03-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 30 15:47:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 15:47:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 15:47:03 volumio systemd[1]: Started mpd.service - Music Player Daemon. Dec 30 15:47:03 volumio sudo[27928]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:03 volumio volumio[27586]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 30 15:47:03 volumio sudo[28075]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:03 volumio sudo[27938]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:03 volumio sudo[28235]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 30 15:47:03 volumio sudo[28235]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:03 volumio sudo[28235]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:03 volumio volumio[27586]: error: MPD error: The expression evaluated to a falsy value: Dec 30 15:47:03 volumio volumio[27586]: assert.ok(self.idling) Dec 30 15:47:03 volumio volumio[27586]: error: The expression evaluated to a falsy value: Dec 30 15:47:03 volumio volumio[27586]: assert.ok(self.idling) Dec 30 15:47:03 volumio volumio[27586]: error: MPD error: The expression evaluated to a falsy value: Dec 30 15:47:03 volumio volumio[27586]: assert.ok(self.idling) Dec 30 15:47:03 volumio volumio[27586]: error: The expression evaluated to a falsy value: Dec 30 15:47:03 volumio volumio[27586]: assert.ok(self.idling) Dec 30 15:47:03 volumio volumio[27586]: error: updateQueue error: null Dec 30 15:47:03 volumio volumio[27586]: info: Completed starting Core Plugins Dec 30 15:47:03 volumio volumio[27586]: info: ------------------------------------------- Dec 30 15:47:03 volumio volumio[27586]: info: ----- MyVolumio plugins startup ---- Dec 30 15:47:03 volumio volumio[27586]: info: ------------------------------------------- Dec 30 15:47:03 volumio volumio[27586]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 30 15:47:03 volumio volumio[27586]: info: MPD running with PID28134 Dec 30 15:47:03 volumio volumio[27586]: ,establishing connection Dec 30 15:47:03 volumio volumio[27586]: error: updateQueue error: null Dec 30 15:47:04 volumio volumio[27586]: info: Initializing connection to go-librespot Websocket Dec 30 15:47:04 volumio volumio[27586]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 30 15:47:05 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.75.188 Dec 30 15:47:05 volumio avahi-daemon[664]: Registering new address record for 169.254.75.188 on eth0.IPv4. Dec 30 15:47:05 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Dec 30 15:47:05 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:05 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 15:47:05 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:05 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.75.188 Dec 30 15:47:06 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.75.188 Dec 30 15:47:06 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.75.188 Dec 30 15:47:06 volumio avahi-daemon[664]: Withdrawing address record for 169.254.75.188 on eth0. Dec 30 15:47:06 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Dec 30 15:47:06 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Dec 30 15:47:06 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:06 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 15:47:06 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:06 volumio kernel: hwmon hwmon1: Voltage normalised Dec 30 15:47:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Dec 30 15:47:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:47:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:47:06 volumio go-librespot[28286]: go-librespot daemon starting... Dec 30 15:47:06 volumio go-librespot[28287]: time="2025-12-30T15:47:06-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 15:47:06 volumio go-librespot[28287]: time="2025-12-30T15:47:06-06:00" level=debug msg="app state loaded" Dec 30 15:47:06 volumio go-librespot[28287]: time="2025-12-30T15:47:06-06:00" level=debug msg="stored credentials not found" Dec 30 15:47:06 volumio go-librespot[28287]: time="2025-12-30T15:47:06-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 15:47:06 volumio sudo[28296]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 30 15:47:06 volumio sudo[28294]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 30 15:47:06 volumio sudo[28294]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:06 volumio sudo[28296]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:06 volumio sudo[28298]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 30 15:47:06 volumio sudo[28298]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:06 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 30 15:47:06 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 30 15:47:06 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 30 15:47:06 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 30 15:47:06 volumio sudo[28294]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:06 volumio sudo[28298]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:06 volumio sudo[28296]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:06 volumio mpd_monitor.sh[28304]: MPD Monitor Service: Starting MPD Monitor Service Dec 30 15:47:06 volumio volumio[27586]: info: Successfully started MPD Monitor Dec 30 15:47:06 volumio volumio[27586]: info: Successfully started MPD Monitor Dec 30 15:47:06 volumio volumio[27586]: info: Successfully started MPD Monitor Dec 30 15:47:06 volumio go-librespot[28287]: time="2025-12-30T15:47:06-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 30 15:47:06 volumio go-librespot[28287]: time="2025-12-30T15:47:06-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 30 15:47:06 volumio go-librespot[28287]: time="2025-12-30T15:47:06-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 30 15:47:06 volumio go-librespot[28287]: time="2025-12-30T15:47:06-06:00" level=info msg="zeroconf server listening on port 46613" Dec 30 15:47:06 volumio go-librespot[28287]: time="2025-12-30T15:47:06-06:00" level=debug msg="obtained new client token: AAAQoBTabgouOlrtSjhVbkHgeq3ZXfb9D4ItJyRegS/PpbS+HDii3zwXjPYDSdnEGXBGbpD15ZFVm/wURO3YNrAz8HUHty6RRX8I/cRdFCXbQUvJRt90ew1oe+NO1fXYQ3XIXPUPgZwCHbb8GHGPKmpN+g1IktcfhXNMb4Chi0AvCJ438uRHYuwooEODjoVZD+CDwrZ9vQ92zt/gTHalK0NFUx+WCrHWxn8jluCznZq0dk+Z5ytRf0U+/Q==" Dec 30 15:47:06 volumio go-librespot[28287]: time="2025-12-30T15:47:06-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 15:47:06 volumio go-librespot[28287]: time="2025-12-30T15:47:06-06:00" level=debug msg="completed keyexchange" Dec 30 15:47:06 volumio go-librespot[28287]: time="2025-12-30T15:47:06-06:00" level=debug msg="completed challenge" Dec 30 15:47:07 volumio volumio[27586]: info: Initializing connection to go-librespot Websocket Dec 30 15:47:07 volumio go-librespot[28287]: time="2025-12-30T15:47:07-06:00" level=debug msg="new websocket client" Dec 30 15:47:07 volumio volumio[27586]: info: Connection to go-librespot Websocket established Dec 30 15:47:07 volumio go-librespot[28287]: time="2025-12-30T15:47:07-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 30 15:47:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 15:47:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 15:47:07 volumio volumio[27586]: info: Connection to go-librespot Websocket closed Dec 30 15:47:10 volumio volumio[27586]: info: Getting Spotify volume Dec 30 15:47:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Dec 30 15:47:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:47:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:47:10 volumio go-librespot[28309]: go-librespot daemon starting... Dec 30 15:47:10 volumio go-librespot[28310]: time="2025-12-30T15:47:10-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 15:47:10 volumio go-librespot[28310]: time="2025-12-30T15:47:10-06:00" level=debug msg="app state loaded" Dec 30 15:47:10 volumio go-librespot[28310]: time="2025-12-30T15:47:10-06:00" level=debug msg="stored credentials not found" Dec 30 15:47:10 volumio go-librespot[28310]: time="2025-12-30T15:47:10-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 15:47:10 volumio kernel: hwmon hwmon1: Undervoltage detected! Dec 30 15:47:10 volumio go-librespot[28310]: time="2025-12-30T15:47:10-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 30 15:47:10 volumio go-librespot[28310]: time="2025-12-30T15:47:10-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 30 15:47:10 volumio go-librespot[28310]: time="2025-12-30T15:47:10-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 30 15:47:10 volumio go-librespot[28310]: time="2025-12-30T15:47:10-06:00" level=info msg="zeroconf server listening on port 42191" Dec 30 15:47:10 volumio volumio[27586]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 30 15:47:10 volumio go-librespot[28310]: time="2025-12-30T15:47:10-06:00" level=debug msg="obtained new client token: AADkLQ+jfse9XiSKm8T9DeNAhddkLZ0ZR1B4MLUHsZEXEtjHXRWvYXzOx2N8TC20zLIHU7BIpRM4Z5bTVYSnhVe8uVu2JNwkvt6M7sXWOF2YwjEOYfFgj2Gzsq27GkZQ2dnVW/aXo2cFo9s/ceFXItmY2b8SvH8wwBvU6y8Pr8zIoFIlPkeipL6xgFXwlUsGZ6OomfSOVk/ZftYc4HmOkpLkE/2iMYIZ2YEQVepr7FZiDEWT092NgR54jA==" Dec 30 15:47:11 volumio volumio[27586]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 30 15:47:11 volumio volumio[27586]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 30 15:47:11 volumio volumio[27586]: errno: -111, Dec 30 15:47:11 volumio volumio[27586]: code: 'ECONNREFUSED', Dec 30 15:47:11 volumio volumio[27586]: syscall: 'connect', Dec 30 15:47:11 volumio volumio[27586]: address: '127.0.0.1', Dec 30 15:47:11 volumio volumio[27586]: port: 9879, Dec 30 15:47:11 volumio volumio[27586]: response: undefined Dec 30 15:47:11 volumio volumio[27586]: } Dec 30 15:47:11 volumio volumio[27586]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 30 15:47:11 volumio go-librespot[28310]: time="2025-12-30T15:47:11-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 15:47:11 volumio go-librespot[28310]: time="2025-12-30T15:47:11-06:00" level=debug msg="completed keyexchange" Dec 30 15:47:11 volumio go-librespot[28310]: time="2025-12-30T15:47:11-06:00" level=debug msg="completed challenge" Dec 30 15:47:11 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.109.244 Dec 30 15:47:11 volumio avahi-daemon[664]: Registering new address record for 169.254.109.244 on eth0.IPv4. Dec 30 15:47:11 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Dec 30 15:47:11 volumio go-librespot[28310]: time="2025-12-30T15:47:11-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 30 15:47:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 15:47:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 15:47:11 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:11 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 15:47:11 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:11 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.109.244 Dec 30 15:47:12 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.109.244 Dec 30 15:47:12 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.109.244 Dec 30 15:47:12 volumio avahi-daemon[664]: Withdrawing address record for 169.254.109.244 on eth0. Dec 30 15:47:12 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Dec 30 15:47:12 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:12 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 15:47:12 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:12 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Dec 30 15:47:12 volumio sudo[28365]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-30 15:46' Dec 30 15:47:12 volumio sudo[28365]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:12 volumio sudo[28365]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:12 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 30 15:47:12 volumio volumio-remote-updater[702]: [2025-12-30 15:47:12] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 30 15:47:12 volumio volumio-remote-updater[702]: [2025-12-30 15:47:12] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 30 15:47:12 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 30 15:47:12 volumio systemd[1]: volumio.service: Consumed 52.687s CPU time. Dec 30 15:47:13 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 30 15:47:13 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Dec 30 15:47:13 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 1000. Dec 30 15:47:13 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 30 15:47:13 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 30 15:47:13 volumio systemd[1]: volumio.service: Consumed 52.687s CPU time. Dec 30 15:47:13 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Dec 30 15:47:13 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Dec 30 15:47:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Dec 30 15:47:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:47:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:47:14 volumio go-librespot[28394]: go-librespot daemon starting... Dec 30 15:47:14 volumio go-librespot[28395]: time="2025-12-30T15:47:14-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 15:47:14 volumio go-librespot[28395]: time="2025-12-30T15:47:14-06:00" level=debug msg="app state loaded" Dec 30 15:47:14 volumio go-librespot[28395]: time="2025-12-30T15:47:14-06:00" level=debug msg="stored credentials not found" Dec 30 15:47:14 volumio go-librespot[28395]: time="2025-12-30T15:47:14-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 15:47:14 volumio go-librespot[28395]: time="2025-12-30T15:47:14-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 30 15:47:14 volumio go-librespot[28395]: time="2025-12-30T15:47:14-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 30 15:47:14 volumio go-librespot[28395]: time="2025-12-30T15:47:14-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 30 15:47:14 volumio go-librespot[28395]: time="2025-12-30T15:47:14-06:00" level=info msg="zeroconf server listening on port 39355" Dec 30 15:47:14 volumio go-librespot[28395]: time="2025-12-30T15:47:14-06:00" level=debug msg="obtained new client token: AAC4zfeiSL3+/EIfLD/eDQr8mV4H+YHMXzwGZuVi2s4sGpz6c2M8U/mVLqt+E4dXbSnPIHnPWy+/2zYEYc+HV2PvhY3fmPXG3CN22Qsla2anTXXqE7FPzHPDY3VGSc2GrGny5cnhG0umnjA2Ye9ETt6VwcZ8RsJW73q76sMI+6vHa/wcTtpdw0MdFCrfuyjv/Y4KEuA5CENPdXynVhTcxaIuOFtxfHA6UGK9HsflFWIyUsA7bXWb5XKJSA==" Dec 30 15:47:14 volumio go-librespot[28395]: time="2025-12-30T15:47:14-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 15:47:15 volumio volumio[28379]: info: ------------------------------------------- Dec 30 15:47:15 volumio volumio[28379]: info: ----- Volumio3 ---- Dec 30 15:47:15 volumio volumio[28379]: info: ------------------------------------------- Dec 30 15:47:15 volumio volumio[28379]: info: ----- System startup ---- Dec 30 15:47:15 volumio volumio[28379]: info: ------------------------------------------- Dec 30 15:47:16 volumio volumio[28379]: info: MYVOLUMIO Environment detected Dec 30 15:47:16 volumio volumio[28379]: info: Plugin folders cleanup Dec 30 15:47:16 volumio volumio[28379]: info: Scanning into folder /volumio/app/plugins/ Dec 30 15:47:16 volumio volumio[28379]: info: Scanning category audio_interface Dec 30 15:47:16 volumio volumio[28379]: info: Scanning category miscellanea Dec 30 15:47:16 volumio volumio[28379]: info: Scanning category music_service Dec 30 15:47:16 volumio volumio[28379]: info: Scanning category plugins.json Dec 30 15:47:16 volumio volumio[28379]: info: Scanning category system_controller Dec 30 15:47:16 volumio volumio[28379]: info: Scanning category user_interface Dec 30 15:47:16 volumio volumio[28379]: info: Scanning into folder /data/plugins/ Dec 30 15:47:16 volumio volumio[28379]: info: Scanning category audio_interface Dec 30 15:47:16 volumio volumio[28379]: info: Scanning category music_service Dec 30 15:47:16 volumio volumio[28379]: info: Scanning category system_controller Dec 30 15:47:16 volumio volumio[28379]: info: Scanning category system_hardware Dec 30 15:47:16 volumio volumio[28379]: info: Scanning category user_interface Dec 30 15:47:16 volumio volumio[28379]: info: Plugin folders cleanup completed Dec 30 15:47:16 volumio volumio[28379]: info: ------------------------------------------- Dec 30 15:47:16 volumio volumio[28379]: info: ----- Core plugins startup ---- Dec 30 15:47:16 volumio volumio[28379]: info: ------------------------------------------- Dec 30 15:47:16 volumio volumio[28379]: info: Loading plugins from folder /volumio/app/plugins/ Dec 30 15:47:16 volumio volumio[28379]: info: Adding plugin upnp to MyMusic Plugins Dec 30 15:47:16 volumio volumio[28379]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 30 15:47:16 volumio volumio[28379]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 30 15:47:16 volumio volumio[28379]: info: Loading plugins from folder /data/plugins/ Dec 30 15:47:16 volumio volumio[28379]: info: Loading plugin "system"... Dec 30 15:47:16 volumio volumio[28379]: info: Loading plugin "appearance"... Dec 30 15:47:16 volumio go-librespot[28395]: time="2025-12-30T15:47:16-06:00" level=debug msg="completed keyexchange" Dec 30 15:47:16 volumio go-librespot[28395]: time="2025-12-30T15:47:16-06:00" level=debug msg="completed challenge" Dec 30 15:47:16 volumio go-librespot[28395]: time="2025-12-30T15:47:16-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 30 15:47:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 15:47:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 15:47:16 volumio kernel: hwmon hwmon1: Voltage normalised Dec 30 15:47:16 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.92.188 Dec 30 15:47:16 volumio avahi-daemon[664]: Registering new address record for 169.254.92.188 on eth0.IPv4. Dec 30 15:47:16 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Dec 30 15:47:16 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:16 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 15:47:16 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:17 volumio volumio[28379]: info: Loading plugin "network"... Dec 30 15:47:17 volumio volumio[28379]: info: Refreshing Cached IP Addresses Dec 30 15:47:17 volumio sudo[28432]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 30 15:47:17 volumio sudo[28434]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 30 15:47:17 volumio sudo[28432]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:17 volumio sudo[28434]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:17 volumio sudo[28434]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:17 volumio sudo[28432]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:17 volumio volumio[28379]: info: Loading plugin "services"... Dec 30 15:47:17 volumio volumio[28379]: info: Loading plugin "alsa_controller"... Dec 30 15:47:17 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.92.188 Dec 30 15:47:17 volumio sudo[28447]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 30 15:47:17 volumio sudo[28447]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:17 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 30 15:47:17 volumio volumio[28379]: info: Loading plugin "wizard"... Dec 30 15:47:17 volumio volumio[28379]: info: Loading plugin "networkfs"... Dec 30 15:47:17 volumio volumio[28379]: info: Starting Udev Watcher for removable devices Dec 30 15:47:17 volumio volumio[28379]: info: Ignoring mount for partition: boot Dec 30 15:47:17 volumio volumio[28379]: info: Ignoring mount for partition: volumio Dec 30 15:47:17 volumio volumio[28379]: info: Ignoring mount for partition: volumio_data Dec 30 15:47:17 volumio volumio[28379]: info: Mounting Device Wikipedia Dec 30 15:47:17 volumio sudo[28471]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Dec 30 15:47:17 volumio sudo[28471]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:17 volumio sudo[28471]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:17 volumio volumio[28379]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Dec 30 15:47:17 volumio volumio[28379]: dmesg(1) may have more information after failed mount system call. Dec 30 15:47:17 volumio volumio[28379]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Dec 30 15:47:17 volumio volumio[28379]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Dec 30 15:47:17 volumio volumio[28379]: dmesg(1) may have more information after failed mount system call. Dec 30 15:47:17 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 30 15:47:17 volumio volumio[28379]: info: Loading plugin "volumio_command_line_client"... Dec 30 15:47:17 volumio volumio[28379]: info: Loading plugin "upnp"... Dec 30 15:47:17 volumio volumio[28379]: info: [1767131237738] Starting Upmpd Daemon Dec 30 15:47:17 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 30 15:47:17 volumio volumio[28379]: info: Loading plugin "my_music"... Dec 30 15:47:17 volumio volumio[28379]: info: Loading plugin "mpd"... Dec 30 15:47:17 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.92.188 Dec 30 15:47:17 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.92.188 Dec 30 15:47:17 volumio avahi-daemon[664]: Withdrawing address record for 169.254.92.188 on eth0. Dec 30 15:47:17 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Dec 30 15:47:17 volumio sudo[28447]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:17 volumio volumio-remote-updater[702]: [2025-12-30 15:47:17] [connect] Successful connection Dec 30 15:47:17 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Dec 30 15:47:18 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:18 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 15:47:18 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:18 volumio volumio[28379]: info: Loading plugin "upnp_browser"... Dec 30 15:47:18 volumio kernel: hwmon hwmon1: Undervoltage detected! Dec 30 15:47:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Dec 30 15:47:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:47:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:47:19 volumio go-librespot[28489]: go-librespot daemon starting... Dec 30 15:47:19 volumio go-librespot[28490]: time="2025-12-30T15:47:19-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 15:47:19 volumio go-librespot[28490]: time="2025-12-30T15:47:19-06:00" level=debug msg="app state loaded" Dec 30 15:47:19 volumio go-librespot[28490]: time="2025-12-30T15:47:19-06:00" level=debug msg="stored credentials not found" Dec 30 15:47:19 volumio go-librespot[28490]: time="2025-12-30T15:47:19-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 15:47:20 volumio go-librespot[28490]: time="2025-12-30T15:47:20-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 30 15:47:20 volumio go-librespot[28490]: time="2025-12-30T15:47:20-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 30 15:47:20 volumio go-librespot[28490]: time="2025-12-30T15:47:20-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 30 15:47:20 volumio go-librespot[28490]: time="2025-12-30T15:47:20-06:00" level=info msg="zeroconf server listening on port 42875" Dec 30 15:47:20 volumio go-librespot[28490]: time="2025-12-30T15:47:20-06:00" level=debug msg="obtained new client token: AAB0EdQkZyO/MWYprOPU1Tvo3hhK1Kzp7qot4bp4mn3w7P5GQFYDvHTZkOmseJmwN+itGx9MZIh68PzjGASBINaPyh+36Rj83+JSpKvRryU+UAci0lZ6Ebtvt+RyYgcmVyGHGY0n/jiAC3EcGM9+MpumKiQO49F5mE95A4NGnqYgma8WwJnQY5kJCMxXjFFvXS/A3flOUvv47j509qJmFB2/dr13oVwP6BMMZTcT2JHLIEcqxYi47NvJ6Q==" Dec 30 15:47:20 volumio go-librespot[28490]: time="2025-12-30T15:47:20-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 15:47:20 volumio go-librespot[28490]: time="2025-12-30T15:47:20-06:00" level=debug msg="completed keyexchange" Dec 30 15:47:20 volumio go-librespot[28490]: time="2025-12-30T15:47:20-06:00" level=debug msg="completed challenge" Dec 30 15:47:20 volumio go-librespot[28490]: time="2025-12-30T15:47:20-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 30 15:47:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 15:47:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 15:47:21 volumio volumio[28379]: info: Loading plugin "alarm-clock"... Dec 30 15:47:21 volumio volumio[28379]: info: Loading plugin "airplay_emulation"... Dec 30 15:47:21 volumio volumio[28379]: info: Starting Shairport Sync Dec 30 15:47:21 volumio volumio[28379]: info: Loading plugin "last_100"... Dec 30 15:47:21 volumio volumio[28379]: info: Loading plugin "webradio"... Dec 30 15:47:21 volumio volumio[28379]: info: Loading plugin "i2s_dacs"... Dec 30 15:47:21 volumio volumio[28379]: info: I2S DAC not set, start Auto-detection Dec 30 15:47:21 volumio volumio[28379]: info: Loading plugin "volumiodiscovery"... Dec 30 15:47:21 volumio volumio[28379]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 30 15:47:21 volumio volumio[28379]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 30 15:47:21 volumio volumio[28379]: *** WARNING *** For more information see Dec 30 15:47:21 volumio volumio[28379]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 30 15:47:21 volumio volumio[28379]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 30 15:47:21 volumio volumio[28379]: *** WARNING *** For more information see Dec 30 15:47:21 volumio node[28379]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 30 15:47:21 volumio node[28379]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 30 15:47:21 volumio node[28379]: *** WARNING *** For more information see Dec 30 15:47:21 volumio node[28379]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 30 15:47:21 volumio node[28379]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 30 15:47:21 volumio node[28379]: *** WARNING *** For more information see Dec 30 15:47:21 volumio volumio[28379]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 30 15:47:21 volumio volumio[28379]: info: Discovery: Started advertising with name: Volumio Dec 30 15:47:21 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 30 15:47:21 volumio volumio[28379]: info: Loading plugin "bandcamp"... Dec 30 15:47:22 volumio volumio[28379]: info: Plugin calmradio is not enabled Dec 30 15:47:22 volumio volumio[28379]: info: Loading plugin "soundcloud"... Dec 30 15:47:23 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.245.91 Dec 30 15:47:23 volumio avahi-daemon[664]: Registering new address record for 169.254.245.91 on eth0.IPv4. Dec 30 15:47:23 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Dec 30 15:47:23 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:23 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 15:47:23 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:23 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.245.91 Dec 30 15:47:23 volumio volumio[28379]: info: Loading plugin "spop"... Dec 30 15:47:23 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.245.91 Dec 30 15:47:23 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.245.91 Dec 30 15:47:23 volumio avahi-daemon[664]: Withdrawing address record for 169.254.245.91 on eth0. Dec 30 15:47:23 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Dec 30 15:47:23 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Dec 30 15:47:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Dec 30 15:47:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:47:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:47:23 volumio go-librespot[28532]: go-librespot daemon starting... Dec 30 15:47:23 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:23 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 15:47:23 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:23 volumio go-librespot[28533]: time="2025-12-30T15:47:23-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 15:47:23 volumio go-librespot[28533]: time="2025-12-30T15:47:23-06:00" level=debug msg="app state loaded" Dec 30 15:47:23 volumio go-librespot[28533]: time="2025-12-30T15:47:23-06:00" level=debug msg="stored credentials not found" Dec 30 15:47:23 volumio go-librespot[28533]: time="2025-12-30T15:47:23-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 15:47:24 volumio go-librespot[28533]: time="2025-12-30T15:47:24-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 30 15:47:24 volumio go-librespot[28533]: time="2025-12-30T15:47:24-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 30 15:47:24 volumio go-librespot[28533]: time="2025-12-30T15:47:24-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 30 15:47:24 volumio go-librespot[28533]: time="2025-12-30T15:47:24-06:00" level=info msg="zeroconf server listening on port 40287" Dec 30 15:47:24 volumio go-librespot[28533]: time="2025-12-30T15:47:24-06:00" level=debug msg="obtained new client token: AAAvUZRiMkicXPCCRTjFII8z6f/cU7IGhboil9C7Fle0k1ywDuBUanHYppCYRKyFs+4vRF3QgDoqNEngjvn16W2x1vDE2G8NSispZ6nGdEq6cHk857hII9Vqn9YSvaaE5Bfzcl4i11uMnL88f0vcOrQZqJj7n7SHy2QgY2ykraDhnjWxtBwpaVdPe5cCG4036aro3Vr1V0WfeLekeChIpFuzMgvvyyQeHvsORry2B1+Wzavp0PnTeCvwGA==" Dec 30 15:47:24 volumio go-librespot[28533]: time="2025-12-30T15:47:24-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 15:47:24 volumio go-librespot[28533]: time="2025-12-30T15:47:24-06:00" level=debug msg="completed keyexchange" Dec 30 15:47:24 volumio go-librespot[28533]: time="2025-12-30T15:47:24-06:00" level=debug msg="completed challenge" Dec 30 15:47:24 volumio go-librespot[28533]: time="2025-12-30T15:47:24-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 30 15:47:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 15:47:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 15:47:25 volumio volumio[28379]: info: Loading plugin "squeezelite_mc"... Dec 30 15:47:26 volumio volumio[28379]: info: Loading plugin "youtube2"... Dec 30 15:47:26 volumio volumio[28379]: info: Loading plugin "ytcr"... Dec 30 15:47:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Dec 30 15:47:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:47:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:47:27 volumio go-librespot[28557]: go-librespot daemon starting... Dec 30 15:47:27 volumio go-librespot[28558]: time="2025-12-30T15:47:27-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 15:47:27 volumio go-librespot[28558]: time="2025-12-30T15:47:27-06:00" level=debug msg="app state loaded" Dec 30 15:47:27 volumio go-librespot[28558]: time="2025-12-30T15:47:27-06:00" level=debug msg="stored credentials not found" Dec 30 15:47:27 volumio go-librespot[28558]: time="2025-12-30T15:47:27-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 15:47:27 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.165.199 Dec 30 15:47:27 volumio avahi-daemon[664]: Registering new address record for 169.254.165.199 on eth0.IPv4. Dec 30 15:47:27 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Dec 30 15:47:27 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:27 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 15:47:27 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:27 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.165.199 Dec 30 15:47:28 volumio go-librespot[28558]: time="2025-12-30T15:47:28-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 30 15:47:28 volumio go-librespot[28558]: time="2025-12-30T15:47:28-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 30 15:47:28 volumio go-librespot[28558]: time="2025-12-30T15:47:28-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 30 15:47:28 volumio go-librespot[28558]: time="2025-12-30T15:47:28-06:00" level=info msg="zeroconf server listening on port 45929" Dec 30 15:47:28 volumio go-librespot[28558]: time="2025-12-30T15:47:28-06:00" level=debug msg="obtained new client token: AABIgOxbAQ8eqNPGmHyHXlJ+CyqOtbfrIqX7uHTUQDE8hxYJIofUxXCmkrpbI6R/ycDjgQ86gvSaQAS3aD+R2dPHBwFD92RTaZBogqw2CAOnHg03ahYVL3ONDOvqxsqfPbHVSCXRFeQlhifzyn/l3ODi7sFVHDMijzGQizz1jdPdVQh8fwygWXbV0oKfjaErHeFVud4atWCyoAs8olIsj3M0S4tCCxLBGXABen5edqOaBJXyitoNmso5Og==" Dec 30 15:47:28 volumio go-librespot[28558]: time="2025-12-30T15:47:28-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 15:47:28 volumio go-librespot[28558]: time="2025-12-30T15:47:28-06:00" level=debug msg="completed keyexchange" Dec 30 15:47:28 volumio go-librespot[28558]: time="2025-12-30T15:47:28-06:00" level=debug msg="completed challenge" Dec 30 15:47:28 volumio go-librespot[28558]: time="2025-12-30T15:47:28-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 30 15:47:28 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.165.199 Dec 30 15:47:28 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.165.199 Dec 30 15:47:28 volumio avahi-daemon[664]: Withdrawing address record for 169.254.165.199 on eth0. Dec 30 15:47:28 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Dec 30 15:47:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 15:47:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 15:47:28 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:28 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 15:47:28 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:28 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Dec 30 15:47:29 volumio volumio[28379]: info: Loading plugin "ytmusic"... Dec 30 15:47:30 volumio volumio[28379]: info: Plugin now_playing is not enabled Dec 30 15:47:30 volumio volumio[28379]: info: Loading plugin "outputs"... Dec 30 15:47:30 volumio volumio[28379]: info: Loading plugin "albumart"... Dec 30 15:47:30 volumio volumio[28379]: info: Plugin example_plugin is not enabled Dec 30 15:47:30 volumio volumio[28379]: info: Loading plugin "inputs"... Dec 30 15:47:30 volumio volumio[28379]: info: Loading plugin "updater_comm"... Dec 30 15:47:30 volumio volumio[28379]: info: Plugin mpdemulation is not enabled Dec 30 15:47:30 volumio volumio[28379]: info: Loading plugin "rest_api"... Dec 30 15:47:30 volumio volumio[28379]: info: Loading plugin "websocket"... Dec 30 15:47:30 volumio volumio[28379]: info: Starting Socket.io Server version 1.7.4 Dec 30 15:47:30 volumio volumio[28379]: info: Plugin fusiondsp is not enabled Dec 30 15:47:30 volumio volumio[28379]: info: Plugin mpdoutput is not enabled Dec 30 15:47:30 volumio volumio[28379]: info: Plugin RoonBridge is not enabled Dec 30 15:47:30 volumio volumio[28379]: info: Loading plugin "podcast"... Dec 30 15:47:30 volumio volumio-remote-updater[702]: [2025-12-30 15:47:30] [connect] Successful connection Dec 30 15:47:30 volumio volumio[28379]: info: ControllerPodcast::constructor Dec 30 15:47:30 volumio volumio[28379]: info: Loading plugin "volusonic"... Dec 30 15:47:31 volumio volumio[28599]: Forking 3 albumart workers Dec 30 15:47:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Dec 30 15:47:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:47:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:47:31 volumio go-librespot[28639]: go-librespot daemon starting... Dec 30 15:47:31 volumio go-librespot[28640]: time="2025-12-30T15:47:31-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 15:47:31 volumio go-librespot[28640]: time="2025-12-30T15:47:31-06:00" level=debug msg="app state loaded" Dec 30 15:47:31 volumio go-librespot[28640]: time="2025-12-30T15:47:31-06:00" level=debug msg="stored credentials not found" Dec 30 15:47:31 volumio go-librespot[28640]: time="2025-12-30T15:47:31-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 15:47:32 volumio go-librespot[28640]: time="2025-12-30T15:47:32-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 30 15:47:32 volumio go-librespot[28640]: time="2025-12-30T15:47:32-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 30 15:47:32 volumio go-librespot[28640]: time="2025-12-30T15:47:32-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 30 15:47:32 volumio go-librespot[28640]: time="2025-12-30T15:47:32-06:00" level=info msg="zeroconf server listening on port 38435" Dec 30 15:47:32 volumio go-librespot[28640]: time="2025-12-30T15:47:32-06:00" level=debug msg="obtained new client token: AABftQi24+3Y1DzvTv6fLjABHn50YLcz7cM1XLrA7trs9Qaf3vKV6aXPa1wjL5xAYCsMV9HmqPkowd/Lj/MTkdQTXiefeH3k6PlQOgfINXgLhChhb4uhjH+pXbRxFDTcoX/sLuoxBo223WhG5LdDYw+PSzexVrOD5uBfcU1QkdKvrGPFdv5SquzGi6X2vecd+XOHMB/1b02u8cb46DBOiRXXoQD1MqOz4KqchHp1aLaQCVEdUFEGULnKyw==" Dec 30 15:47:32 volumio go-librespot[28640]: time="2025-12-30T15:47:32-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 15:47:32 volumio go-librespot[28640]: time="2025-12-30T15:47:32-06:00" level=debug msg="completed keyexchange" Dec 30 15:47:32 volumio go-librespot[28640]: time="2025-12-30T15:47:32-06:00" level=debug msg="completed challenge" Dec 30 15:47:32 volumio go-librespot[28640]: time="2025-12-30T15:47:32-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 30 15:47:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 15:47:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 15:47:33 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.6.19 Dec 30 15:47:33 volumio avahi-daemon[664]: Registering new address record for 169.254.6.19 on eth0.IPv4. Dec 30 15:47:33 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Dec 30 15:47:33 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:33 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 15:47:33 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:33 volumio volumio[28611]: Starting albumart workers Dec 30 15:47:33 volumio volumio[28379]: info: Applying required configuration parameters for plugin volusonic Dec 30 15:47:33 volumio volumio[28379]: info: Loading plugin "backup_restore"... Dec 30 15:47:34 volumio volumio[28609]: Starting albumart workers Dec 30 15:47:34 volumio volumio[28610]: Starting albumart workers Dec 30 15:47:34 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.6.19 Dec 30 15:47:34 volumio volumio[28379]: info: Applying required configuration parameters for plugin backup_restore Dec 30 15:47:34 volumio volumio[28379]: info: Plugin rpi_eeprom_config is not enabled Dec 30 15:47:34 volumio volumio[28379]: info: Plugin rpi_eeprom_updater is not enabled Dec 30 15:47:34 volumio volumio[28379]: info: Loading plugin "scheduledrestart"... Dec 30 15:47:34 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.6.19 Dec 30 15:47:34 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.6.19 Dec 30 15:47:34 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Dec 30 15:47:34 volumio avahi-daemon[664]: Withdrawing address record for 169.254.6.19 on eth0. Dec 30 15:47:34 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:34 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 15:47:34 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:34 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Dec 30 15:47:34 volumio volumio[28379]: info: Applying required configuration parameters for plugin scheduledrestart Dec 30 15:47:34 volumio volumio[28379]: info: Plugin Bluetoothremote is not enabled Dec 30 15:47:34 volumio volumio[28379]: info: Plugin music_services_shield is not enabled Dec 30 15:47:34 volumio volumio[28379]: info: Loading plugin "Systeminfo"... Dec 30 15:47:35 volumio volumio[28379]: info: Plugin peppymeterbasic is not enabled Dec 30 15:47:35 volumio volumio[28379]: info: Loading plugin "peppyspectrum"... Dec 30 15:47:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Dec 30 15:47:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:47:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:47:36 volumio go-librespot[28697]: go-librespot daemon starting... Dec 30 15:47:36 volumio volumio[28379]: info: Loading i18n strings for locale en Dec 30 15:47:36 volumio go-librespot[28698]: time="2025-12-30T15:47:36-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 15:47:36 volumio go-librespot[28698]: time="2025-12-30T15:47:36-06:00" level=debug msg="app state loaded" Dec 30 15:47:36 volumio go-librespot[28698]: time="2025-12-30T15:47:36-06:00" level=debug msg="stored credentials not found" Dec 30 15:47:36 volumio go-librespot[28698]: time="2025-12-30T15:47:36-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 15:47:36 volumio volumio[28379]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Dec 30 15:47:36 volumio volumio[28379]: Updating browse sources language Dec 30 15:47:36 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 15:47:36 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 30 15:47:36 volumio volumio[28379]: info: CoreCommandRouter::initPlayerControls Dec 30 15:47:36 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:36 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:36 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:36 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:36 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:36 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:36 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:36 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:36 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 30 15:47:36 volumio volumio[28379]: Express server listening on port 3000 Dec 30 15:47:36 volumio volumio[28379]: [Metrics] WebUI: 21s 708.80ms Dec 30 15:47:36 volumio volumio[28379]: info: CoreStateMachine::resetVolumioState Dec 30 15:47:36 volumio volumio[28379]: info: CoreStateMachine::getcurrentVolume Dec 30 15:47:36 volumio volumio[28379]: info: CoreCommandRouter::volumioRetrievevolume Dec 30 15:47:36 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 15:47:36 volumio go-librespot[28698]: time="2025-12-30T15:47:36-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 30 15:47:36 volumio go-librespot[28698]: time="2025-12-30T15:47:36-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 30 15:47:36 volumio go-librespot[28698]: time="2025-12-30T15:47:36-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 30 15:47:36 volumio go-librespot[28698]: time="2025-12-30T15:47:36-06:00" level=info msg="zeroconf server listening on port 34137" Dec 30 15:47:36 volumio sudo[28710]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 30 15:47:36 volumio sudo[28710]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:36 volumio sudo[28710]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:36 volumio sudo[28712]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 30 15:47:36 volumio sudo[28712]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:36 volumio sudo[28712]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:36 volumio volumio[28379]: info: Volumio Network Manager: Network status updated: 1 Dec 30 15:47:36 volumio go-librespot[28698]: time="2025-12-30T15:47:36-06:00" level=debug msg="obtained new client token: AACYw8973Mb8sFgwzjG3YVuXZcfk41x41cS7VEkLMSv6xDeL24tUZT2A96ZSS/64I4FGxCeGr1lvov90zrtuDTBbQUYB949rDtg4me05OfG/11wQQw8mS+fU0RyUjF8oVLFmsNF63MPDq+zd8BqimELVSluwdzeTvU+Horoex1EZ36vdBc8VR00pvtdRyCzQFCHB0DQIE7TrLqHTza/wivPJZ+12L7ISn9SeQvEp1RtxCjEq7g0lLKX4pQ==" Dec 30 15:47:36 volumio go-librespot[28698]: time="2025-12-30T15:47:36-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 15:47:36 volumio go-librespot[28698]: time="2025-12-30T15:47:36-06:00" level=debug msg="completed keyexchange" Dec 30 15:47:36 volumio go-librespot[28698]: time="2025-12-30T15:47:36-06:00" level=debug msg="completed challenge" Dec 30 15:47:36 volumio go-librespot[28698]: time="2025-12-30T15:47:36-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 30 15:47:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 15:47:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 15:47:36 volumio volumio[28379]: info: VolumeController:: Volume=100 Mute =false Dec 30 15:47:36 volumio volumio[28379]: info: CoreStateMachine::pushState Dec 30 15:47:36 volumio volumio[28379]: info: CorePlayQueue::getTrack 0 Dec 30 15:47:36 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 30 15:47:36 volumio volumio[28379]: info: CoreCommandRouter::volumioPushState Dec 30 15:47:36 volumio volumio[28379]: info: CoreStateMachine::updateTrackBlock Dec 30 15:47:36 volumio volumio[28379]: info: CorePlayQueue::getTrackBlock Dec 30 15:47:36 volumio volumio[28379]: info: CoreCommandRouter::volumioRetrievevolume Dec 30 15:47:37 volumio volumio[28379]: info: Reloading queue from file Dec 30 15:47:37 volumio volumio[28379]: info: CoreStateMachine::setRepeat null single undefined Dec 30 15:47:37 volumio volumio[28379]: info: CoreStateMachine::pushState Dec 30 15:47:37 volumio volumio[28379]: info: CorePlayQueue::getTrack 0 Dec 30 15:47:37 volumio volumio[28379]: info: CoreCommandRouter::volumioPushState Dec 30 15:47:37 volumio volumio[28379]: info: CoreStateMachine::setRandom null Dec 30 15:47:37 volumio volumio[28379]: info: CoreStateMachine::pushState Dec 30 15:47:37 volumio volumio[28379]: info: CorePlayQueue::getTrack 0 Dec 30 15:47:37 volumio volumio[28379]: info: CoreCommandRouter::volumioPushState Dec 30 15:47:37 volumio volumio[28379]: info: Setting Device type: Raspberry PI Dec 30 15:47:37 volumio volumio[28379]: info: VolumeController:: Volume=100 Mute =false Dec 30 15:47:37 volumio volumio[28379]: info: CoreStateMachine::pushState Dec 30 15:47:37 volumio volumio[28379]: info: CorePlayQueue::getTrack 0 Dec 30 15:47:37 volumio volumio[28379]: info: CoreCommandRouter::volumioPushState Dec 30 15:47:37 volumio volumio[28379]: info: Completed loading Core Plugins Dec 30 15:47:37 volumio volumio[28379]: info: Preparing to generate the ALSA configuration file Dec 30 15:47:37 volumio sudo[28725]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 30 15:47:37 volumio sudo[28725]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:37 volumio volumio[28379]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Dec 30 15:47:37 volumio volumio[28379]: info: Discovery: Found device Volumio Dec 30 15:47:37 volumio volumio[28379]: info: CoreCommandRouter::volumioGetState Dec 30 15:47:37 volumio volumio[28379]: info: CorePlayQueue::getTrack 0 Dec 30 15:47:37 volumio volumio[28379]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Dec 30 15:47:37 volumio volumio[28379]: info: Discovery: Found device Volumio Dec 30 15:47:37 volumio volumio[28379]: info: CoreCommandRouter::volumioGetState Dec 30 15:47:37 volumio volumio[28379]: info: CorePlayQueue::getTrack 0 Dec 30 15:47:37 volumio volumio[28379]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 30 15:47:37 volumio volumio[28379]: info: Reading ALSA contributions from plugins. Dec 30 15:47:37 volumio sudo[28725]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:37 volumio volumio[28379]: info: Upmpdcli Daemon Started Dec 30 15:47:37 volumio volumio[28379]: info: Asound.conf file unchanged, so no further update is needed Dec 30 15:47:37 volumio volumio[28379]: info: Output device has changed, restarting MPD Dec 30 15:47:37 volumio volumio[28379]: info: Output device has changed, restarting Shairport Sync Dec 30 15:47:37 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:37 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 15:47:37 volumio sudo[28728]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 30 15:47:37 volumio sudo[28728]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:37 volumio sudo[28728]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:37 volumio sudo[28730]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 30 15:47:37 volumio sudo[28730]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:37 volumio volumio[28379]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 30 15:47:37 volumio volumio[28379]: info: ___________ START PLUGINS ___________ Dec 30 15:47:37 volumio volumio[28379]: info: ControllerMpd::onStart: Initializing MPD Dec 30 15:47:37 volumio volumio[28379]: info: Creating MPD Configuration file Dec 30 15:47:37 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 30 15:47:37 volumio volumio[28379]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 15:47:37 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 30 15:47:37 volumio volumio[28379]: info: [1767131257381] CoreMusicLibrary::Adding element Media Servers Dec 30 15:47:37 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 15:47:37 volumio sudo[28738]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 30 15:47:37 volumio sudo[28738]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:37 volumio sudo[28740]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 30 15:47:37 volumio sudo[28740]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:37 volumio sudo[28738]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:37 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:37 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 15:47:37 volumio volumio[28379]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 30 15:47:37 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:37 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 15:47:37 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 30 15:47:37 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 30 15:47:37 volumio systemd[1]: mpd.service: Consumed 5.784s CPU time. Dec 30 15:47:37 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 30 15:47:37 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 30 15:47:37 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 30 15:47:37 volumio volumio[28379]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 30 15:47:37 volumio volumio[28379]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 15:47:37 volumio volumio[28379]: info: [1767131257548] CoreMusicLibrary::Adding element Last_100 Dec 30 15:47:37 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 15:47:37 volumio volumio[28379]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 15:47:37 volumio volumio[28379]: info: [1767131257556] CoreMusicLibrary::Adding element Webradio Dec 30 15:47:37 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 15:47:37 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 30 15:47:37 volumio volumio[28379]: info: Initializing BBC Radios Dec 30 15:47:37 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 30 15:47:37 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 30 15:47:37 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 30 15:47:37 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 15:47:37 volumio volumio[28379]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 15:47:37 volumio volumio[28379]: info: [1767131257704] CoreMusicLibrary::Adding element Bandcamp Discover Dec 30 15:47:37 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 15:47:37 volumio volumio[28379]: Cannot find translation for source Bandcamp Discover Dec 30 15:47:37 volumio volumio[28379]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 15:47:37 volumio volumio[28379]: info: [1767131257724] CoreMusicLibrary::Adding element SoundCloud Dec 30 15:47:37 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 15:47:37 volumio volumio[28379]: Cannot find translation for source Bandcamp Discover Dec 30 15:47:37 volumio volumio[28379]: Cannot find translation for source SoundCloud Dec 30 15:47:37 volumio volumio[28379]: info: Creating Spotify config file Dec 30 15:47:37 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:38 volumio sudo[28771]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 30 15:47:38 volumio sudo[28771]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 30 15:47:38 volumio sudo[28771]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:38 volumio volumio[28379]: info: [squeezelite_mc] Starting proxy server... Dec 30 15:47:38 volumio volumio[28379]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 15:47:38 volumio volumio[28379]: info: [1767131258399] CoreMusicLibrary::Adding element YouTube2 Dec 30 15:47:38 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 15:47:38 volumio volumio[28379]: Cannot find translation for source Bandcamp Discover Dec 30 15:47:38 volumio volumio[28379]: Cannot find translation for source SoundCloud Dec 30 15:47:38 volumio volumio[28379]: Cannot find translation for source YouTube2 Dec 30 15:47:38 volumio volumio[28379]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 15:47:38 volumio volumio[28379]: info: [1767131258429] CoreMusicLibrary::Adding element YouTube Music Dec 30 15:47:38 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 15:47:38 volumio volumio[28379]: Cannot find translation for source Bandcamp Discover Dec 30 15:47:38 volumio volumio[28379]: Cannot find translation for source SoundCloud Dec 30 15:47:38 volumio volumio[28379]: Cannot find translation for source YouTube2 Dec 30 15:47:38 volumio volumio[28379]: Cannot find translation for source YouTube Music Dec 30 15:47:38 volumio volumio[28379]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 15:47:38 volumio volumio[28379]: info: [1767131258448] CoreMusicLibrary::Adding element Podcast Dec 30 15:47:38 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 15:47:38 volumio volumio[28379]: Cannot find translation for source Bandcamp Discover Dec 30 15:47:38 volumio volumio[28379]: Cannot find translation for source SoundCloud Dec 30 15:47:38 volumio volumio[28379]: Cannot find translation for source YouTube2 Dec 30 15:47:38 volumio volumio[28379]: Cannot find translation for source YouTube Music Dec 30 15:47:38 volumio volumio[28379]: Cannot find translation for source Podcast Dec 30 15:47:38 volumio volumio[28379]: info: Loading i18n strings for locale en Dec 30 15:47:38 volumio volumio[28379]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Dec 30 15:47:38 volumio volumio[28379]: Updating browse sources language Dec 30 15:47:38 volumio volumio[28379]: Cannot find translation for source Bandcamp Discover Dec 30 15:47:38 volumio volumio[28379]: Cannot find translation for source SoundCloud Dec 30 15:47:38 volumio volumio[28379]: Cannot find translation for source YouTube2 Dec 30 15:47:38 volumio volumio[28379]: Cannot find translation for source YouTube Music Dec 30 15:47:38 volumio volumio[28379]: Cannot find translation for source Podcast Dec 30 15:47:38 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 15:47:38 volumio volumio[28379]: Cannot find translation for source Bandcamp Discover Dec 30 15:47:38 volumio volumio[28379]: Cannot find translation for source SoundCloud Dec 30 15:47:38 volumio volumio[28379]: Cannot find translation for source YouTube2 Dec 30 15:47:38 volumio volumio[28379]: Cannot find translation for source YouTube Music Dec 30 15:47:38 volumio volumio[28379]: Cannot find translation for source Podcast Dec 30 15:47:38 volumio volumio[28379]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 15:47:38 volumio volumio[28379]: info: [1767131258529] CoreMusicLibrary::Adding element Volusonic Dec 30 15:47:38 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 15:47:38 volumio volumio[28379]: Cannot find translation for source Bandcamp Discover Dec 30 15:47:38 volumio volumio[28379]: Cannot find translation for source SoundCloud Dec 30 15:47:38 volumio volumio[28379]: Cannot find translation for source YouTube2 Dec 30 15:47:38 volumio volumio[28379]: Cannot find translation for source YouTube Music Dec 30 15:47:38 volumio volumio[28379]: Cannot find translation for source Podcast Dec 30 15:47:38 volumio volumio[28379]: Cannot find translation for source Volusonic Dec 30 15:47:38 volumio volumio[28379]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Dec 30 15:47:38 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Dec 30 15:47:38 volumio volumio[28379]: info: Volumio Calling Home Dec 30 15:47:38 volumio volumio[28379]: info: [squeezelite_mc] Proxy server started on port 39471 Dec 30 15:47:38 volumio volumio[28379]: info: Preparing to generate the ALSA configuration file Dec 30 15:47:38 volumio volumio[28379]: info: CoreCommandRouter::volumioRetrievevolume Dec 30 15:47:39 volumio volumio[28379]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 30 15:47:39 volumio volumio[28379]: info: Reading ALSA contributions from plugins. Dec 30 15:47:39 volumio volumio[28379]: info: MPD Permissions set Dec 30 15:47:39 volumio volumio[28379]: info: MPD Permissions set Dec 30 15:47:39 volumio volumio[28379]: info: Spotify config file written Dec 30 15:47:39 volumio sudo[28788]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 30 15:47:39 volumio sudo[28788]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:39 volumio volumio[28379]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Dec 30 15:47:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:47:39 volumio volumio[28379]: info: VolumeController:: Volume=100 Mute =false Dec 30 15:47:39 volumio volumio[28379]: info: CoreStateMachine::pushState Dec 30 15:47:39 volumio volumio[28379]: info: CorePlayQueue::getTrack 0 Dec 30 15:47:39 volumio volumio[28379]: info: CoreCommandRouter::volumioPushState Dec 30 15:47:39 volumio volumio[28379]: info: [squeezelite_mc] Server discovery started Dec 30 15:47:39 volumio volumio[28379]: info: [squeezelite_mc] Player finder started Dec 30 15:47:39 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:39 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:39 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:39 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 30 15:47:39 volumio volumio[28379]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Dec 30 15:47:39 volumio go-librespot[28790]: go-librespot daemon starting... Dec 30 15:47:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:47:39 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:39 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:39 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:39 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:39 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:39 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:39 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:39 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:39 volumio sudo[28788]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:39 volumio go-librespot[28792]: time="2025-12-30T15:47:39-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 15:47:39 volumio go-librespot[28792]: time="2025-12-30T15:47:39-06:00" level=debug msg="app state loaded" Dec 30 15:47:39 volumio go-librespot[28792]: time="2025-12-30T15:47:39-06:00" level=debug msg="stored credentials not found" Dec 30 15:47:39 volumio go-librespot[28792]: time="2025-12-30T15:47:39-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 15:47:39 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 15:47:39 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:39 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:39 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:39 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:39 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:39 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:39 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:39 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:39 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:39 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 15:47:39 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:39 volumio volumio[28379]: info: No need to fix Spotify hosts Dec 30 15:47:39 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.62.221 Dec 30 15:47:39 volumio avahi-daemon[664]: Registering new address record for 169.254.62.221 on eth0.IPv4. Dec 30 15:47:39 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Dec 30 15:47:39 volumio volumio[28379]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Dec 30 15:47:39 volumio volumio[28379]: info: Volumio called home Dec 30 15:47:39 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:39 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 15:47:39 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:39 volumio go-librespot[28792]: time="2025-12-30T15:47:39-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 30 15:47:39 volumio go-librespot[28792]: time="2025-12-30T15:47:39-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 30 15:47:39 volumio go-librespot[28792]: time="2025-12-30T15:47:39-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 30 15:47:39 volumio go-librespot[28792]: time="2025-12-30T15:47:39-06:00" level=info msg="zeroconf server listening on port 36235" Dec 30 15:47:39 volumio volumio[28379]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Dec 30 15:47:39 volumio volumio[28379]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Dec 30 15:47:39 volumio volumio[28379]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf Dec 30 15:47:40 volumio volumio[28379]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 30 15:47:40 volumio volumio[28379]: SPOTIFY: BQBc6IrToM_7y9H2zt_0VE8lvUuXiY9Ll8JKHgabu7WnPwj2imAAT3dewokTUPE5Z7pOzhryLeHmiZPOkFtgwP4flv3djhrr_3jbhd7JlH5U5-6_73BzttIO-VWatg0b4CPvPh4fCXqRTPlE7ORaYP7bX_7eFotV1IMOPnC20x8nz8UlvU-mxCcEEwZyJtorIA0E0QRn38ZPTw7nHTB34BKGiYshWzGudlB_JJY Dec 30 15:47:40 volumio volumio[28379]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 30 15:47:40 volumio volumio[28379]: info: New Spotify access token = BQBc6IrToM_7y9H2zt_0VE8lvUuXiY9Ll8JKHgabu7WnPwj2imAAT3dewokTUPE5Z7pOzhryLeHmiZPOkFtgwP4flv3djhrr_3jbhd7JlH5U5-6_73BzttIO-VWatg0b4CPvPh4fCXqRTPlE7ORaYP7bX_7eFotV1IMOPnC20x8nz8UlvU-mxCcEEwZyJtorIA0E0QRn38ZPTw7nHTB34BKGiYshWzGudlB_JJY Dec 30 15:47:40 volumio volumio[28379]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 30 15:47:40 volumio sudo[28828]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf Dec 30 15:47:40 volumio sudo[28828]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:40 volumio sudo[28828]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:40 volumio go-librespot[28792]: time="2025-12-30T15:47:40-06:00" level=debug msg="obtained new client token: AABmPv+U51EM5HO7co2wndwRn8ZNZg/EDQ/HtpVpe8dMb6WRgVBec34fjFAK/UhSgvz386vuMeLPj5LXC2SchXLuR4QdV5SjalzjJHYHw5KVIxTlnFTi8RPWAfegeMwAKr8Qy/dBkVp1gDabVEAWXQ6dRKOAHX/KfYi/uaCT6SaqpxAoMu1QJhLO5Y5H7SHlKBsktrnoqFMNmJ3RzEEARrnv6SIXkKLYG4WSVQPQxVe/CHkgLcylhc4=" Dec 30 15:47:40 volumio volumio[28379]: info: Starting Shairport Sync Dec 30 15:47:40 volumio volumio[28379]: info: Starting Shairport Sync Dec 30 15:47:40 volumio volumio[28379]: info: Starting Shairport Sync Dec 30 15:47:40 volumio go-librespot[28792]: time="2025-12-30T15:47:40-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 15:47:40 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.62.221 Dec 30 15:47:40 volumio sudo[28833]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 30 15:47:40 volumio sudo[28833]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:40 volumio volumio[28379]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Dec 30 15:47:40 volumio sudo[28835]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 30 15:47:40 volumio sudo[28835]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:40 volumio sudo[28837]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 30 15:47:40 volumio sudo[28837]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:40 volumio go-librespot[28792]: time="2025-12-30T15:47:40-06:00" level=debug msg="completed keyexchange" Dec 30 15:47:40 volumio go-librespot[28792]: time="2025-12-30T15:47:40-06:00" level=debug msg="completed challenge" Dec 30 15:47:40 volumio go-librespot[28792]: time="2025-12-30T15:47:40-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 30 15:47:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 15:47:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 15:47:40 volumio sudo[28843]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Dec 30 15:47:40 volumio sudo[28843]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:40 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.62.221 Dec 30 15:47:40 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.62.221 Dec 30 15:47:40 volumio avahi-daemon[664]: Withdrawing address record for 169.254.62.221 on eth0. Dec 30 15:47:40 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Dec 30 15:47:40 volumio sudo[28843]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:40 volumio volumio[28379]: info: Asound.conf file unchanged, so no further update is needed Dec 30 15:47:40 volumio volumio[28379]: info: Output device has changed, restarting MPD Dec 30 15:47:40 volumio volumio[28379]: info: Output device has changed, restarting Shairport Sync Dec 30 15:47:40 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:40 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 15:47:40 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:40 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 15:47:40 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:40 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Dec 30 15:47:40 volumio sudo[28854]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 30 15:47:40 volumio sudo[28854]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:40 volumio sudo[28854]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:40 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 30 15:47:40 volumio sudo[28860]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 30 15:47:40 volumio sudo[28860]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:40 volumio volumio[28379]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 30 15:47:40 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 30 15:47:40 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 30 15:47:40 volumio systemd[1]: shairport-sync.service: Consumed 2.176s CPU time. Dec 30 15:47:40 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 30 15:47:40 volumio sudo[28833]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:40 volumio sudo[28835]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:40 volumio sudo[28837]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:40 volumio volumio[28379]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Dec 30 15:47:40 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 30 15:47:40 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 30 15:47:40 volumio systemd[1]: mpd.service: Consumed 2.980s CPU time. Dec 30 15:47:40 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 30 15:47:40 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 30 15:47:40 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 30 15:47:40 volumio sudo[28886]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Dec 30 15:47:40 volumio sudo[28886]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:40 volumio sudo[28886]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:40 volumio volumio[28379]: info: MPD Permissions set Dec 30 15:47:40 volumio volumio[28379]: info: Shairport-Sync Started Dec 30 15:47:40 volumio volumio[28379]: Error adding Membership: Error: addMembership EINVAL Dec 30 15:47:40 volumio volumio[28379]: info: Shairport-Sync Started Dec 30 15:47:40 volumio volumio[28379]: info: Shairport-Sync Started Dec 30 15:47:40 volumio volumio[28379]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Dec 30 15:47:41 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 30 15:47:41 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 30 15:47:41 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:41 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:41 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:41 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:41 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:41 volumio sudo[28895]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Dec 30 15:47:41 volumio sudo[28895]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:41 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:41 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:41 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:41 volumio systemd[1]: Reloading. Dec 30 15:47:41 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 15:47:41 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:41 volumio volumio[28379]: info: CoreCommandRouter::volumioGetState Dec 30 15:47:41 volumio volumio[28379]: info: CorePlayQueue::getTrack 0 Dec 30 15:47:41 volumio volumio[28379]: info: Starting Shairport Sync Dec 30 15:47:41 volumio sudo[28896]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 30 15:47:41 volumio sudo[28896]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 30 15:47:41 volumio sudo[28904]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 30 15:47:41 volumio sudo[28904]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:41 volumio sudo[28896]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:41 volumio volumio[28379]: SPOTIFY: User informations: {"display_name":"Clint Smith","external_urls":{"spotify":"https://open.spotify.com/user/clintsmith1"},"followers":{"href":null,"total":7},"href":"https://api.spotify.com/v1/users/clintsmith1","id":"clintsmith1","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee856520409d25d9cc210472a0fd","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b826520409d25d9cc210472a0fd","width":64}],"type":"user","uri":"spotify:user:clintsmith1"} Dec 30 15:47:41 volumio volumio[28379]: info: Spotify Successfully logged in Dec 30 15:47:41 volumio volumio[28379]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 15:47:41 volumio volumio[28379]: info: [1767131261633] CoreMusicLibrary::Adding element Spotify Dec 30 15:47:41 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 15:47:41 volumio volumio[28379]: Cannot find translation for source Bandcamp Discover Dec 30 15:47:41 volumio volumio[28379]: Cannot find translation for source SoundCloud Dec 30 15:47:41 volumio volumio[28379]: Cannot find translation for source YouTube2 Dec 30 15:47:41 volumio volumio[28379]: Cannot find translation for source YouTube Music Dec 30 15:47:41 volumio volumio[28379]: Cannot find translation for source Podcast Dec 30 15:47:41 volumio volumio[28379]: Cannot find translation for source Volusonic Dec 30 15:47:41 volumio volumio[28379]: Cannot find translation for source Spotify Dec 30 15:47:42 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:42 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:42 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:47:42 volumio volumio[28379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 30 15:47:43 volumio volumio[28379]: info: go-librespot daemon successfully initialized Dec 30 15:47:43 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 30 15:47:43 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 30 15:47:44 volumio sudo[28895]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:44 volumio volumio[28379]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 30 15:47:44 volumio sudo[28926]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 30 15:47:44 volumio sudo[28926]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Dec 30 15:47:44 volumio sudo[28926]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:44 volumio volumio[28379]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Dec 30 15:47:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:47:44 volumio sudo[28930]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Dec 30 15:47:44 volumio sudo[28930]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:47:44 volumio go-librespot[28929]: go-librespot daemon starting... Dec 30 15:47:44 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 30 15:47:44 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 30 15:47:44 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 30 15:47:44 volumio systemd[1]: shairport-sync.service: Consumed 1.458s CPU time. Dec 30 15:47:44 volumio go-librespot[28932]: time="2025-12-30T15:47:44-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 15:47:44 volumio go-librespot[28932]: time="2025-12-30T15:47:44-06:00" level=debug msg="app state loaded" Dec 30 15:47:44 volumio go-librespot[28932]: time="2025-12-30T15:47:44-06:00" level=debug msg="stored credentials not found" Dec 30 15:47:44 volumio go-librespot[28932]: time="2025-12-30T15:47:44-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 15:47:44 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 30 15:47:44 volumio sudo[28904]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:44 volumio volumio[28379]: info: Shairport-Sync Started Dec 30 15:47:44 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Dec 30 15:47:44 volumio systemd[1]: squeezelite.service: Deactivated successfully. Dec 30 15:47:44 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Dec 30 15:47:44 volumio sudo[28930]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:44 volumio go-librespot[28932]: time="2025-12-30T15:47:44-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 30 15:47:44 volumio go-librespot[28932]: time="2025-12-30T15:47:44-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 30 15:47:44 volumio go-librespot[28932]: time="2025-12-30T15:47:44-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 30 15:47:44 volumio go-librespot[28932]: time="2025-12-30T15:47:44-06:00" level=info msg="zeroconf server listening on port 38621" Dec 30 15:47:45 volumio go-librespot[28932]: time="2025-12-30T15:47:45-06:00" level=debug msg="obtained new client token: AACzrAO6XMfe+e9AdEo+Xj/GNPzXPUGmXd7mHpYqlBQsGT5jTzwG0K86V2b4MVRtwOJVR/pgB4CW0GSewk2U0E+qU8IPzDB+8uJQPtismLtwpLl9uz7J2DO5MFKssYj0zp1D2SoLIJAIBmbfNSjT6W17sL2c3wUe1Y28o+TUndwujcp5tSYtn6jISYItYHuQcsgcSKkrj6yx4yOEkJktny7eOh33AhDlmyS820JldTk9JMMmUj+nGUw=" Dec 30 15:47:45 volumio go-librespot[28932]: time="2025-12-30T15:47:45-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 15:47:45 volumio go-librespot[28932]: time="2025-12-30T15:47:45-06:00" level=debug msg="completed keyexchange" Dec 30 15:47:45 volumio go-librespot[28932]: time="2025-12-30T15:47:45-06:00" level=debug msg="completed challenge" Dec 30 15:47:45 volumio go-librespot[28932]: time="2025-12-30T15:47:45-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 30 15:47:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 15:47:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 15:47:45 volumio volumio[28379]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 30 15:47:45 volumio volumio-remote-updater[702]: [2025-12-30 15:47:45] [connect] Successful connection Dec 30 15:47:45 volumio volumio-remote-updater[702]: [2025-12-30 15:47:45] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1767131265 101 Dec 30 15:47:45 volumio volumio[28379]: 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: 3 Dec 30 15:47:45 volumio sudo[28955]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 30 15:47:45 volumio sudo[28955]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:45 volumio sudo[28955]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:45 volumio volumio[28379]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Dec 30 15:47:45 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.50.79 Dec 30 15:47:45 volumio avahi-daemon[664]: Registering new address record for 169.254.50.79 on eth0.IPv4. Dec 30 15:47:45 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Dec 30 15:47:45 volumio sudo[28960]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Dec 30 15:47:45 volumio sudo[28960]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:45 volumio sudo[28960]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:45 volumio volumio[28379]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Dec 30 15:47:45 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:45 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 15:47:45 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:45 volumio sudo[28972]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Dec 30 15:47:45 volumio sudo[28972]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:45 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Dec 30 15:47:45 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Dec 30 15:47:45 volumio sudo[28972]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:45 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.50.79 Dec 30 15:47:46 volumio volumio[28379]: info: Initializing connection to go-librespot Websocket Dec 30 15:47:46 volumio volumio[28379]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 30 15:47:46 volumio volumio[28379]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 30 15:47:46 volumio sudo[28985]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 30 15:47:46 volumio sudo[28985]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:46 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.50.79 Dec 30 15:47:46 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.50.79 Dec 30 15:47:46 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Dec 30 15:47:46 volumio avahi-daemon[664]: Withdrawing address record for 169.254.50.79 on eth0. Dec 30 15:47:46 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Dec 30 15:47:46 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:46 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 15:47:46 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:46 volumio sudo[28985]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:47 volumio volumio[28379]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 30 15:47:47 volumio sudo[29006]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 30 15:47:47 volumio sudo[29006]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:47 volumio sudo[29006]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:47 volumio volumio[28379]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 30 15:47:47 volumio sudo[29023]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 30 15:47:47 volumio sudo[29023]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:48 volumio sudo[29023]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Dec 30 15:47:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:47:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:47:48 volumio go-librespot[29026]: go-librespot daemon starting... Dec 30 15:47:48 volumio volumio[28379]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 30 15:47:48 volumio go-librespot[29027]: time="2025-12-30T15:47:48-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 15:47:48 volumio go-librespot[29027]: time="2025-12-30T15:47:48-06:00" level=debug msg="app state loaded" Dec 30 15:47:48 volumio go-librespot[29027]: time="2025-12-30T15:47:48-06:00" level=debug msg="stored credentials not found" Dec 30 15:47:48 volumio go-librespot[29027]: time="2025-12-30T15:47:48-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 15:47:48 volumio sudo[29034]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 30 15:47:48 volumio sudo[29034]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:48 volumio sudo[29034]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:48 volumio go-librespot[29027]: time="2025-12-30T15:47:48-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 30 15:47:48 volumio go-librespot[29027]: time="2025-12-30T15:47:48-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 30 15:47:48 volumio go-librespot[29027]: time="2025-12-30T15:47:48-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 30 15:47:49 volumio go-librespot[29027]: time="2025-12-30T15:47:49-06:00" level=info msg="zeroconf server listening on port 44221" Dec 30 15:47:49 volumio volumio[28379]: info: Initializing connection to go-librespot Websocket Dec 30 15:47:49 volumio go-librespot[29027]: time="2025-12-30T15:47:49-06:00" level=debug msg="new websocket client" Dec 30 15:47:49 volumio volumio[28379]: info: Connection to go-librespot Websocket established Dec 30 15:47:49 volumio go-librespot[29027]: time="2025-12-30T15:47:49-06:00" level=debug msg="obtained new client token: AADxvravNMc5sjNBRDWwZvrdIZ7HK1J2dnnRkQfGjJbZksZ7yj8FKLOasj750qmBC7c3SiUb18B0NRekfLfhtrevLXuh6/5n6C4bQK0mAtiXeey4DJHzgCTW4kXIlA4E/1amlhkzcjAfiyafbR7hIj3tGFAeNcoOIg0AJfcrhptTb/Jz4jIS793x4oMhDcLIF8CPzpfVA6zZcRYQexRFVbH1nRMPS/EdANJzVvPWRJfAf5nnW0xhzMY=" Dec 30 15:47:49 volumio go-librespot[29027]: time="2025-12-30T15:47:49-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 15:47:49 volumio mpd[28924]: 2025-12-30T15:47:49 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 30 15:47:49 volumio volumio[28379]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 30 15:47:49 volumio go-librespot[29027]: time="2025-12-30T15:47:49-06:00" level=debug msg="completed keyexchange" Dec 30 15:47:49 volumio go-librespot[29027]: time="2025-12-30T15:47:49-06:00" level=debug msg="completed challenge" Dec 30 15:47:49 volumio sudo[29038]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 30 15:47:49 volumio sudo[29038]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:49 volumio go-librespot[29027]: time="2025-12-30T15:47:49-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 30 15:47:49 volumio volumio[28379]: info: Connection to go-librespot Websocket closed Dec 30 15:47:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 15:47:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 15:47:49 volumio sudo[29038]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:49 volumio systemd[1]: Started mpd.service - Music Player Daemon. Dec 30 15:47:49 volumio sudo[28860]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:49 volumio sudo[28740]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:49 volumio sudo[28730]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:49 volumio volumio[28379]: info: Completed starting Core Plugins Dec 30 15:47:49 volumio volumio[28379]: info: ------------------------------------------- Dec 30 15:47:49 volumio volumio[28379]: info: ----- MyVolumio plugins startup ---- Dec 30 15:47:49 volumio volumio[28379]: info: ------------------------------------------- Dec 30 15:47:49 volumio volumio[28379]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 30 15:47:49 volumio volumio[28379]: error: MPD error: The expression evaluated to a falsy value: Dec 30 15:47:49 volumio volumio[28379]: assert.ok(self.idling) Dec 30 15:47:49 volumio volumio[28379]: error: The expression evaluated to a falsy value: Dec 30 15:47:49 volumio volumio[28379]: assert.ok(self.idling) Dec 30 15:47:49 volumio volumio[28379]: error: MPD error: The expression evaluated to a falsy value: Dec 30 15:47:49 volumio volumio[28379]: assert.ok(self.idling) Dec 30 15:47:49 volumio volumio[28379]: error: The expression evaluated to a falsy value: Dec 30 15:47:49 volumio volumio[28379]: assert.ok(self.idling) Dec 30 15:47:49 volumio volumio[28379]: info: MPD running with PID28924 Dec 30 15:47:49 volumio volumio[28379]: ,establishing connection Dec 30 15:47:49 volumio volumio[28379]: error: MPD error: The expression evaluated to a falsy value: Dec 30 15:47:49 volumio volumio[28379]: assert.ok(self.idling) Dec 30 15:47:49 volumio volumio[28379]: error: The expression evaluated to a falsy value: Dec 30 15:47:49 volumio volumio[28379]: assert.ok(self.idling) Dec 30 15:47:49 volumio volumio[28379]: error: updateQueue error: null Dec 30 15:47:51 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.174.120 Dec 30 15:47:51 volumio avahi-daemon[664]: Registering new address record for 169.254.174.120 on eth0.IPv4. Dec 30 15:47:51 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Dec 30 15:47:51 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:51 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 15:47:51 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:51 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.174.120 Dec 30 15:47:51 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.174.120 Dec 30 15:47:51 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.174.120 Dec 30 15:47:51 volumio avahi-daemon[664]: Withdrawing address record for 169.254.174.120 on eth0. Dec 30 15:47:51 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Dec 30 15:47:51 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Dec 30 15:47:51 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:51 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 15:47:51 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:52 volumio kernel: hwmon hwmon1: Voltage normalised Dec 30 15:47:52 volumio volumio[28379]: info: Getting Spotify volume Dec 30 15:47:52 volumio volumio[28379]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 30 15:47:52 volumio volumio[28379]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 30 15:47:52 volumio volumio[28379]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 30 15:47:52 volumio volumio[28379]: errno: -111, Dec 30 15:47:52 volumio volumio[28379]: code: 'ECONNREFUSED', Dec 30 15:47:52 volumio volumio[28379]: syscall: 'connect', Dec 30 15:47:52 volumio volumio[28379]: address: '127.0.0.1', Dec 30 15:47:52 volumio volumio[28379]: port: 9879, Dec 30 15:47:52 volumio volumio[28379]: response: undefined Dec 30 15:47:52 volumio volumio[28379]: } Dec 30 15:47:52 volumio volumio[28379]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 30 15:47:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Dec 30 15:47:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:47:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:47:52 volumio go-librespot[29090]: go-librespot daemon starting... Dec 30 15:47:52 volumio go-librespot[29091]: time="2025-12-30T15:47:52-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 15:47:52 volumio go-librespot[29091]: time="2025-12-30T15:47:52-06:00" level=debug msg="app state loaded" Dec 30 15:47:52 volumio go-librespot[29091]: time="2025-12-30T15:47:52-06:00" level=debug msg="stored credentials not found" Dec 30 15:47:52 volumio go-librespot[29091]: time="2025-12-30T15:47:52-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 15:47:52 volumio go-librespot[29091]: time="2025-12-30T15:47:52-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 30 15:47:52 volumio go-librespot[29091]: time="2025-12-30T15:47:52-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 30 15:47:52 volumio go-librespot[29091]: time="2025-12-30T15:47:52-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 30 15:47:52 volumio go-librespot[29091]: time="2025-12-30T15:47:52-06:00" level=info msg="zeroconf server listening on port 34409" Dec 30 15:47:52 volumio go-librespot[29091]: time="2025-12-30T15:47:52-06:00" level=debug msg="obtained new client token: AACFEVeF/0W/JUDLdbOA+CybJxAHkaEnppV5kUc/+UJyd+/PjHxIwvMSAUjX3kkWK/RBLbYDil/mlM9v8QQwO01jFwWs9+AkcdkAmZtfAdTOwZsf3u+5W+NDzvDjAqAYqKcQwTtybCmb+WgriOpQOmJnyJZQDrgKFADhgrO3nUx+u1TKjGVmy0dN5x9RLlZDH6lxh6fj/1Y7iVwpWGw/Cz/CW8hBh7/K2IH12s5lvpvvApTtdRjZvqZhJA==" Dec 30 15:47:52 volumio sudo[29100]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-30 15:46' Dec 30 15:47:52 volumio sudo[29100]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:52 volumio go-librespot[29091]: time="2025-12-30T15:47:52-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 15:47:52 volumio go-librespot[29091]: time="2025-12-30T15:47:52-06:00" level=debug msg="completed keyexchange" Dec 30 15:47:52 volumio go-librespot[29091]: time="2025-12-30T15:47:52-06:00" level=debug msg="completed challenge" Dec 30 15:47:53 volumio go-librespot[29091]: time="2025-12-30T15:47:53-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 30 15:47:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 15:47:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 15:47:53 volumio sudo[29100]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:53 volumio volumio-remote-updater[702]: [2025-12-30 15:47:53] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 30 15:47:53 volumio volumio-remote-updater[702]: [2025-12-30 15:47:53] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 30 15:47:53 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 30 15:47:53 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 30 15:47:53 volumio systemd[1]: volumio.service: Consumed 50.227s CPU time. Dec 30 15:47:53 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 30 15:47:53 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Dec 30 15:47:53 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 1001. Dec 30 15:47:53 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 30 15:47:53 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 30 15:47:53 volumio systemd[1]: volumio.service: Consumed 50.227s CPU time. Dec 30 15:47:53 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Dec 30 15:47:53 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Dec 30 15:47:55 volumio volumio[29112]: info: ------------------------------------------- Dec 30 15:47:55 volumio volumio[29112]: info: ----- Volumio3 ---- Dec 30 15:47:55 volumio volumio[29112]: info: ------------------------------------------- Dec 30 15:47:55 volumio volumio[29112]: info: ----- System startup ---- Dec 30 15:47:55 volumio volumio[29112]: info: ------------------------------------------- Dec 30 15:47:56 volumio volumio[29112]: info: MYVOLUMIO Environment detected Dec 30 15:47:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Dec 30 15:47:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:47:56 volumio volumio[29112]: info: Plugin folders cleanup Dec 30 15:47:56 volumio volumio[29112]: info: Scanning into folder /volumio/app/plugins/ Dec 30 15:47:56 volumio volumio[29112]: info: Scanning category audio_interface Dec 30 15:47:56 volumio volumio[29112]: info: Scanning category miscellanea Dec 30 15:47:56 volumio volumio[29112]: info: Scanning category music_service Dec 30 15:47:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:47:56 volumio volumio[29112]: info: Scanning category plugins.json Dec 30 15:47:56 volumio volumio[29112]: info: Scanning category system_controller Dec 30 15:47:56 volumio go-librespot[29136]: go-librespot daemon starting... Dec 30 15:47:56 volumio volumio[29112]: info: Scanning category user_interface Dec 30 15:47:56 volumio volumio[29112]: info: Scanning into folder /data/plugins/ Dec 30 15:47:56 volumio volumio[29112]: info: Scanning category audio_interface Dec 30 15:47:56 volumio volumio[29112]: info: Scanning category music_service Dec 30 15:47:56 volumio volumio[29112]: info: Scanning category system_controller Dec 30 15:47:56 volumio volumio[29112]: info: Scanning category system_hardware Dec 30 15:47:56 volumio volumio[29112]: info: Scanning category user_interface Dec 30 15:47:56 volumio volumio[29112]: info: Plugin folders cleanup completed Dec 30 15:47:56 volumio volumio[29112]: info: ------------------------------------------- Dec 30 15:47:56 volumio volumio[29112]: info: ----- Core plugins startup ---- Dec 30 15:47:56 volumio volumio[29112]: info: ------------------------------------------- Dec 30 15:47:56 volumio volumio[29112]: info: Loading plugins from folder /volumio/app/plugins/ Dec 30 15:47:56 volumio go-librespot[29137]: time="2025-12-30T15:47:56-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 15:47:56 volumio go-librespot[29137]: time="2025-12-30T15:47:56-06:00" level=debug msg="app state loaded" Dec 30 15:47:56 volumio go-librespot[29137]: time="2025-12-30T15:47:56-06:00" level=debug msg="stored credentials not found" Dec 30 15:47:56 volumio volumio[29112]: info: Adding plugin upnp to MyMusic Plugins Dec 30 15:47:56 volumio go-librespot[29137]: time="2025-12-30T15:47:56-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 15:47:56 volumio volumio[29112]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 30 15:47:56 volumio volumio[29112]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 30 15:47:56 volumio volumio[29112]: info: Loading plugins from folder /data/plugins/ Dec 30 15:47:56 volumio volumio[29112]: info: Loading plugin "system"... Dec 30 15:47:56 volumio volumio[29112]: info: Loading plugin "appearance"... Dec 30 15:47:56 volumio go-librespot[29137]: time="2025-12-30T15:47:56-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 30 15:47:56 volumio go-librespot[29137]: time="2025-12-30T15:47:56-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 30 15:47:56 volumio go-librespot[29137]: time="2025-12-30T15:47:56-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 30 15:47:56 volumio go-librespot[29137]: time="2025-12-30T15:47:56-06:00" level=info msg="zeroconf server listening on port 34419" Dec 30 15:47:56 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.25.180 Dec 30 15:47:56 volumio avahi-daemon[664]: Registering new address record for 169.254.25.180 on eth0.IPv4. Dec 30 15:47:56 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Dec 30 15:47:56 volumio go-librespot[29137]: time="2025-12-30T15:47:56-06:00" level=debug msg="obtained new client token: AABf/H/yqtP/6Gfya/5vyuo51x/45SMkzEJOYQmApbNk7X2mIUVqzFRw9fSP8//h3clGLVukF/BNGUoTPEU1SSsXlgE/wGuWXGtMuO5rgynr3yFudsBW+bSVo6nmg57YffRqlGsJmAa6x7g++ejIA9ioBaOvfpMYbMYepdQPXitUXW5Oqr2gQUJTn5CCQWepE+Q1fWVLWPQJxIh5ORXFXP471ap8nY4kgN+yl8gELM/yUmjgXYRhePePtA==" Dec 30 15:47:56 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:56 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 15:47:56 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:56 volumio go-librespot[29137]: time="2025-12-30T15:47:56-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 15:47:56 volumio go-librespot[29137]: time="2025-12-30T15:47:56-06:00" level=debug msg="completed keyexchange" Dec 30 15:47:56 volumio go-librespot[29137]: time="2025-12-30T15:47:56-06:00" level=debug msg="completed challenge" Dec 30 15:47:56 volumio go-librespot[29137]: time="2025-12-30T15:47:56-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 30 15:47:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 15:47:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 15:47:57 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.25.180 Dec 30 15:47:57 volumio volumio[29112]: info: Loading plugin "network"... Dec 30 15:47:57 volumio volumio[29112]: info: Refreshing Cached IP Addresses Dec 30 15:47:57 volumio sudo[29165]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 30 15:47:57 volumio sudo[29165]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:57 volumio sudo[29167]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 30 15:47:57 volumio sudo[29167]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:57 volumio sudo[29167]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:57 volumio sudo[29165]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:57 volumio volumio[29112]: info: Loading plugin "services"... Dec 30 15:47:57 volumio volumio[29112]: info: Loading plugin "alsa_controller"... Dec 30 15:47:57 volumio sudo[29178]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 30 15:47:57 volumio sudo[29178]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:57 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 30 15:47:57 volumio volumio[29112]: info: Loading plugin "wizard"... Dec 30 15:47:57 volumio volumio[29112]: info: Loading plugin "networkfs"... Dec 30 15:47:57 volumio volumio[29112]: info: Starting Udev Watcher for removable devices Dec 30 15:47:57 volumio volumio[29112]: info: Ignoring mount for partition: boot Dec 30 15:47:57 volumio volumio[29112]: info: Ignoring mount for partition: volumio Dec 30 15:47:57 volumio volumio[29112]: info: Ignoring mount for partition: volumio_data Dec 30 15:47:57 volumio volumio[29112]: info: Mounting Device Wikipedia Dec 30 15:47:57 volumio sudo[29204]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Dec 30 15:47:57 volumio sudo[29204]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:47:57 volumio sudo[29204]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:57 volumio volumio[29112]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Dec 30 15:47:57 volumio volumio[29112]: dmesg(1) may have more information after failed mount system call. Dec 30 15:47:57 volumio volumio[29112]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Dec 30 15:47:57 volumio volumio[29112]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Dec 30 15:47:57 volumio volumio[29112]: dmesg(1) may have more information after failed mount system call. Dec 30 15:47:57 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 30 15:47:57 volumio volumio[29112]: info: Loading plugin "volumio_command_line_client"... Dec 30 15:47:57 volumio volumio[29112]: info: Loading plugin "upnp"... Dec 30 15:47:57 volumio volumio[29112]: info: [1767131277935] Starting Upmpd Daemon Dec 30 15:47:57 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 30 15:47:57 volumio volumio[29112]: info: Loading plugin "my_music"... Dec 30 15:47:57 volumio volumio[29112]: info: Loading plugin "mpd"... Dec 30 15:47:57 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.25.180 Dec 30 15:47:57 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.25.180 Dec 30 15:47:57 volumio avahi-daemon[664]: Withdrawing address record for 169.254.25.180 on eth0. Dec 30 15:47:57 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Dec 30 15:47:58 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:58 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 15:47:58 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:47:58 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Dec 30 15:47:58 volumio sudo[29178]: pam_unix(sudo:session): session closed for user root Dec 30 15:47:58 volumio kernel: hwmon hwmon1: Undervoltage detected! Dec 30 15:47:58 volumio volumio-remote-updater[702]: [2025-12-30 15:47:58] [connect] Successful connection Dec 30 15:47:58 volumio volumio[29112]: info: Loading plugin "upnp_browser"... Dec 30 15:47:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Dec 30 15:47:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:48:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:48:00 volumio go-librespot[29223]: go-librespot daemon starting... Dec 30 15:48:00 volumio go-librespot[29224]: time="2025-12-30T15:48:00-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 15:48:00 volumio go-librespot[29224]: time="2025-12-30T15:48:00-06:00" level=debug msg="app state loaded" Dec 30 15:48:00 volumio go-librespot[29224]: time="2025-12-30T15:48:00-06:00" level=debug msg="stored credentials not found" Dec 30 15:48:00 volumio go-librespot[29224]: time="2025-12-30T15:48:00-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 15:48:00 volumio go-librespot[29224]: time="2025-12-30T15:48:00-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 30 15:48:00 volumio go-librespot[29224]: time="2025-12-30T15:48:00-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 30 15:48:00 volumio go-librespot[29224]: time="2025-12-30T15:48:00-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 30 15:48:00 volumio go-librespot[29224]: time="2025-12-30T15:48:00-06:00" level=info msg="zeroconf server listening on port 34981" Dec 30 15:48:00 volumio go-librespot[29224]: time="2025-12-30T15:48:00-06:00" level=debug msg="obtained new client token: AABF+xSCpvomcWj7KP3CPLdPvg3+ZXW+KjVwTnfxt7IFpB53Cf0hANINEOrV70zV48xI+jCeqDhBvlUvM3XuhDjJqb6Q/kyR77v9izsuwFSgwXdf7BRhjaGYV/kIYWGjCVzZpzAFNfs0kDygK69FTM/yqih+6vqmKxhyaBAEbyBpAspJTerDSyFbu0cwekJAI4V0S+qaGQQUcP9kWGKox3rMWxECbiJh+Zli3nKHgwcp36vRV62ZIpkhkg==" Dec 30 15:48:00 volumio go-librespot[29224]: time="2025-12-30T15:48:00-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 15:48:00 volumio go-librespot[29224]: time="2025-12-30T15:48:00-06:00" level=debug msg="completed keyexchange" Dec 30 15:48:00 volumio go-librespot[29224]: time="2025-12-30T15:48:00-06:00" level=debug msg="completed challenge" Dec 30 15:48:00 volumio go-librespot[29224]: time="2025-12-30T15:48:00-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 30 15:48:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 15:48:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 15:48:01 volumio volumio[29112]: info: Loading plugin "alarm-clock"... Dec 30 15:48:01 volumio volumio[29112]: info: Loading plugin "airplay_emulation"... Dec 30 15:48:01 volumio volumio[29112]: info: Starting Shairport Sync Dec 30 15:48:01 volumio volumio[29112]: info: Loading plugin "last_100"... Dec 30 15:48:01 volumio volumio[29112]: info: Loading plugin "webradio"... Dec 30 15:48:01 volumio volumio[29112]: info: Loading plugin "i2s_dacs"... Dec 30 15:48:01 volumio volumio[29112]: info: I2S DAC not set, start Auto-detection Dec 30 15:48:01 volumio volumio[29112]: info: Loading plugin "volumiodiscovery"... Dec 30 15:48:01 volumio volumio[29112]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 30 15:48:01 volumio volumio[29112]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 30 15:48:01 volumio volumio[29112]: *** WARNING *** For more information see Dec 30 15:48:01 volumio volumio[29112]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 30 15:48:01 volumio volumio[29112]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 30 15:48:01 volumio volumio[29112]: *** WARNING *** For more information see Dec 30 15:48:01 volumio node[29112]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 30 15:48:01 volumio node[29112]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 30 15:48:01 volumio node[29112]: *** WARNING *** For more information see Dec 30 15:48:01 volumio node[29112]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 30 15:48:01 volumio node[29112]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 30 15:48:01 volumio node[29112]: *** WARNING *** For more information see Dec 30 15:48:01 volumio volumio[29112]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 30 15:48:01 volumio volumio[29112]: info: Discovery: Started advertising with name: Volumio Dec 30 15:48:01 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 30 15:48:01 volumio volumio[29112]: info: Loading plugin "bandcamp"... Dec 30 15:48:02 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.218.107 Dec 30 15:48:02 volumio avahi-daemon[664]: Registering new address record for 169.254.218.107 on eth0.IPv4. Dec 30 15:48:02 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Dec 30 15:48:02 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:48:02 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 15:48:02 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:48:02 volumio volumio[29112]: info: Plugin calmradio is not enabled Dec 30 15:48:02 volumio volumio[29112]: info: Loading plugin "soundcloud"... Dec 30 15:48:03 volumio volumio[29112]: info: Loading plugin "spop"... Dec 30 15:48:03 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.218.107 Dec 30 15:48:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Dec 30 15:48:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:48:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:48:03 volumio go-librespot[29249]: go-librespot daemon starting... Dec 30 15:48:04 volumio go-librespot[29250]: time="2025-12-30T15:48:04-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 15:48:04 volumio go-librespot[29250]: time="2025-12-30T15:48:04-06:00" level=debug msg="app state loaded" Dec 30 15:48:04 volumio go-librespot[29250]: time="2025-12-30T15:48:04-06:00" level=debug msg="stored credentials not found" Dec 30 15:48:04 volumio go-librespot[29250]: time="2025-12-30T15:48:04-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 15:48:04 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.218.107 Dec 30 15:48:04 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.218.107 Dec 30 15:48:04 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Dec 30 15:48:04 volumio avahi-daemon[664]: Withdrawing address record for 169.254.218.107 on eth0. Dec 30 15:48:04 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:48:04 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 15:48:04 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:48:04 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Dec 30 15:48:04 volumio go-librespot[29250]: time="2025-12-30T15:48:04-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 30 15:48:04 volumio go-librespot[29250]: time="2025-12-30T15:48:04-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 30 15:48:04 volumio go-librespot[29250]: time="2025-12-30T15:48:04-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 30 15:48:04 volumio volumio[29112]: info: Loading plugin "squeezelite_mc"... Dec 30 15:48:04 volumio go-librespot[29250]: time="2025-12-30T15:48:04-06:00" level=info msg="zeroconf server listening on port 36145" Dec 30 15:48:04 volumio go-librespot[29250]: time="2025-12-30T15:48:04-06:00" level=debug msg="obtained new client token: AAAFboVwPpf5y0eLWuVcslLc54rDNBXG5lLQCrBwRgl2uo96yTEgcIyKdCoPR4WtgUuEEW8nGMoeUPgZOigSKQrvDzM8v+7tRaGs46r9IN1XCzfkFyb5fMhD7+GVvI78tddSIHN0cDk5JK3gR/sWToodsLM6VFCt8eTMPfKtDyam4cHfJxKkB2y6Bp+OVys2wuPFNwy00ATmghYRWmIplKDlJG1cVP2ApfSKMGjvcHTt0+rgwC8yZebo1w==" Dec 30 15:48:04 volumio go-librespot[29250]: time="2025-12-30T15:48:04-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 15:48:04 volumio kernel: hwmon hwmon1: Voltage normalised Dec 30 15:48:04 volumio go-librespot[29250]: time="2025-12-30T15:48:04-06:00" level=debug msg="completed keyexchange" Dec 30 15:48:04 volumio go-librespot[29250]: time="2025-12-30T15:48:04-06:00" level=debug msg="completed challenge" Dec 30 15:48:04 volumio go-librespot[29250]: time="2025-12-30T15:48:04-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 30 15:48:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 15:48:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 15:48:04 volumio volumio[29112]: info: Loading plugin "youtube2"... Dec 30 15:48:05 volumio volumio[29112]: info: Loading plugin "ytcr"... Dec 30 15:48:06 volumio kernel: hwmon hwmon1: Undervoltage detected! Dec 30 15:48:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Dec 30 15:48:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:48:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:48:07 volumio go-librespot[29290]: go-librespot daemon starting... Dec 30 15:48:07 volumio go-librespot[29291]: time="2025-12-30T15:48:07-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 15:48:07 volumio go-librespot[29291]: time="2025-12-30T15:48:07-06:00" level=debug msg="app state loaded" Dec 30 15:48:07 volumio go-librespot[29291]: time="2025-12-30T15:48:07-06:00" level=debug msg="stored credentials not found" Dec 30 15:48:07 volumio go-librespot[29291]: time="2025-12-30T15:48:07-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 15:48:08 volumio volumio[29112]: info: Loading plugin "ytmusic"... Dec 30 15:48:08 volumio go-librespot[29291]: time="2025-12-30T15:48:08-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 30 15:48:08 volumio go-librespot[29291]: time="2025-12-30T15:48:08-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 30 15:48:08 volumio go-librespot[29291]: time="2025-12-30T15:48:08-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 30 15:48:08 volumio go-librespot[29291]: time="2025-12-30T15:48:08-06:00" level=info msg="zeroconf server listening on port 35765" Dec 30 15:48:08 volumio go-librespot[29291]: time="2025-12-30T15:48:08-06:00" level=debug msg="obtained new client token: AACBXsA4K2ZCo5Bm43mNWpDHJzfAajsNkXsPX8lYMlbO+Nsv0kLkc2OA7A5WdVLghC1luZo/+B48yGnxI4CLHXv8HJYCPFCio3Ps6VGzQmBPz1pqg9iLCQPl7tC8dr7bn8jL4RAml5kqkogqxS7/2Y18moS/zX6IKBBkZE4QDpk7VHMhG+z/v8GvbOnhuLZyreF2/8toYBYqBRsQDWnwu5bxxhaxTMgTkdQvFtIo0M+BFg2gK1QP05G3BQ==" Dec 30 15:48:08 volumio go-librespot[29291]: time="2025-12-30T15:48:08-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 15:48:08 volumio go-librespot[29291]: time="2025-12-30T15:48:08-06:00" level=debug msg="completed keyexchange" Dec 30 15:48:08 volumio go-librespot[29291]: time="2025-12-30T15:48:08-06:00" level=debug msg="completed challenge" Dec 30 15:48:08 volumio go-librespot[29291]: time="2025-12-30T15:48:08-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 30 15:48:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 15:48:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 15:48:09 volumio volumio[29112]: info: Plugin now_playing is not enabled Dec 30 15:48:09 volumio volumio[29112]: info: Loading plugin "outputs"... Dec 30 15:48:09 volumio volumio[29112]: info: Loading plugin "albumart"... Dec 30 15:48:09 volumio volumio[29112]: info: Plugin example_plugin is not enabled Dec 30 15:48:09 volumio volumio[29112]: info: Loading plugin "inputs"... Dec 30 15:48:09 volumio volumio[29112]: info: Loading plugin "updater_comm"... Dec 30 15:48:09 volumio volumio[29112]: info: Plugin mpdemulation is not enabled Dec 30 15:48:09 volumio volumio[29112]: info: Loading plugin "rest_api"... Dec 30 15:48:09 volumio volumio[29112]: info: Loading plugin "websocket"... Dec 30 15:48:09 volumio volumio[29112]: info: Starting Socket.io Server version 1.7.4 Dec 30 15:48:09 volumio volumio[29112]: info: Plugin fusiondsp is not enabled Dec 30 15:48:09 volumio volumio[29112]: info: Plugin mpdoutput is not enabled Dec 30 15:48:09 volumio volumio[29112]: info: Plugin RoonBridge is not enabled Dec 30 15:48:09 volumio volumio[29112]: info: Loading plugin "podcast"... Dec 30 15:48:09 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.135.65 Dec 30 15:48:09 volumio avahi-daemon[664]: Registering new address record for 169.254.135.65 on eth0.IPv4. Dec 30 15:48:09 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Dec 30 15:48:09 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:48:09 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 15:48:09 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:48:09 volumio volumio[29112]: info: ControllerPodcast::constructor Dec 30 15:48:09 volumio volumio[29112]: info: Loading plugin "volusonic"... Dec 30 15:48:09 volumio volumio[29299]: Forking 3 albumart workers Dec 30 15:48:10 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.135.65 Dec 30 15:48:10 volumio ntpd[872]: IO: Listen normally on 688 eth0 169.254.135.65:123 Dec 30 15:48:10 volumio ntpd[872]: IO: new interface(s) found: waking up resolver Dec 30 15:48:10 volumio volumio-remote-updater[702]: [2025-12-30 15:48:10] [connect] Successful connection Dec 30 15:48:10 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.135.65 Dec 30 15:48:10 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.135.65 Dec 30 15:48:10 volumio avahi-daemon[664]: Withdrawing address record for 169.254.135.65 on eth0. Dec 30 15:48:10 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Dec 30 15:48:10 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:48:10 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 15:48:10 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Dec 30 15:48:10 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:48:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Dec 30 15:48:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:48:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:48:11 volumio go-librespot[29374]: go-librespot daemon starting... Dec 30 15:48:11 volumio go-librespot[29375]: time="2025-12-30T15:48:11-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 15:48:11 volumio go-librespot[29375]: time="2025-12-30T15:48:11-06:00" level=debug msg="app state loaded" Dec 30 15:48:11 volumio go-librespot[29375]: time="2025-12-30T15:48:11-06:00" level=debug msg="stored credentials not found" Dec 30 15:48:11 volumio go-librespot[29375]: time="2025-12-30T15:48:11-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 15:48:12 volumio volumio[29328]: Starting albumart workers Dec 30 15:48:12 volumio ntpd[872]: IO: Deleting interface #688 eth0, 169.254.135.65#123, interface stats: received=0, sent=0, dropped=0, active_time=2 secs Dec 30 15:48:12 volumio volumio[29112]: info: Applying required configuration parameters for plugin volusonic Dec 30 15:48:12 volumio volumio[29112]: info: Loading plugin "backup_restore"... Dec 30 15:48:12 volumio go-librespot[29375]: time="2025-12-30T15:48:12-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 30 15:48:12 volumio go-librespot[29375]: time="2025-12-30T15:48:12-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 30 15:48:12 volumio go-librespot[29375]: time="2025-12-30T15:48:12-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 30 15:48:12 volumio go-librespot[29375]: time="2025-12-30T15:48:12-06:00" level=info msg="zeroconf server listening on port 45463" Dec 30 15:48:12 volumio go-librespot[29375]: time="2025-12-30T15:48:12-06:00" level=debug msg="obtained new client token: AABvjn//KJiG0Cu/S6H/51PtEWkCaYvoLpzH33rVH1bkmtNKQOx1KXQSkIv0AmRggMedPz93VKu/OHCT3sF9vfJtDV6gv5GVUlKzlddQPdidVWT57f77/kOjb5OypzUj8n3evcVm14mBcIfMB/3+LZaElPzZ/vhgUIxew4A3aFkkFIkL915/kI06A+K46Z4nKOFM2YBOqm7GHtoAAmw6aBTH1m78O0lCBF48gDaSKCMrRcQYzb3Pm2jQwg==" Dec 30 15:48:12 volumio volumio[29329]: Starting albumart workers Dec 30 15:48:12 volumio go-librespot[29375]: time="2025-12-30T15:48:12-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 15:48:12 volumio go-librespot[29375]: time="2025-12-30T15:48:12-06:00" level=debug msg="completed keyexchange" Dec 30 15:48:12 volumio go-librespot[29375]: time="2025-12-30T15:48:12-06:00" level=debug msg="completed challenge" Dec 30 15:48:12 volumio go-librespot[29375]: time="2025-12-30T15:48:12-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 30 15:48:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 15:48:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 15:48:12 volumio volumio[29330]: Starting albumart workers Dec 30 15:48:12 volumio volumio[29112]: info: Applying required configuration parameters for plugin backup_restore Dec 30 15:48:12 volumio volumio[29112]: info: Plugin rpi_eeprom_config is not enabled Dec 30 15:48:12 volumio volumio[29112]: info: Plugin rpi_eeprom_updater is not enabled Dec 30 15:48:12 volumio volumio[29112]: info: Loading plugin "scheduledrestart"... Dec 30 15:48:13 volumio volumio[29112]: info: Applying required configuration parameters for plugin scheduledrestart Dec 30 15:48:13 volumio volumio[29112]: info: Plugin Bluetoothremote is not enabled Dec 30 15:48:13 volumio volumio[29112]: info: Plugin music_services_shield is not enabled Dec 30 15:48:13 volumio volumio[29112]: info: Loading plugin "Systeminfo"... Dec 30 15:48:13 volumio volumio[29112]: info: Plugin peppymeterbasic is not enabled Dec 30 15:48:13 volumio volumio[29112]: info: Loading plugin "peppyspectrum"... Dec 30 15:48:14 volumio volumio[29112]: info: Loading i18n strings for locale en Dec 30 15:48:14 volumio volumio[29112]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Dec 30 15:48:14 volumio volumio[29112]: Updating browse sources language Dec 30 15:48:14 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 15:48:14 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 30 15:48:14 volumio volumio[29112]: info: CoreCommandRouter::initPlayerControls Dec 30 15:48:14 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:14 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:14 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:14 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:14 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:14 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:14 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:14 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:14 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 30 15:48:14 volumio volumio[29112]: Express server listening on port 3000 Dec 30 15:48:14 volumio volumio[29112]: [Metrics] WebUI: 19s 839.97ms Dec 30 15:48:14 volumio volumio[29112]: info: CoreStateMachine::resetVolumioState Dec 30 15:48:14 volumio volumio[29112]: info: CoreStateMachine::getcurrentVolume Dec 30 15:48:14 volumio volumio[29112]: info: CoreCommandRouter::volumioRetrievevolume Dec 30 15:48:14 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 15:48:14 volumio sudo[29406]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 30 15:48:14 volumio sudo[29406]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:48:14 volumio sudo[29406]: pam_unix(sudo:session): session closed for user root Dec 30 15:48:14 volumio sudo[29408]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 30 15:48:14 volumio sudo[29408]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:48:14 volumio sudo[29408]: pam_unix(sudo:session): session closed for user root Dec 30 15:48:14 volumio volumio[29112]: info: Volumio Network Manager: Network status updated: 1 Dec 30 15:48:15 volumio volumio-remote-updater[702]: [2025-12-30 15:48:15] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1767131290 101 Dec 30 15:48:15 volumio volumio[29112]: 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: 1 Dec 30 15:48:15 volumio volumio[29112]: info: VolumeController:: Volume=100 Mute =false Dec 30 15:48:15 volumio volumio[29112]: info: CoreStateMachine::pushState Dec 30 15:48:15 volumio volumio[29112]: info: CorePlayQueue::getTrack 0 Dec 30 15:48:15 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 30 15:48:15 volumio volumio[29112]: info: CoreCommandRouter::volumioPushState Dec 30 15:48:15 volumio volumio[29112]: info: CoreStateMachine::updateTrackBlock Dec 30 15:48:15 volumio volumio[29112]: info: CorePlayQueue::getTrackBlock Dec 30 15:48:15 volumio volumio[29112]: info: CoreCommandRouter::volumioRetrievevolume Dec 30 15:48:15 volumio volumio[29112]: info: Reloading queue from file Dec 30 15:48:15 volumio volumio[29112]: info: CoreStateMachine::setRepeat null single undefined Dec 30 15:48:15 volumio volumio[29112]: info: CoreStateMachine::pushState Dec 30 15:48:15 volumio volumio[29112]: info: CorePlayQueue::getTrack 0 Dec 30 15:48:15 volumio volumio[29112]: info: CoreCommandRouter::volumioPushState Dec 30 15:48:15 volumio volumio[29112]: info: CoreStateMachine::setRandom null Dec 30 15:48:15 volumio volumio[29112]: info: CoreStateMachine::pushState Dec 30 15:48:15 volumio volumio[29112]: info: CorePlayQueue::getTrack 0 Dec 30 15:48:15 volumio volumio[29112]: info: CoreCommandRouter::volumioPushState Dec 30 15:48:15 volumio volumio[29112]: info: Setting Device type: Raspberry PI Dec 30 15:48:15 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.177.169 Dec 30 15:48:15 volumio avahi-daemon[664]: Registering new address record for 169.254.177.169 on eth0.IPv4. Dec 30 15:48:15 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Dec 30 15:48:15 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:48:15 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 15:48:15 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:48:15 volumio volumio[29112]: info: VolumeController:: Volume=100 Mute =false Dec 30 15:48:15 volumio volumio[29112]: info: CoreStateMachine::pushState Dec 30 15:48:15 volumio volumio[29112]: info: CorePlayQueue::getTrack 0 Dec 30 15:48:15 volumio volumio[29112]: info: CoreCommandRouter::volumioPushState Dec 30 15:48:15 volumio volumio[29112]: info: Completed loading Core Plugins Dec 30 15:48:15 volumio sudo[29439]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 30 15:48:15 volumio volumio[29112]: info: Preparing to generate the ALSA configuration file Dec 30 15:48:15 volumio sudo[29439]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:48:15 volumio volumio[29112]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Dec 30 15:48:15 volumio volumio[29112]: info: Discovery: Found device Volumio Dec 30 15:48:15 volumio volumio[29112]: info: CoreCommandRouter::volumioGetState Dec 30 15:48:15 volumio volumio[29112]: info: CorePlayQueue::getTrack 0 Dec 30 15:48:15 volumio volumio[29112]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Dec 30 15:48:15 volumio volumio[29112]: info: Discovery: Found device Volumio Dec 30 15:48:15 volumio volumio[29112]: info: CoreCommandRouter::volumioGetState Dec 30 15:48:15 volumio volumio[29112]: info: CorePlayQueue::getTrack 0 Dec 30 15:48:15 volumio volumio[29112]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 30 15:48:15 volumio sudo[29439]: pam_unix(sudo:session): session closed for user root Dec 30 15:48:15 volumio volumio[29112]: info: Reading ALSA contributions from plugins. Dec 30 15:48:15 volumio volumio[29112]: info: Upmpdcli Daemon Started Dec 30 15:48:15 volumio volumio[29112]: info: Asound.conf file unchanged, so no further update is needed Dec 30 15:48:15 volumio volumio[29112]: info: Output device has changed, restarting MPD Dec 30 15:48:15 volumio volumio[29112]: info: Output device has changed, restarting Shairport Sync Dec 30 15:48:15 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:15 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 15:48:15 volumio sudo[29442]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 30 15:48:15 volumio sudo[29442]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:48:15 volumio sudo[29442]: pam_unix(sudo:session): session closed for user root Dec 30 15:48:15 volumio sudo[29444]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 30 15:48:15 volumio sudo[29444]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:48:15 volumio volumio[29112]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 30 15:48:15 volumio volumio[29112]: info: ___________ START PLUGINS ___________ Dec 30 15:48:15 volumio volumio[29112]: info: ControllerMpd::onStart: Initializing MPD Dec 30 15:48:15 volumio volumio[29112]: info: Creating MPD Configuration file Dec 30 15:48:15 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 30 15:48:15 volumio volumio[29112]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 15:48:15 volumio volumio[29112]: info: [1767131295779] CoreMusicLibrary::Adding element Media Servers Dec 30 15:48:15 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 15:48:15 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 30 15:48:15 volumio sudo[29452]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 30 15:48:15 volumio sudo[29452]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:48:15 volumio sudo[29452]: pam_unix(sudo:session): session closed for user root Dec 30 15:48:15 volumio sudo[29454]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 30 15:48:15 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:15 volumio sudo[29454]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:48:15 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 15:48:15 volumio volumio[29112]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 30 15:48:15 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:15 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 15:48:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Dec 30 15:48:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:48:15 volumio volumio[29112]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 30 15:48:16 volumio volumio[29112]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 15:48:16 volumio volumio[29112]: info: [1767131295995] CoreMusicLibrary::Adding element Last_100 Dec 30 15:48:16 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 15:48:16 volumio volumio[29112]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 15:48:16 volumio volumio[29112]: info: [1767131296002] CoreMusicLibrary::Adding element Webradio Dec 30 15:48:16 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 15:48:16 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 30 15:48:16 volumio volumio[29112]: info: Initializing BBC Radios Dec 30 15:48:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:48:16 volumio go-librespot[29465]: go-librespot daemon starting... Dec 30 15:48:16 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 30 15:48:16 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 30 15:48:16 volumio systemd[1]: mpd.service: Consumed 5.434s CPU time. Dec 30 15:48:16 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 30 15:48:16 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 30 15:48:16 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 30 15:48:16 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 30 15:48:16 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 30 15:48:16 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.177.169 Dec 30 15:48:16 volumio go-librespot[29470]: time="2025-12-30T15:48:16-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 15:48:16 volumio go-librespot[29470]: time="2025-12-30T15:48:16-06:00" level=debug msg="app state loaded" Dec 30 15:48:16 volumio go-librespot[29470]: time="2025-12-30T15:48:16-06:00" level=debug msg="stored credentials not found" Dec 30 15:48:16 volumio go-librespot[29470]: time="2025-12-30T15:48:16-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 15:48:16 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 30 15:48:16 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 15:48:16 volumio volumio[29112]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 15:48:16 volumio volumio[29112]: info: [1767131296190] CoreMusicLibrary::Adding element Bandcamp Discover Dec 30 15:48:16 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 15:48:16 volumio volumio[29112]: Cannot find translation for source Bandcamp Discover Dec 30 15:48:16 volumio volumio[29112]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 15:48:16 volumio volumio[29112]: info: [1767131296211] CoreMusicLibrary::Adding element SoundCloud Dec 30 15:48:16 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 15:48:16 volumio volumio[29112]: Cannot find translation for source Bandcamp Discover Dec 30 15:48:16 volumio volumio[29112]: Cannot find translation for source SoundCloud Dec 30 15:48:16 volumio volumio[29112]: info: Creating Spotify config file Dec 30 15:48:16 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:16 volumio ntpd[872]: IO: Listen normally on 689 eth0 169.254.177.169:123 Dec 30 15:48:16 volumio ntpd[872]: IO: new interface(s) found: waking up resolver Dec 30 15:48:16 volumio go-librespot[29470]: time="2025-12-30T15:48:16-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 30 15:48:16 volumio go-librespot[29470]: time="2025-12-30T15:48:16-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 30 15:48:16 volumio go-librespot[29470]: time="2025-12-30T15:48:16-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 30 15:48:16 volumio sudo[29483]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 30 15:48:16 volumio sudo[29483]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 30 15:48:16 volumio sudo[29483]: pam_unix(sudo:session): session closed for user root Dec 30 15:48:16 volumio go-librespot[29470]: time="2025-12-30T15:48:16-06:00" level=info msg="zeroconf server listening on port 44811" Dec 30 15:48:16 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.177.169 Dec 30 15:48:16 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.177.169 Dec 30 15:48:16 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Dec 30 15:48:16 volumio avahi-daemon[664]: Withdrawing address record for 169.254.177.169 on eth0. Dec 30 15:48:16 volumio go-librespot[29470]: time="2025-12-30T15:48:16-06:00" level=debug msg="obtained new client token: AAAZlzs1pv+KYDvH8VpglzOHwxcmsNAU9FJ5x2Zz6LBhsUsy4Etg3UBsBr4pkqF2yWy/A2BgGn1nH2zz10/VKaN8R4th8580fvRYrO0hzTFJ1fWXIcYxPoF3OC0yC05QKqqs87pcwpPqdpqtVVVs6uBJmys/ZJsTzQKr3+ZOHDg5TOyqu96xu7yGN4ZnP4TtORMNjrU0JJI85cJCg8Gyb3A2MQ1gO39glF8+KxniD1eYFApcaGDeS5FPgg==" Dec 30 15:48:16 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:48:16 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 15:48:16 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:48:16 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Dec 30 15:48:16 volumio go-librespot[29470]: time="2025-12-30T15:48:16-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 15:48:16 volumio volumio[29112]: info: [squeezelite_mc] Starting proxy server... Dec 30 15:48:16 volumio volumio[29112]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 15:48:16 volumio volumio[29112]: info: [1767131296684] CoreMusicLibrary::Adding element YouTube2 Dec 30 15:48:16 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 15:48:16 volumio volumio[29112]: Cannot find translation for source Bandcamp Discover Dec 30 15:48:16 volumio volumio[29112]: Cannot find translation for source SoundCloud Dec 30 15:48:16 volumio volumio[29112]: Cannot find translation for source YouTube2 Dec 30 15:48:16 volumio volumio[29112]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 15:48:16 volumio volumio[29112]: info: [1767131296704] CoreMusicLibrary::Adding element YouTube Music Dec 30 15:48:16 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 15:48:16 volumio volumio[29112]: Cannot find translation for source Bandcamp Discover Dec 30 15:48:16 volumio volumio[29112]: Cannot find translation for source SoundCloud Dec 30 15:48:16 volumio volumio[29112]: Cannot find translation for source YouTube2 Dec 30 15:48:16 volumio volumio[29112]: Cannot find translation for source YouTube Music Dec 30 15:48:16 volumio volumio[29112]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 15:48:16 volumio volumio[29112]: info: [1767131296716] CoreMusicLibrary::Adding element Podcast Dec 30 15:48:16 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 15:48:16 volumio volumio[29112]: Cannot find translation for source Bandcamp Discover Dec 30 15:48:16 volumio volumio[29112]: Cannot find translation for source SoundCloud Dec 30 15:48:16 volumio volumio[29112]: Cannot find translation for source YouTube2 Dec 30 15:48:16 volumio volumio[29112]: Cannot find translation for source YouTube Music Dec 30 15:48:16 volumio volumio[29112]: Cannot find translation for source Podcast Dec 30 15:48:16 volumio go-librespot[29470]: time="2025-12-30T15:48:16-06:00" level=debug msg="completed keyexchange" Dec 30 15:48:16 volumio go-librespot[29470]: time="2025-12-30T15:48:16-06:00" level=debug msg="completed challenge" Dec 30 15:48:16 volumio volumio[29112]: info: Loading i18n strings for locale en Dec 30 15:48:16 volumio volumio[29112]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Dec 30 15:48:16 volumio volumio[29112]: Updating browse sources language Dec 30 15:48:16 volumio volumio[29112]: Cannot find translation for source Bandcamp Discover Dec 30 15:48:16 volumio volumio[29112]: Cannot find translation for source SoundCloud Dec 30 15:48:16 volumio volumio[29112]: Cannot find translation for source YouTube2 Dec 30 15:48:16 volumio volumio[29112]: Cannot find translation for source YouTube Music Dec 30 15:48:16 volumio volumio[29112]: Cannot find translation for source Podcast Dec 30 15:48:16 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 15:48:16 volumio volumio[29112]: Cannot find translation for source Bandcamp Discover Dec 30 15:48:16 volumio volumio[29112]: Cannot find translation for source SoundCloud Dec 30 15:48:16 volumio volumio[29112]: Cannot find translation for source YouTube2 Dec 30 15:48:16 volumio volumio[29112]: Cannot find translation for source YouTube Music Dec 30 15:48:16 volumio volumio[29112]: Cannot find translation for source Podcast Dec 30 15:48:16 volumio volumio[29112]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 15:48:16 volumio volumio[29112]: info: [1767131296765] CoreMusicLibrary::Adding element Volusonic Dec 30 15:48:16 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 15:48:16 volumio volumio[29112]: Cannot find translation for source Bandcamp Discover Dec 30 15:48:16 volumio volumio[29112]: Cannot find translation for source SoundCloud Dec 30 15:48:16 volumio volumio[29112]: Cannot find translation for source YouTube2 Dec 30 15:48:16 volumio volumio[29112]: Cannot find translation for source YouTube Music Dec 30 15:48:16 volumio volumio[29112]: Cannot find translation for source Podcast Dec 30 15:48:16 volumio volumio[29112]: Cannot find translation for source Volusonic Dec 30 15:48:16 volumio go-librespot[29470]: time="2025-12-30T15:48:16-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 30 15:48:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 15:48:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 15:48:16 volumio volumio[29112]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Dec 30 15:48:16 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Dec 30 15:48:16 volumio volumio[29112]: info: Volumio Calling Home Dec 30 15:48:16 volumio volumio[29112]: info: [squeezelite_mc] Proxy server started on port 40011 Dec 30 15:48:16 volumio volumio[29112]: info: Preparing to generate the ALSA configuration file Dec 30 15:48:17 volumio volumio[29112]: info: CoreCommandRouter::volumioRetrievevolume Dec 30 15:48:17 volumio volumio[29112]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 30 15:48:17 volumio volumio[29112]: info: Reading ALSA contributions from plugins. Dec 30 15:48:17 volumio volumio[29112]: info: MPD Permissions set Dec 30 15:48:17 volumio volumio[29112]: info: MPD Permissions set Dec 30 15:48:17 volumio volumio[29112]: info: Spotify config file written Dec 30 15:48:17 volumio sudo[29515]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 30 15:48:17 volumio sudo[29515]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:48:17 volumio volumio[29112]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Dec 30 15:48:17 volumio volumio[29112]: info: VolumeController:: Volume=100 Mute =false Dec 30 15:48:17 volumio volumio[29112]: info: CoreStateMachine::pushState Dec 30 15:48:17 volumio volumio[29112]: info: CorePlayQueue::getTrack 0 Dec 30 15:48:17 volumio volumio[29112]: info: CoreCommandRouter::volumioPushState Dec 30 15:48:17 volumio volumio[29112]: info: [squeezelite_mc] Server discovery started Dec 30 15:48:17 volumio volumio[29112]: info: [squeezelite_mc] Player finder started Dec 30 15:48:17 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:17 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:17 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:17 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 30 15:48:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:48:17 volumio volumio[29112]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Dec 30 15:48:17 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:17 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:17 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:17 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:17 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:17 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:17 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:17 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:17 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 15:48:17 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:17 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:17 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:17 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:17 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:17 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:17 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:17 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:17 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:17 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 15:48:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:48:17 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:17 volumio volumio[29112]: info: No need to fix Spotify hosts Dec 30 15:48:17 volumio go-librespot[29517]: go-librespot daemon starting... Dec 30 15:48:17 volumio sudo[29515]: pam_unix(sudo:session): session closed for user root Dec 30 15:48:17 volumio go-librespot[29530]: time="2025-12-30T15:48:17-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 15:48:17 volumio go-librespot[29530]: time="2025-12-30T15:48:17-06:00" level=debug msg="app state loaded" Dec 30 15:48:17 volumio go-librespot[29530]: time="2025-12-30T15:48:17-06:00" level=debug msg="stored credentials not found" Dec 30 15:48:17 volumio go-librespot[29530]: time="2025-12-30T15:48:17-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 15:48:17 volumio volumio[29112]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Dec 30 15:48:17 volumio volumio[29112]: info: Volumio called home Dec 30 15:48:17 volumio volumio[29112]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Dec 30 15:48:17 volumio volumio[29112]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Dec 30 15:48:17 volumio volumio[29112]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf Dec 30 15:48:17 volumio go-librespot[29530]: time="2025-12-30T15:48:17-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 30 15:48:17 volumio go-librespot[29530]: time="2025-12-30T15:48:17-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 30 15:48:17 volumio go-librespot[29530]: time="2025-12-30T15:48:17-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 30 15:48:17 volumio volumio[29112]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 30 15:48:17 volumio volumio[29112]: SPOTIFY: BQB1-NJY2_FO0noBpSB4zXdl6TDEgbWfU0lDdNXK6DEK-xN5a_RFDBKt56w6LdWVuPuLoHnfFFdmmxbPcljO9uDEvikz_LN92DfwydC3yYuFU2IhWXEcVQUjSv6SFMBmuaYAViyNvBVAea7xfuwS8JyLVRCd7z5wzEAhygNrlbFddfpY3w7rwnjZoW2rAGB32A7cNV2qY5D1uXQ7RTpAJlWaxQCo0Lxoqf6WcRk Dec 30 15:48:17 volumio volumio[29112]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 30 15:48:17 volumio volumio[29112]: info: New Spotify access token = BQB1-NJY2_FO0noBpSB4zXdl6TDEgbWfU0lDdNXK6DEK-xN5a_RFDBKt56w6LdWVuPuLoHnfFFdmmxbPcljO9uDEvikz_LN92DfwydC3yYuFU2IhWXEcVQUjSv6SFMBmuaYAViyNvBVAea7xfuwS8JyLVRCd7z5wzEAhygNrlbFddfpY3w7rwnjZoW2rAGB32A7cNV2qY5D1uXQ7RTpAJlWaxQCo0Lxoqf6WcRk Dec 30 15:48:17 volumio volumio[29112]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 30 15:48:17 volumio go-librespot[29530]: time="2025-12-30T15:48:17-06:00" level=info msg="zeroconf server listening on port 40169" Dec 30 15:48:17 volumio sudo[29539]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf Dec 30 15:48:17 volumio sudo[29539]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:48:17 volumio volumio[29112]: info: Starting Shairport Sync Dec 30 15:48:17 volumio sudo[29539]: pam_unix(sudo:session): session closed for user root Dec 30 15:48:17 volumio volumio[29112]: info: Starting Shairport Sync Dec 30 15:48:17 volumio volumio[29112]: info: Starting Shairport Sync Dec 30 15:48:17 volumio sudo[29547]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 30 15:48:17 volumio sudo[29547]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:48:17 volumio go-librespot[29530]: time="2025-12-30T15:48:17-06:00" level=debug msg="obtained new client token: AAAikExOCia9c55xtFCLKUbQdi8GWi8YMS8/5ZfGIxMa85q1PhPcgj41nsm6u15MMtTfEbmv0VzFoIQyrs20qrNbQA7cYzEChGmn4Xcd5YqBgAh2G0HBFlEshuvw42iIDRjQj40kKOsCqZM5ka9Nj/0CW0gmnh4pYJ6vshSpAplEdg3F4BLP4PbY7imS+0AgM6+GQcBo5PGw2/dl6QGk8wy32WmTHHiM4iAXYtYWPvUCmYo0pchUZCiifw==" Dec 30 15:48:17 volumio sudo[29554]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 30 15:48:17 volumio sudo[29554]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:48:17 volumio sudo[29560]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 30 15:48:17 volumio sudo[29560]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:48:17 volumio volumio[29112]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Dec 30 15:48:17 volumio go-librespot[29530]: time="2025-12-30T15:48:17-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 15:48:17 volumio volumio[29112]: info: Asound.conf file unchanged, so no further update is needed Dec 30 15:48:17 volumio volumio[29112]: info: Output device has changed, restarting MPD Dec 30 15:48:17 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 30 15:48:17 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 30 15:48:17 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 30 15:48:17 volumio systemd[1]: shairport-sync.service: Consumed 2.041s CPU time. Dec 30 15:48:17 volumio volumio[29112]: info: Output device has changed, restarting Shairport Sync Dec 30 15:48:17 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:17 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 15:48:17 volumio go-librespot[29530]: time="2025-12-30T15:48:17-06:00" level=debug msg="completed keyexchange" Dec 30 15:48:17 volumio go-librespot[29530]: time="2025-12-30T15:48:17-06:00" level=debug msg="completed challenge" Dec 30 15:48:17 volumio sudo[29570]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 30 15:48:17 volumio sudo[29567]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Dec 30 15:48:17 volumio sudo[29567]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:48:17 volumio sudo[29570]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:48:17 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 30 15:48:17 volumio go-librespot[29530]: time="2025-12-30T15:48:17-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 30 15:48:17 volumio sudo[29554]: pam_unix(sudo:session): session closed for user root Dec 30 15:48:17 volumio sudo[29547]: pam_unix(sudo:session): session closed for user root Dec 30 15:48:17 volumio sudo[29572]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 30 15:48:17 volumio sudo[29567]: pam_unix(sudo:session): session closed for user root Dec 30 15:48:17 volumio sudo[29572]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:48:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 15:48:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 15:48:17 volumio sudo[29570]: pam_unix(sudo:session): session closed for user root Dec 30 15:48:17 volumio volumio[29112]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 30 15:48:18 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 30 15:48:18 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 30 15:48:18 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 30 15:48:18 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 30 15:48:18 volumio sudo[29560]: pam_unix(sudo:session): session closed for user root Dec 30 15:48:18 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 30 15:48:18 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 30 15:48:18 volumio systemd[1]: mpd.service: Consumed 1.726s CPU time. Dec 30 15:48:18 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 30 15:48:18 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 30 15:48:18 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 30 15:48:18 volumio volumio[29112]: info: MPD Permissions set Dec 30 15:48:18 volumio volumio[29112]: info: Shairport-Sync Started Dec 30 15:48:18 volumio volumio[29112]: Error adding Membership: Error: addMembership EINVAL Dec 30 15:48:18 volumio volumio[29112]: info: Shairport-Sync Started Dec 30 15:48:18 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 30 15:48:18 volumio volumio[29112]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Dec 30 15:48:18 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 30 15:48:18 volumio sudo[29605]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Dec 30 15:48:18 volumio sudo[29605]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:48:18 volumio sudo[29605]: pam_unix(sudo:session): session closed for user root Dec 30 15:48:18 volumio volumio[29112]: info: Shairport-Sync Started Dec 30 15:48:18 volumio volumio[29112]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Dec 30 15:48:18 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:18 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:18 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:18 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:18 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:18 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:18 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:18 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:18 volumio ntpd[872]: IO: Deleting interface #689 eth0, 169.254.177.169#123, interface stats: received=0, sent=0, dropped=0, active_time=2 secs Dec 30 15:48:18 volumio sudo[29620]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Dec 30 15:48:18 volumio sudo[29620]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:48:18 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 15:48:18 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:18 volumio volumio[29112]: SPOTIFY: User informations: {"display_name":"Clint Smith","external_urls":{"spotify":"https://open.spotify.com/user/clintsmith1"},"followers":{"href":null,"total":7},"href":"https://api.spotify.com/v1/users/clintsmith1","id":"clintsmith1","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee856520409d25d9cc210472a0fd","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b826520409d25d9cc210472a0fd","width":64}],"type":"user","uri":"spotify:user:clintsmith1"} Dec 30 15:48:18 volumio volumio[29112]: info: Spotify Successfully logged in Dec 30 15:48:18 volumio volumio[29112]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 15:48:18 volumio volumio[29112]: info: [1767131298426] CoreMusicLibrary::Adding element Spotify Dec 30 15:48:18 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 15:48:18 volumio volumio[29112]: Cannot find translation for source Bandcamp Discover Dec 30 15:48:18 volumio volumio[29112]: Cannot find translation for source SoundCloud Dec 30 15:48:18 volumio volumio[29112]: Cannot find translation for source YouTube2 Dec 30 15:48:18 volumio volumio[29112]: Cannot find translation for source YouTube Music Dec 30 15:48:18 volumio volumio[29112]: Cannot find translation for source Podcast Dec 30 15:48:18 volumio volumio[29112]: Cannot find translation for source Volusonic Dec 30 15:48:18 volumio volumio[29112]: Cannot find translation for source Spotify Dec 30 15:48:18 volumio systemd[1]: Reloading. Dec 30 15:48:18 volumio sudo[29600]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 30 15:48:18 volumio sudo[29600]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 30 15:48:18 volumio sudo[29600]: pam_unix(sudo:session): session closed for user root Dec 30 15:48:18 volumio volumio[29112]: info: CoreCommandRouter::volumioGetState Dec 30 15:48:18 volumio volumio[29112]: info: CorePlayQueue::getTrack 0 Dec 30 15:48:18 volumio volumio[29112]: info: Starting Shairport Sync Dec 30 15:48:18 volumio sudo[29629]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 30 15:48:18 volumio sudo[29629]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:48:19 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:19 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:19 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 15:48:19 volumio volumio[29112]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 30 15:48:20 volumio volumio[29112]: info: go-librespot daemon successfully initialized Dec 30 15:48:20 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 30 15:48:20 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 30 15:48:21 volumio sudo[29620]: pam_unix(sudo:session): session closed for user root Dec 30 15:48:21 volumio volumio[29112]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 30 15:48:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Dec 30 15:48:21 volumio sudo[29650]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 30 15:48:21 volumio sudo[29650]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:48:21 volumio sudo[29650]: pam_unix(sudo:session): session closed for user root Dec 30 15:48:21 volumio volumio[29112]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Dec 30 15:48:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:48:21 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.221.173 Dec 30 15:48:21 volumio avahi-daemon[664]: Registering new address record for 169.254.221.173 on eth0.IPv4. Dec 30 15:48:21 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Dec 30 15:48:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 15:48:21 volumio go-librespot[29652]: go-librespot daemon starting... Dec 30 15:48:21 volumio sudo[29654]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Dec 30 15:48:21 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 30 15:48:21 volumio sudo[29654]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 15:48:21 volumio volumio[29112]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 30 15:48:21 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 30 15:48:21 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 30 15:48:21 volumio systemd[1]: shairport-sync.service: Consumed 1.560s CPU time. Dec 30 15:48:21 volumio volumio[29112]: Error: addMembership ENODEV Dec 30 15:48:21 volumio volumio[29112]: at Socket.addMembership (node:dgram:860:11) Dec 30 15:48:21 volumio volumio[29112]: at addMembership (/volumio/node_modules/node-ssdp/lib/index.js:264:16) { Dec 30 15:48:21 volumio volumio[29112]: errno: -19, Dec 30 15:48:21 volumio volumio[29112]: code: 'ENODEV', Dec 30 15:48:21 volumio volumio[29112]: syscall: 'addMembership' Dec 30 15:48:21 volumio volumio[29112]: } Dec 30 15:48:21 volumio volumio[29112]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 30 15:48:21 volumio go-librespot[29664]: time="2025-12-30T15:48:21-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 15:48:21 volumio go-librespot[29664]: time="2025-12-30T15:48:21-06:00" level=debug msg="app state loaded" Dec 30 15:48:21 volumio go-librespot[29664]: time="2025-12-30T15:48:21-06:00" level=debug msg="stored credentials not found" Dec 30 15:48:21 volumio go-librespot[29664]: time="2025-12-30T15:48:21-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 15:48:22 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 30 15:48:22 volumio sudo[29629]: pam_unix(sudo:session): session closed for user root Dec 30 15:48:22 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:48:22 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 15:48:22 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:48:22 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Dec 30 15:48:22 volumio systemd[1]: squeezelite.service: Deactivated successfully. Dec 30 15:48:22 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Dec 30 15:48:22 volumio go-librespot[29664]: time="2025-12-30T15:48:22-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 30 15:48:22 volumio go-librespot[29664]: time="2025-12-30T15:48:22-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 30 15:48:22 volumio go-librespot[29664]: time="2025-12-30T15:48:22-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 30 15:48:22 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.221.173 Dec 30 15:48:22 volumio go-librespot[29664]: time="2025-12-30T15:48:22-06:00" level=info msg="zeroconf server listening on port 39991" Dec 30 15:48:22 volumio sudo[29654]: pam_unix(sudo:session): session closed for user root Dec 30 15:48:22 volumio go-librespot[29664]: time="2025-12-30T15:48:22-06:00" level=debug msg="obtained new client token: AAAutzII3WtT+SRXvRvdMvrywZC5SAM3ZQEs2RlXMCE8jSYmWVe0O9kg0dc0fuXSmMQ2XGTpyMM9hBmk44lu8WkcXz6hKCF5us1lONkQt8f/vE/uQKEzSZWa/qEwT3rZl8gTJiIKLSptnh5ctvYmx1zUZa8rl4oQ36zZ9StccvYGMQVe1eZPif/WYdDAxwlsZf1I4xsAKWf9pP780Ve8eQ/q9xOIm3APc/omVlkxYiim7hi/GW9LQfltEg==" Dec 30 15:48:22 volumio go-librespot[29664]: time="2025-12-30T15:48:22-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 15:48:22 volumio go-librespot[29664]: time="2025-12-30T15:48:22-06:00" level=debug msg="completed keyexchange" Dec 30 15:48:22 volumio go-librespot[29664]: time="2025-12-30T15:48:22-06:00" level=debug msg="completed challenge" Dec 30 15:48:22 volumio go-librespot[29664]: time="2025-12-30T15:48:22-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 30 15:48:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 15:48:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 15:48:22 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.221.173 Dec 30 15:48:22 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.221.173 Dec 30 15:48:22 volumio avahi-daemon[664]: Withdrawing address record for 169.254.221.173 on eth0. Dec 30 15:48:22 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Dec 30 15:48:23 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:48:23 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 15:48:23 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 15:48:23 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Dec 30 15:48:23 volumio sudo[29725]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-30 15:47' Dec 30 15:48:23 volumio sudo[29725]: 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="ac7dd5922ede329d1459d48b226ddc71f5209a2c" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="3441cddd43405c36fe444484553f10f2f5bc830b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Nov 13 11:04:27 UTC 2025" VOLUMIO_VERSION="4.069" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="7da8d6d9f8baf8621af4ec2af5a00f00"