Jan 09 06:57:00 volumio sudo[1564]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Jan 09 06:57:00 volumio sudo[1564]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:00 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 09 06:57:00 volumio sudo[1559]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:00 volumio volumio[1075]: info: Shairport-Sync Started Jan 09 06:57:00 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 09 06:57:00 volumio systemd[1]: Reloading. Jan 09 06:57:00 volumio volumio[1075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:00 volumio volumio[1075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:00 volumio volumio[1075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:00 volumio volumio[1075]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 09 06:57:01 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.243.98 Jan 09 06:57:01 volumio avahi-daemon[664]: Registering new address record for 169.254.243.98 on eth0.IPv4. Jan 09 06:57:01 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 09 06:57:01 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.243.98 Jan 09 06:57:01 volumio volumio[1075]: info: go-librespot daemon successfully initialized Jan 09 06:57:02 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.243.98 Jan 09 06:57:02 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.243.98 Jan 09 06:57:02 volumio avahi-daemon[664]: Withdrawing address record for 169.254.243.98 on eth0. Jan 09 06:57:02 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 09 06:57:02 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 09 06:57:02 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. Jan 09 06:57:02 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. Jan 09 06:57:03 volumio sudo[1564]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:03 volumio volumio[1075]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 09 06:57:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Jan 09 06:57:03 volumio sudo[1643]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 09 06:57:03 volumio sudo[1643]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:03 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:03 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 09 06:57:03 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:57:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:57:03 volumio go-librespot[1646]: go-librespot daemon starting... Jan 09 06:57:03 volumio go-librespot[1647]: time="2026-01-09T06:57:03-06:00" level=info msg="running go-librespot 0.4.0" Jan 09 06:57:03 volumio go-librespot[1647]: time="2026-01-09T06:57:03-06:00" level=debug msg="app state loaded" Jan 09 06:57:03 volumio go-librespot[1647]: time="2026-01-09T06:57:03-06:00" level=debug msg="stored credentials not found" Jan 09 06:57:03 volumio go-librespot[1647]: time="2026-01-09T06:57:03-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 09 06:57:03 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:03 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 09 06:57:03 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:03 volumio sudo[1643]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:03 volumio volumio[1075]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Jan 09 06:57:03 volumio sudo[1654]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Jan 09 06:57:03 volumio sudo[1654]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:03 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Jan 09 06:57:03 volumio go-librespot[1647]: time="2026-01-09T06:57: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]" Jan 09 06:57:03 volumio go-librespot[1647]: time="2026-01-09T06:57: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]" Jan 09 06:57:03 volumio go-librespot[1647]: time="2026-01-09T06:57: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]" Jan 09 06:57:03 volumio go-librespot[1647]: time="2026-01-09T06:57:03-06:00" level=info msg="zeroconf server listening on port 40683" Jan 09 06:57:03 volumio systemd[1]: squeezelite.service: Deactivated successfully. Jan 09 06:57:03 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Jan 09 06:57:03 volumio sudo[1654]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:03 volumio go-librespot[1647]: time="2026-01-09T06:57:03-06:00" level=debug msg="obtained new client token: AADuQIhhuoKfygBG8/eS6Lhg62UVuxanCSKeiLv5pjnNxL0BQIfNiRdtBL+Ya8PGecCxPqsp99SA03VucvBU04PTyPGbBcstTuoq7EfTv4J6uEzlln9lunB2IY1cvSwfTUc6RR52irF2YpxIRAJAC5Sy3YBGTFtVpyXt1ZptFmg+FvEFzY/qqn3c1480Lqx45UwS3IsErYU+qASRH9wkoLnp11OqK8VQPudVZNqvQQEWbm4Xro96IWV02g==" Jan 09 06:57:03 volumio go-librespot[1647]: time="2026-01-09T06:57:03-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 09 06:57:03 volumio go-librespot[1647]: time="2026-01-09T06:57:03-06:00" level=debug msg="completed keyexchange" Jan 09 06:57:03 volumio go-librespot[1647]: time="2026-01-09T06:57:03-06:00" level=debug msg="completed challenge" Jan 09 06:57:04 volumio volumio[1075]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 09 06:57:04 volumio sudo[1658]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 09 06:57:04 volumio sudo[1658]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:04 volumio sudo[1658]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:04 volumio volumio[1075]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Jan 09 06:57:04 volumio sudo[1662]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Jan 09 06:57:04 volumio sudo[1662]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:04 volumio sudo[1662]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:04 volumio volumio[1075]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Jan 09 06:57:04 volumio sudo[1665]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Jan 09 06:57:04 volumio sudo[1665]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:04 volumio mpd[1557]: 2026-01-09T06:57:04 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 09 06:57:04 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Jan 09 06:57:04 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Jan 09 06:57:04 volumio sudo[1665]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:04 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 09 06:57:04 volumio sudo[1439]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:04 volumio volumio[1075]: info: Initializing connection to go-librespot Websocket Jan 09 06:57:04 volumio sudo[1429]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:04 volumio sudo[1515]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:04 volumio volumio[1075]: error: MPD error: The expression evaluated to a falsy value: Jan 09 06:57:04 volumio volumio[1075]: assert.ok(self.idling) Jan 09 06:57:04 volumio volumio[1075]: error: The expression evaluated to a falsy value: Jan 09 06:57:04 volumio volumio[1075]: assert.ok(self.idling) Jan 09 06:57:04 volumio volumio[1075]: error: MPD error: The expression evaluated to a falsy value: Jan 09 06:57:04 volumio volumio[1075]: assert.ok(self.idling) Jan 09 06:57:04 volumio volumio[1075]: error: The expression evaluated to a falsy value: Jan 09 06:57:04 volumio volumio[1075]: assert.ok(self.idling) Jan 09 06:57:04 volumio go-librespot[1647]: time="2026-01-09T06:57:04-06:00" level=debug msg="new websocket client" Jan 09 06:57:04 volumio volumio[1075]: info: MPD running with PID1557 Jan 09 06:57:04 volumio volumio[1075]: ,establishing connection Jan 09 06:57:04 volumio volumio[1075]: error: updateQueue error: null Jan 09 06:57:04 volumio volumio[1075]: info: Connection to go-librespot Websocket established Jan 09 06:57:04 volumio volumio[1075]: error: updateQueue error: null Jan 09 06:57:05 volumio volumio[1075]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 09 06:57:05 volumio sudo[1676]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 09 06:57:05 volumio sudo[1676]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:05 volumio sudo[1676]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:05 volumio go-librespot[1647]: time="2026-01-09T06:57:05-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 " Jan 09 06:57:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 09 06:57:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 09 06:57:05 volumio volumio[1075]: info: Connection to go-librespot Websocket closed Jan 09 06:57:05 volumio volumio[1075]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 09 06:57:05 volumio sudo[1679]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 09 06:57:05 volumio sudo[1679]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:05 volumio sudo[1679]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:06 volumio volumio[1075]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 09 06:57:06 volumio sudo[1682]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 09 06:57:06 volumio sudo[1682]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:06 volumio kernel: hwmon hwmon1: Voltage normalised Jan 09 06:57:06 volumio sudo[1682]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:06 volumio volumio[1075]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 09 06:57:06 volumio sudo[1686]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 09 06:57:06 volumio sudo[1686]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:07 volumio sudo[1686]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:07 volumio volumio[1075]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 09 06:57:07 volumio sudo[1689]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 09 06:57:07 volumio sudo[1689]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:07 volumio sudo[1689]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:07 volumio volumio[1075]: info: Completed starting Core Plugins Jan 09 06:57:07 volumio volumio[1075]: info: ------------------------------------------- Jan 09 06:57:07 volumio volumio[1075]: info: ----- MyVolumio plugins startup ---- Jan 09 06:57:07 volumio volumio[1075]: info: ------------------------------------------- Jan 09 06:57:07 volumio volumio[1075]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 09 06:57:07 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.42.12 Jan 09 06:57:07 volumio avahi-daemon[664]: Registering new address record for 169.254.42.12 on eth0.IPv4. Jan 09 06:57:07 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 09 06:57:07 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:07 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 09 06:57:07 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:07 volumio sudo[1708]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 09 06:57:07 volumio sudo[1708]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:07 volumio sudo[1710]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 09 06:57:07 volumio sudo[1710]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:07 volumio sudo[1713]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 09 06:57:07 volumio sudo[1713]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:07 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 09 06:57:07 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 09 06:57:07 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 09 06:57:07 volumio volumio[1075]: info: Getting Spotify volume Jan 09 06:57:07 volumio volumio[1075]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 09 06:57:07 volumio volumio[1075]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 09 06:57:07 volumio volumio[1075]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 09 06:57:07 volumio volumio[1075]: errno: -111, Jan 09 06:57:07 volumio volumio[1075]: code: 'ECONNREFUSED', Jan 09 06:57:07 volumio volumio[1075]: syscall: 'connect', Jan 09 06:57:07 volumio volumio[1075]: address: '127.0.0.1', Jan 09 06:57:07 volumio volumio[1075]: port: 9879, Jan 09 06:57:07 volumio volumio[1075]: response: undefined Jan 09 06:57:07 volumio volumio[1075]: } Jan 09 06:57:07 volumio volumio[1075]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 09 06:57:07 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 09 06:57:07 volumio sudo[1713]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:07 volumio sudo[1708]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:07 volumio mpd_monitor.sh[1716]: MPD Monitor Service: Starting MPD Monitor Service Jan 09 06:57:07 volumio sudo[1710]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:08 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.42.12 Jan 09 06:57:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Jan 09 06:57:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:57:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:57:08 volumio go-librespot[1732]: go-librespot daemon starting... Jan 09 06:57:08 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.42.12 Jan 09 06:57:08 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.42.12 Jan 09 06:57:08 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 09 06:57:08 volumio avahi-daemon[664]: Withdrawing address record for 169.254.42.12 on eth0. Jan 09 06:57:08 volumio go-librespot[1733]: time="2026-01-09T06:57:08-06:00" level=info msg="running go-librespot 0.4.0" Jan 09 06:57:08 volumio go-librespot[1733]: time="2026-01-09T06:57:08-06:00" level=debug msg="app state loaded" Jan 09 06:57:08 volumio go-librespot[1733]: time="2026-01-09T06:57:08-06:00" level=debug msg="stored credentials not found" Jan 09 06:57:08 volumio go-librespot[1733]: time="2026-01-09T06:57:08-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 09 06:57:08 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:08 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 09 06:57:08 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:08 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 09 06:57:08 volumio sudo[1759]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-09 06:56' Jan 09 06:57:08 volumio sudo[1759]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:08 volumio go-librespot[1733]: time="2026-01-09T06:57: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-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 09 06:57:08 volumio go-librespot[1733]: time="2026-01-09T06:57:08-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]" Jan 09 06:57:08 volumio go-librespot[1733]: time="2026-01-09T06:57:08-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]" Jan 09 06:57:08 volumio go-librespot[1733]: time="2026-01-09T06:57:08-06:00" level=info msg="zeroconf server listening on port 46619" Jan 09 06:57:08 volumio go-librespot[1733]: time="2026-01-09T06:57:08-06:00" level=debug msg="obtained new client token: AAARjqA3kox3damZV81LvuWv7kvDOXpIF9lGQqzWCRjMp36K3zEexiMpAF0aJRk8E8YPv2mmYTkErJqGHxzlkybU/sczH6ENvuHGlCgpjekFKrQIvpQIhCIGViR+IQlmy/cyb0ScTgiQmLMcbaeuJ8rbBmlSb7Td3yJIh6WRtOdqi8SyDp+Ckb8Y/w32qLawGpkhboQg/9ByvWXUC0ogezcgIIfydIppP4/BS2h7DvPxj6G3NtsX5M4L6Q==" Jan 09 06:57:08 volumio sudo[1759]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:08 volumio go-librespot[1733]: time="2026-01-09T06:57:08-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 09 06:57:09 volumio go-librespot[1733]: time="2026-01-09T06:57:09-06:00" level=debug msg="completed keyexchange" Jan 09 06:57:09 volumio go-librespot[1733]: time="2026-01-09T06:57:09-06:00" level=debug msg="completed challenge" Jan 09 06:57:09 volumio volumio-remote-updater[14193]: [2026-01-09 06:57:09] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 09 06:57:09 volumio volumio-remote-updater[14193]: [2026-01-09 06:57:09] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 09 06:57:09 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 09 06:57:09 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 09 06:57:09 volumio systemd[1]: volumio.service: Consumed 42.269s CPU time. Jan 09 06:57:09 volumio go-librespot[1733]: time="2026-01-09T06:57:09-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 " Jan 09 06:57:09 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 09 06:57:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 09 06:57:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 09 06:57:09 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 09 06:57:09 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 16164. Jan 09 06:57:09 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 09 06:57:09 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 09 06:57:09 volumio systemd[1]: volumio.service: Consumed 42.269s CPU time. Jan 09 06:57:09 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 09 06:57:09 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 09 06:57:11 volumio volumio[1776]: info: ------------------------------------------- Jan 09 06:57:11 volumio volumio[1776]: info: ----- Volumio3 ---- Jan 09 06:57:11 volumio volumio[1776]: info: ------------------------------------------- Jan 09 06:57:11 volumio volumio[1776]: info: ----- System startup ---- Jan 09 06:57:11 volumio volumio[1776]: info: ------------------------------------------- Jan 09 06:57:12 volumio volumio[1776]: info: MYVOLUMIO Environment detected Jan 09 06:57:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Jan 09 06:57:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:57:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:57:12 volumio go-librespot[1800]: go-librespot daemon starting... Jan 09 06:57:12 volumio go-librespot[1801]: time="2026-01-09T06:57:12-06:00" level=info msg="running go-librespot 0.4.0" Jan 09 06:57:12 volumio go-librespot[1801]: time="2026-01-09T06:57:12-06:00" level=debug msg="app state loaded" Jan 09 06:57:12 volumio volumio[1776]: info: Plugin folders cleanup Jan 09 06:57:12 volumio volumio[1776]: info: Scanning into folder /volumio/app/plugins/ Jan 09 06:57:12 volumio go-librespot[1801]: time="2026-01-09T06:57:12-06:00" level=debug msg="stored credentials not found" Jan 09 06:57:12 volumio volumio[1776]: info: Scanning category audio_interface Jan 09 06:57:12 volumio go-librespot[1801]: time="2026-01-09T06:57:12-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 09 06:57:12 volumio volumio[1776]: info: Scanning category miscellanea Jan 09 06:57:12 volumio volumio[1776]: info: Scanning category music_service Jan 09 06:57:12 volumio volumio[1776]: info: Scanning category plugins.json Jan 09 06:57:12 volumio volumio[1776]: info: Scanning category system_controller Jan 09 06:57:12 volumio volumio[1776]: info: Scanning category user_interface Jan 09 06:57:12 volumio volumio[1776]: info: Scanning into folder /data/plugins/ Jan 09 06:57:12 volumio volumio[1776]: info: Scanning category audio_interface Jan 09 06:57:12 volumio volumio[1776]: info: Scanning category music_service Jan 09 06:57:12 volumio volumio[1776]: info: Scanning category system_controller Jan 09 06:57:12 volumio volumio[1776]: info: Scanning category system_hardware Jan 09 06:57:12 volumio volumio[1776]: info: Scanning category user_interface Jan 09 06:57:12 volumio volumio[1776]: info: Plugin folders cleanup completed Jan 09 06:57:12 volumio volumio[1776]: info: ------------------------------------------- Jan 09 06:57:12 volumio volumio[1776]: info: ----- Core plugins startup ---- Jan 09 06:57:12 volumio volumio[1776]: info: ------------------------------------------- Jan 09 06:57:12 volumio volumio[1776]: info: Loading plugins from folder /volumio/app/plugins/ Jan 09 06:57:12 volumio volumio[1776]: info: Adding plugin upnp to MyMusic Plugins Jan 09 06:57:12 volumio volumio[1776]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 09 06:57:12 volumio volumio[1776]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 09 06:57:12 volumio volumio[1776]: info: Loading plugins from folder /data/plugins/ Jan 09 06:57:12 volumio volumio[1776]: info: Loading plugin "system"... Jan 09 06:57:12 volumio volumio[1776]: info: Loading plugin "appearance"... Jan 09 06:57:12 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.205.31 Jan 09 06:57:12 volumio avahi-daemon[664]: Registering new address record for 169.254.205.31 on eth0.IPv4. Jan 09 06:57:12 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 09 06:57:12 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 09 06:57:12 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:12 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 09 06:57:12 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:12 volumio go-librespot[1801]: time="2026-01-09T06:57: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 09 06:57:12 volumio go-librespot[1801]: time="2026-01-09T06:57:12-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]" Jan 09 06:57:12 volumio go-librespot[1801]: time="2026-01-09T06:57:12-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]" Jan 09 06:57:12 volumio go-librespot[1801]: time="2026-01-09T06:57:12-06:00" level=info msg="zeroconf server listening on port 33489" Jan 09 06:57:12 volumio go-librespot[1801]: time="2026-01-09T06:57:12-06:00" level=debug msg="obtained new client token: AAAjck78H1qu98b/kQtNCPF9/axK19CJ9HiwZujE4vjmxYmLsuZa2ll4p4H0SX27NBt8DuQxjsPqb3gEG01griir9UTp7BcOZrMzH5JbXaRlECE6tWYexk2ZzHTswjm8ERiB7a9urnOpX9iNfprrdLUIDuRGl9diWN05ek+RLkWga9WLP7llaHCvOO8g4wUMPhUTkuI+SX+Xt5kjzrTvyJN5JllcXVbiJizSD36D8/XS+rIjjytvtqwv8g==" Jan 09 06:57:13 volumio go-librespot[1801]: time="2026-01-09T06:57:13-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 09 06:57:13 volumio go-librespot[1801]: time="2026-01-09T06:57:13-06:00" level=debug msg="completed keyexchange" Jan 09 06:57:13 volumio go-librespot[1801]: time="2026-01-09T06:57:13-06:00" level=debug msg="completed challenge" Jan 09 06:57:13 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.205.31 Jan 09 06:57:13 volumio go-librespot[1801]: time="2026-01-09T06:57:13-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 " Jan 09 06:57:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 09 06:57:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 09 06:57:13 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.205.31 Jan 09 06:57:13 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.205.31 Jan 09 06:57:13 volumio avahi-daemon[664]: Withdrawing address record for 169.254.205.31 on eth0. Jan 09 06:57:13 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 09 06:57:13 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:13 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 09 06:57:13 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:13 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 09 06:57:14 volumio volumio-remote-updater[14193]: [2026-01-09 06:57:14] [connect] Successful connection Jan 09 06:57:14 volumio volumio[1776]: info: Loading plugin "network"... Jan 09 06:57:14 volumio volumio[1776]: info: Refreshing Cached IP Addresses Jan 09 06:57:14 volumio sudo[1845]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 09 06:57:14 volumio sudo[1845]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:14 volumio sudo[1847]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 09 06:57:14 volumio volumio[1776]: info: Loading plugin "services"... Jan 09 06:57:14 volumio sudo[1847]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:14 volumio sudo[1845]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:14 volumio volumio[1776]: info: Loading plugin "alsa_controller"... Jan 09 06:57:14 volumio sudo[1847]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:14 volumio sudo[1855]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 09 06:57:14 volumio sudo[1855]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:14 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 09 06:57:14 volumio volumio[1776]: info: Loading plugin "wizard"... Jan 09 06:57:14 volumio volumio[1776]: info: Loading plugin "networkfs"... Jan 09 06:57:14 volumio volumio[1776]: info: Starting Udev Watcher for removable devices Jan 09 06:57:14 volumio volumio[1776]: info: Ignoring mount for partition: boot Jan 09 06:57:14 volumio volumio[1776]: info: Ignoring mount for partition: volumio Jan 09 06:57:14 volumio volumio[1776]: info: Ignoring mount for partition: volumio_data Jan 09 06:57:14 volumio volumio[1776]: info: Mounting Device Wikipedia Jan 09 06:57:14 volumio sudo[1884]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Jan 09 06:57:14 volumio sudo[1884]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:14 volumio sudo[1884]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:14 volumio volumio[1776]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Jan 09 06:57:14 volumio volumio[1776]: dmesg(1) may have more information after failed mount system call. Jan 09 06:57:14 volumio volumio[1776]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Jan 09 06:57:14 volumio volumio[1776]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Jan 09 06:57:14 volumio volumio[1776]: dmesg(1) may have more information after failed mount system call. Jan 09 06:57:14 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 09 06:57:14 volumio volumio[1776]: info: Loading plugin "volumio_command_line_client"... Jan 09 06:57:14 volumio volumio[1776]: info: Loading plugin "upnp"... Jan 09 06:57:15 volumio volumio[1776]: info: [1767963435002] Starting Upmpd Daemon Jan 09 06:57:15 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 09 06:57:15 volumio volumio[1776]: info: Loading plugin "my_music"... Jan 09 06:57:15 volumio volumio[1776]: info: Loading plugin "mpd"... Jan 09 06:57:15 volumio sudo[1855]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:15 volumio volumio[1776]: info: Loading plugin "upnp_browser"... Jan 09 06:57:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Jan 09 06:57:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:57:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:57:16 volumio go-librespot[1886]: go-librespot daemon starting... Jan 09 06:57:16 volumio go-librespot[1887]: time="2026-01-09T06:57:16-06:00" level=info msg="running go-librespot 0.4.0" Jan 09 06:57:16 volumio go-librespot[1887]: time="2026-01-09T06:57:16-06:00" level=debug msg="app state loaded" Jan 09 06:57:16 volumio go-librespot[1887]: time="2026-01-09T06:57:16-06:00" level=debug msg="stored credentials not found" Jan 09 06:57:16 volumio go-librespot[1887]: time="2026-01-09T06:57:16-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 09 06:57:16 volumio go-librespot[1887]: time="2026-01-09T06:57: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]" Jan 09 06:57:16 volumio go-librespot[1887]: time="2026-01-09T06:57: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]" Jan 09 06:57:16 volumio go-librespot[1887]: time="2026-01-09T06:57: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]" Jan 09 06:57:16 volumio go-librespot[1887]: time="2026-01-09T06:57:16-06:00" level=info msg="zeroconf server listening on port 45819" Jan 09 06:57:16 volumio go-librespot[1887]: time="2026-01-09T06:57:16-06:00" level=debug msg="obtained new client token: AAAkhjjD9EVtTQIBAhxlpv1C9qo4AcXRNKogyqO8f9DZd+WwP/Twf+pDiWV2NnumzJf9fGaecJz5ZuQGokss40FoieinSJKQLjEzdSkV00wES1Pt96N+QMHJDaZVT2n8kc563uQNEf1Dn9ISIcqY68Ab9DXHGK+eh5FkAC4a5qSgYTcRSKJsRIFCVrzpEOJwJssoDLUkg9zGIdU6LaLm/Ch4WZY0IUntGIi9qyfsKpltr3TRKMbR03HA4Q==" Jan 09 06:57:16 volumio go-librespot[1887]: time="2026-01-09T06:57:16-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 09 06:57:17 volumio go-librespot[1887]: time="2026-01-09T06:57:17-06:00" level=debug msg="completed keyexchange" Jan 09 06:57:17 volumio go-librespot[1887]: time="2026-01-09T06:57:17-06:00" level=debug msg="completed challenge" Jan 09 06:57:17 volumio go-librespot[1887]: time="2026-01-09T06:57: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 " Jan 09 06:57:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 09 06:57:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 09 06:57:18 volumio volumio[1776]: info: Loading plugin "alarm-clock"... Jan 09 06:57:18 volumio volumio[1776]: info: Loading plugin "airplay_emulation"... Jan 09 06:57:18 volumio volumio[1776]: info: Starting Shairport Sync Jan 09 06:57:18 volumio volumio[1776]: info: Loading plugin "last_100"... Jan 09 06:57:18 volumio volumio[1776]: info: Loading plugin "webradio"... Jan 09 06:57:18 volumio volumio[1776]: info: Loading plugin "i2s_dacs"... Jan 09 06:57:18 volumio volumio[1776]: info: I2S DAC not set, start Auto-detection Jan 09 06:57:18 volumio volumio[1776]: info: Loading plugin "volumiodiscovery"... Jan 09 06:57:18 volumio volumio[1776]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 09 06:57:18 volumio volumio[1776]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 09 06:57:18 volumio volumio[1776]: *** WARNING *** For more information see Jan 09 06:57:18 volumio volumio[1776]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 09 06:57:18 volumio volumio[1776]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 09 06:57:18 volumio volumio[1776]: *** WARNING *** For more information see Jan 09 06:57:18 volumio node[1776]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 09 06:57:18 volumio node[1776]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 09 06:57:18 volumio node[1776]: *** WARNING *** For more information see Jan 09 06:57:18 volumio node[1776]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 09 06:57:18 volumio node[1776]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 09 06:57:18 volumio node[1776]: *** WARNING *** For more information see Jan 09 06:57:18 volumio volumio[1776]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 09 06:57:18 volumio volumio[1776]: info: Discovery: Started advertising with name: Volumio Jan 09 06:57:18 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 09 06:57:18 volumio volumio[1776]: info: Loading plugin "bandcamp"... Jan 09 06:57:18 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.3.155 Jan 09 06:57:18 volumio avahi-daemon[664]: Registering new address record for 169.254.3.155 on eth0.IPv4. Jan 09 06:57:18 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 09 06:57:18 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:18 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 09 06:57:18 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:18 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.3.155 Jan 09 06:57:19 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.3.155 Jan 09 06:57:19 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.3.155 Jan 09 06:57:19 volumio avahi-daemon[664]: Withdrawing address record for 169.254.3.155 on eth0. Jan 09 06:57:19 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 09 06:57:19 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:19 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 09 06:57:19 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:19 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 09 06:57:20 volumio volumio[1776]: info: Plugin calmradio is not enabled Jan 09 06:57:20 volumio volumio[1776]: info: Loading plugin "soundcloud"... Jan 09 06:57:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Jan 09 06:57:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:57:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:57:20 volumio go-librespot[1929]: go-librespot daemon starting... Jan 09 06:57:20 volumio go-librespot[1930]: time="2026-01-09T06:57:20-06:00" level=info msg="running go-librespot 0.4.0" Jan 09 06:57:20 volumio go-librespot[1930]: time="2026-01-09T06:57:20-06:00" level=debug msg="app state loaded" Jan 09 06:57:20 volumio go-librespot[1930]: time="2026-01-09T06:57:20-06:00" level=debug msg="stored credentials not found" Jan 09 06:57:20 volumio go-librespot[1930]: time="2026-01-09T06:57:20-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 09 06:57:20 volumio go-librespot[1930]: time="2026-01-09T06:57: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 09 06:57:20 volumio go-librespot[1930]: time="2026-01-09T06:57:20-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]" Jan 09 06:57:20 volumio go-librespot[1930]: time="2026-01-09T06:57:20-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]" Jan 09 06:57:20 volumio go-librespot[1930]: time="2026-01-09T06:57:20-06:00" level=info msg="zeroconf server listening on port 37271" Jan 09 06:57:20 volumio go-librespot[1930]: time="2026-01-09T06:57:20-06:00" level=debug msg="obtained new client token: AABy784Jh4Kb6urbBkk1mjSwL32my4pmESEQXUPpxQcZRMxaM+1miiSzU0lYv8A9Iz1lm720Tb3iOIxZm7TwJckLl63TSShW2YhaODZhbgf9pEjTR0l2LCKEPr8C9wKGcdk4iBM4rmeozFa90m3jNP5xeX0IJxTYKj6OmshRBj2mhYF3H9MpEv5i959S/6JPo/Yr8wrsiAZbfkWSWREGeaFPhVor10hm85aaDhoE+Z/Z9ZH18WFkh1WAsg==" Jan 09 06:57:20 volumio volumio[1776]: info: Loading plugin "spop"... Jan 09 06:57:20 volumio go-librespot[1930]: time="2026-01-09T06:57:20-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 09 06:57:20 volumio go-librespot[1930]: time="2026-01-09T06:57:20-06:00" level=debug msg="completed keyexchange" Jan 09 06:57:20 volumio go-librespot[1930]: time="2026-01-09T06:57:20-06:00" level=debug msg="completed challenge" Jan 09 06:57:21 volumio go-librespot[1930]: time="2026-01-09T06:57:21-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 " Jan 09 06:57:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 09 06:57:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 09 06:57:22 volumio volumio[1776]: info: Loading plugin "squeezelite_mc"... Jan 09 06:57:23 volumio volumio[1776]: info: Loading plugin "youtube2"... Jan 09 06:57:24 volumio volumio[1776]: info: Loading plugin "ytcr"... Jan 09 06:57:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Jan 09 06:57:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:57:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:57:24 volumio go-librespot[1938]: go-librespot daemon starting... Jan 09 06:57:24 volumio go-librespot[1939]: time="2026-01-09T06:57:24-06:00" level=info msg="running go-librespot 0.4.0" Jan 09 06:57:24 volumio go-librespot[1939]: time="2026-01-09T06:57:24-06:00" level=debug msg="app state loaded" Jan 09 06:57:24 volumio go-librespot[1939]: time="2026-01-09T06:57:24-06:00" level=debug msg="stored credentials not found" Jan 09 06:57:24 volumio go-librespot[1939]: time="2026-01-09T06:57:24-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 09 06:57:24 volumio go-librespot[1939]: time="2026-01-09T06:57: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]" Jan 09 06:57:24 volumio go-librespot[1939]: time="2026-01-09T06:57: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]" Jan 09 06:57:24 volumio go-librespot[1939]: time="2026-01-09T06:57: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]" Jan 09 06:57:24 volumio go-librespot[1939]: time="2026-01-09T06:57:24-06:00" level=info msg="zeroconf server listening on port 39823" Jan 09 06:57:24 volumio go-librespot[1939]: time="2026-01-09T06:57:24-06:00" level=debug msg="obtained new client token: AAChdaL9xrWAYwHF+ZouXCz0Fl6SfLM6tJ53p63XXYfkRIzDSYwYMW88xVP2yePzPYIahOto/BAZqmBdi0vOjqXMHOORBO111ZeFl1oHRMpDSGc8W+BHeF9eLI+9owOGn0enn7+p3EOmdMvKsoKnYBOdSXahbHONO0MBWEpKDrRB2UxA4a1zetya2glavBuQNjmOXe5Qq4RzuDBIynp28+U9hWO0oxNcJSu6YjVGTiA2IYWpZxHP3Mv6kQ==" Jan 09 06:57:24 volumio go-librespot[1939]: time="2026-01-09T06:57:24-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 09 06:57:24 volumio go-librespot[1939]: time="2026-01-09T06:57:24-06:00" level=debug msg="completed keyexchange" Jan 09 06:57:24 volumio go-librespot[1939]: time="2026-01-09T06:57:24-06:00" level=debug msg="completed challenge" Jan 09 06:57:24 volumio go-librespot[1939]: time="2026-01-09T06:57: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 " Jan 09 06:57:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 09 06:57:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 09 06:57:25 volumio kernel: hwmon hwmon1: Voltage normalised Jan 09 06:57:25 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.44.42 Jan 09 06:57:25 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 09 06:57:25 volumio avahi-daemon[664]: Registering new address record for 169.254.44.42 on eth0.IPv4. Jan 09 06:57:25 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:25 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 09 06:57:25 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:25 volumio volumio[1776]: info: Loading plugin "ytmusic"... Jan 09 06:57:25 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.44.42 Jan 09 06:57:26 volumio volumio[1776]: info: Plugin now_playing is not enabled Jan 09 06:57:26 volumio volumio[1776]: info: Loading plugin "outputs"... Jan 09 06:57:26 volumio volumio[1776]: info: Loading plugin "albumart"... Jan 09 06:57:26 volumio volumio[1776]: info: Plugin example_plugin is not enabled Jan 09 06:57:26 volumio volumio[1776]: info: Loading plugin "inputs"... Jan 09 06:57:26 volumio volumio[1776]: info: Loading plugin "updater_comm"... Jan 09 06:57:26 volumio volumio[1776]: info: Plugin mpdemulation is not enabled Jan 09 06:57:26 volumio volumio[1776]: info: Loading plugin "rest_api"... Jan 09 06:57:26 volumio volumio[1776]: info: Loading plugin "websocket"... Jan 09 06:57:26 volumio volumio[1776]: info: Starting Socket.io Server version 1.7.4 Jan 09 06:57:26 volumio volumio[1776]: info: Plugin fusiondsp is not enabled Jan 09 06:57:26 volumio volumio[1776]: info: Plugin mpdoutput is not enabled Jan 09 06:57:26 volumio volumio[1776]: info: Plugin RoonBridge is not enabled Jan 09 06:57:26 volumio volumio[1776]: info: Loading plugin "podcast"... Jan 09 06:57:26 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.44.42 Jan 09 06:57:26 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.44.42 Jan 09 06:57:26 volumio avahi-daemon[664]: Withdrawing address record for 169.254.44.42 on eth0. Jan 09 06:57:26 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 09 06:57:26 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:26 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 09 06:57:26 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:26 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 09 06:57:26 volumio volumio[1776]: info: ControllerPodcast::constructor Jan 09 06:57:26 volumio volumio-remote-updater[14193]: [2026-01-09 06:57:26] [connect] Successful connection Jan 09 06:57:26 volumio volumio[1776]: info: Loading plugin "volusonic"... Jan 09 06:57:26 volumio volumio[1977]: Forking 3 albumart workers Jan 09 06:57:27 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 09 06:57:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Jan 09 06:57:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:57:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:57:28 volumio go-librespot[2033]: go-librespot daemon starting... Jan 09 06:57:28 volumio go-librespot[2037]: time="2026-01-09T06:57:28-06:00" level=info msg="running go-librespot 0.4.0" Jan 09 06:57:28 volumio go-librespot[2037]: time="2026-01-09T06:57:28-06:00" level=debug msg="app state loaded" Jan 09 06:57:28 volumio go-librespot[2037]: time="2026-01-09T06:57:28-06:00" level=debug msg="stored credentials not found" Jan 09 06:57:28 volumio go-librespot[2037]: time="2026-01-09T06:57:28-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 09 06:57:28 volumio go-librespot[2037]: time="2026-01-09T06:57: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 09 06:57:28 volumio go-librespot[2037]: time="2026-01-09T06:57:28-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]" Jan 09 06:57:28 volumio go-librespot[2037]: time="2026-01-09T06:57:28-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]" Jan 09 06:57:28 volumio go-librespot[2037]: time="2026-01-09T06:57:28-06:00" level=info msg="zeroconf server listening on port 40401" Jan 09 06:57:28 volumio go-librespot[2037]: time="2026-01-09T06:57:28-06:00" level=debug msg="obtained new client token: AABHaXSIQtoZZpXrpE9ozDRXDUD7iWabOV0ojs0Yj+mMKmZDksEHDB4ifhMxxZ2Z4qGHlh3wNwKAfkjkGnw4XxtURoAELjEPF6CcbB8crkxole1/IyWizi2LkSDO/iOEPIxCknWnKkEfF7jXDBhe5/ZAX4fhnzz6DuowxIx05XKpFjaHLyxK4hPuv/jytYsFyi63HxXYgu6rQ9T49x3eQltFqXnKFtf1xJJaINuAQ0U2wXaO1ityD+xFCg==" Jan 09 06:57:28 volumio go-librespot[2037]: time="2026-01-09T06:57:28-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 09 06:57:29 volumio go-librespot[2037]: time="2026-01-09T06:57:28-06:00" level=debug msg="completed keyexchange" Jan 09 06:57:29 volumio go-librespot[2037]: time="2026-01-09T06:57:28-06:00" level=debug msg="completed challenge" Jan 09 06:57:29 volumio go-librespot[2037]: time="2026-01-09T06:57:29-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 " Jan 09 06:57:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 09 06:57:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 09 06:57:29 volumio volumio[1776]: info: Applying required configuration parameters for plugin volusonic Jan 09 06:57:29 volumio volumio[1776]: info: Loading plugin "backup_restore"... Jan 09 06:57:29 volumio volumio[2005]: Starting albumart workers Jan 09 06:57:29 volumio volumio[2004]: Starting albumart workers Jan 09 06:57:29 volumio volumio[2003]: Starting albumart workers Jan 09 06:57:29 volumio volumio[1776]: info: Applying required configuration parameters for plugin backup_restore Jan 09 06:57:29 volumio volumio[1776]: info: Plugin rpi_eeprom_config is not enabled Jan 09 06:57:29 volumio volumio[1776]: info: Plugin rpi_eeprom_updater is not enabled Jan 09 06:57:29 volumio volumio[1776]: info: Loading plugin "scheduledrestart"... Jan 09 06:57:29 volumio volumio[1776]: info: Applying required configuration parameters for plugin scheduledrestart Jan 09 06:57:30 volumio volumio[1776]: info: Plugin Bluetoothremote is not enabled Jan 09 06:57:30 volumio volumio[1776]: info: Plugin music_services_shield is not enabled Jan 09 06:57:30 volumio volumio[1776]: info: Loading plugin "Systeminfo"... Jan 09 06:57:30 volumio volumio[1776]: info: Plugin peppymeterbasic is not enabled Jan 09 06:57:30 volumio volumio[1776]: info: Loading plugin "peppyspectrum"... Jan 09 06:57:30 volumio volumio[1776]: info: Loading i18n strings for locale en Jan 09 06:57:30 volumio volumio[1776]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 09 06:57:30 volumio volumio[1776]: Updating browse sources language Jan 09 06:57:30 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::initPlayerControls Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 09 06:57:31 volumio volumio[1776]: Express server listening on port 3000 Jan 09 06:57:31 volumio volumio[1776]: [Metrics] WebUI: 20s 362.56ms Jan 09 06:57:31 volumio volumio[1776]: info: CoreStateMachine::resetVolumioState Jan 09 06:57:31 volumio volumio[1776]: info: CoreStateMachine::getcurrentVolume Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::volumioRetrievevolume Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:57:31 volumio sudo[2067]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 09 06:57:31 volumio sudo[2067]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:31 volumio sudo[2067]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:31 volumio sudo[2069]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 09 06:57:31 volumio sudo[2069]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:31 volumio sudo[2069]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:31 volumio volumio[1776]: info: Volumio Network Manager: Network status updated: 1 Jan 09 06:57:31 volumio volumio[1776]: info: VolumeController:: Volume=100 Mute =false Jan 09 06:57:31 volumio volumio[1776]: info: CoreStateMachine::pushState Jan 09 06:57:31 volumio volumio[1776]: info: CorePlayQueue::getTrack 0 Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::volumioPushState Jan 09 06:57:31 volumio volumio[1776]: info: CoreStateMachine::updateTrackBlock Jan 09 06:57:31 volumio volumio[1776]: info: CorePlayQueue::getTrackBlock Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::volumioRetrievevolume Jan 09 06:57:31 volumio volumio-remote-updater[14193]: [2026-01-09 06:57:31] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1767963446 101 Jan 09 06:57:31 volumio volumio[1776]: 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 Jan 09 06:57:31 volumio volumio[1776]: info: Reloading queue from file Jan 09 06:57:31 volumio volumio[1776]: info: CoreStateMachine::setRepeat null single undefined Jan 09 06:57:31 volumio volumio[1776]: info: CoreStateMachine::pushState Jan 09 06:57:31 volumio volumio[1776]: info: CorePlayQueue::getTrack 0 Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::volumioPushState Jan 09 06:57:31 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.225.17 Jan 09 06:57:31 volumio volumio[1776]: info: CoreStateMachine::setRandom null Jan 09 06:57:31 volumio volumio[1776]: info: CoreStateMachine::pushState Jan 09 06:57:31 volumio volumio[1776]: info: CorePlayQueue::getTrack 0 Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::volumioPushState Jan 09 06:57:31 volumio avahi-daemon[664]: Registering new address record for 169.254.225.17 on eth0.IPv4. Jan 09 06:57:31 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 09 06:57:31 volumio volumio[1776]: info: Setting Device type: Raspberry PI Jan 09 06:57:31 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:31 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 09 06:57:31 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:31 volumio volumio[1776]: info: VolumeController:: Volume=100 Mute =false Jan 09 06:57:31 volumio volumio[1776]: info: CoreStateMachine::pushState Jan 09 06:57:31 volumio volumio[1776]: info: CorePlayQueue::getTrack 0 Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::volumioPushState Jan 09 06:57:31 volumio volumio[1776]: info: Completed loading Core Plugins Jan 09 06:57:31 volumio volumio[1776]: info: Preparing to generate the ALSA configuration file Jan 09 06:57:31 volumio sudo[2099]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 09 06:57:31 volumio sudo[2099]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:31 volumio volumio[1776]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Jan 09 06:57:31 volumio volumio[1776]: info: Discovery: Found device Volumio Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::volumioGetState Jan 09 06:57:31 volumio volumio[1776]: info: CorePlayQueue::getTrack 0 Jan 09 06:57:31 volumio volumio[1776]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Jan 09 06:57:31 volumio volumio[1776]: info: Discovery: Found device Volumio Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::volumioGetState Jan 09 06:57:31 volumio volumio[1776]: info: CorePlayQueue::getTrack 0 Jan 09 06:57:31 volumio volumio[1776]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 09 06:57:31 volumio volumio[1776]: info: Reading ALSA contributions from plugins. Jan 09 06:57:31 volumio volumio[1776]: info: Asound.conf file unchanged, so no further update is needed Jan 09 06:57:31 volumio sudo[2099]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:31 volumio volumio[1776]: info: Output device has changed, restarting MPD Jan 09 06:57:31 volumio volumio[1776]: info: Output device has changed, restarting Shairport Sync Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:57:31 volumio sudo[2102]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 09 06:57:31 volumio sudo[2102]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:31 volumio sudo[2102]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:31 volumio sudo[2104]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 09 06:57:31 volumio sudo[2104]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:31 volumio volumio[1776]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 09 06:57:31 volumio volumio[1776]: info: ___________ START PLUGINS ___________ Jan 09 06:57:31 volumio volumio[1776]: info: ControllerMpd::onStart: Initializing MPD Jan 09 06:57:31 volumio volumio[1776]: info: Creating MPD Configuration file Jan 09 06:57:31 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 09 06:57:31 volumio sudo[2112]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 09 06:57:31 volumio sudo[2112]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:31 volumio volumio[1776]: info: [1767963451711] CoreMusicLibrary::Adding element Media Servers Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 09 06:57:31 volumio sudo[2112]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:31 volumio sudo[2114]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 09 06:57:31 volumio sudo[2114]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:57:31 volumio volumio[1776]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:57:31 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 09 06:57:31 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 09 06:57:31 volumio systemd[1]: mpd.service: Consumed 5.185s CPU time. Jan 09 06:57:31 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 09 06:57:31 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 09 06:57:31 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 09 06:57:31 volumio volumio[1776]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 09 06:57:31 volumio volumio[1776]: info: [1767963451821] CoreMusicLibrary::Adding element Last_100 Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 09 06:57:31 volumio volumio[1776]: info: [1767963451825] CoreMusicLibrary::Adding element Webradio Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 09 06:57:31 volumio volumio[1776]: info: Initializing BBC Radios Jan 09 06:57:31 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 09 06:57:31 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 09 06:57:31 volumio volumio[1776]: info: [1767963451906] CoreMusicLibrary::Adding element Bandcamp Discover Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 09 06:57:31 volumio volumio[1776]: Cannot find translation for source Bandcamp Discover Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 09 06:57:31 volumio volumio[1776]: info: [1767963451918] CoreMusicLibrary::Adding element SoundCloud Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 09 06:57:31 volumio volumio[1776]: Cannot find translation for source Bandcamp Discover Jan 09 06:57:31 volumio volumio[1776]: Cannot find translation for source SoundCloud Jan 09 06:57:31 volumio volumio[1776]: info: Creating Spotify config file Jan 09 06:57:31 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:32 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.225.17 Jan 09 06:57:32 volumio sudo[2139]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 09 06:57:32 volumio sudo[2139]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 09 06:57:32 volumio sudo[2139]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:32 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.225.17 Jan 09 06:57:32 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.225.17 Jan 09 06:57:32 volumio avahi-daemon[664]: Withdrawing address record for 169.254.225.17 on eth0. Jan 09 06:57:32 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 09 06:57:32 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 09 06:57:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Jan 09 06:57:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:57:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:57:32 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:32 volumio go-librespot[2158]: go-librespot daemon starting... Jan 09 06:57:32 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 09 06:57:32 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:32 volumio volumio[1776]: info: [squeezelite_mc] Starting proxy server... Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 09 06:57:32 volumio volumio[1776]: info: [1767963452326] CoreMusicLibrary::Adding element YouTube2 Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 09 06:57:32 volumio volumio[1776]: Cannot find translation for source Bandcamp Discover Jan 09 06:57:32 volumio volumio[1776]: Cannot find translation for source SoundCloud Jan 09 06:57:32 volumio volumio[1776]: Cannot find translation for source YouTube2 Jan 09 06:57:32 volumio go-librespot[2159]: time="2026-01-09T06:57:32-06:00" level=info msg="running go-librespot 0.4.0" Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 09 06:57:32 volumio volumio[1776]: info: [1767963452348] CoreMusicLibrary::Adding element YouTube Music Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 09 06:57:32 volumio volumio[1776]: Cannot find translation for source Bandcamp Discover Jan 09 06:57:32 volumio volumio[1776]: Cannot find translation for source SoundCloud Jan 09 06:57:32 volumio volumio[1776]: Cannot find translation for source YouTube2 Jan 09 06:57:32 volumio volumio[1776]: Cannot find translation for source YouTube Music Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 09 06:57:32 volumio volumio[1776]: info: [1767963452360] CoreMusicLibrary::Adding element Podcast Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 09 06:57:32 volumio volumio[1776]: Cannot find translation for source Bandcamp Discover Jan 09 06:57:32 volumio volumio[1776]: Cannot find translation for source SoundCloud Jan 09 06:57:32 volumio volumio[1776]: Cannot find translation for source YouTube2 Jan 09 06:57:32 volumio volumio[1776]: Cannot find translation for source YouTube Music Jan 09 06:57:32 volumio volumio[1776]: Cannot find translation for source Podcast Jan 09 06:57:32 volumio volumio[1776]: info: Loading i18n strings for locale en Jan 09 06:57:32 volumio volumio[1776]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 09 06:57:32 volumio volumio[1776]: Updating browse sources language Jan 09 06:57:32 volumio volumio[1776]: Cannot find translation for source Bandcamp Discover Jan 09 06:57:32 volumio volumio[1776]: Cannot find translation for source SoundCloud Jan 09 06:57:32 volumio volumio[1776]: Cannot find translation for source YouTube2 Jan 09 06:57:32 volumio volumio[1776]: Cannot find translation for source YouTube Music Jan 09 06:57:32 volumio volumio[1776]: Cannot find translation for source Podcast Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 09 06:57:32 volumio volumio[1776]: Cannot find translation for source Bandcamp Discover Jan 09 06:57:32 volumio volumio[1776]: Cannot find translation for source SoundCloud Jan 09 06:57:32 volumio volumio[1776]: Cannot find translation for source YouTube2 Jan 09 06:57:32 volumio volumio[1776]: Cannot find translation for source YouTube Music Jan 09 06:57:32 volumio volumio[1776]: Cannot find translation for source Podcast Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 09 06:57:32 volumio volumio[1776]: info: [1767963452441] CoreMusicLibrary::Adding element Volusonic Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 09 06:57:32 volumio volumio[1776]: Cannot find translation for source Bandcamp Discover Jan 09 06:57:32 volumio volumio[1776]: Cannot find translation for source SoundCloud Jan 09 06:57:32 volumio volumio[1776]: Cannot find translation for source YouTube2 Jan 09 06:57:32 volumio volumio[1776]: Cannot find translation for source YouTube Music Jan 09 06:57:32 volumio volumio[1776]: Cannot find translation for source Podcast Jan 09 06:57:32 volumio volumio[1776]: Cannot find translation for source Volusonic Jan 09 06:57:32 volumio volumio[1776]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jan 09 06:57:32 volumio volumio[1776]: info: Volumio Calling Home Jan 09 06:57:32 volumio go-librespot[2159]: time="2026-01-09T06:57:32-06:00" level=info msg="zeroconf server listening on port 32919" Jan 09 06:57:32 volumio volumio[1776]: info: [squeezelite_mc] Proxy server started on port 43421 Jan 09 06:57:32 volumio volumio[1776]: info: Preparing to generate the ALSA configuration file Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::volumioRetrievevolume Jan 09 06:57:32 volumio volumio[1776]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 09 06:57:32 volumio volumio[1776]: info: Reading ALSA contributions from plugins. Jan 09 06:57:32 volumio volumio[1776]: info: MPD Permissions set Jan 09 06:57:32 volumio volumio[1776]: info: MPD Permissions set Jan 09 06:57:32 volumio volumio[1776]: info: Upmpdcli Daemon Started Jan 09 06:57:32 volumio volumio[1776]: info: Spotify config file written Jan 09 06:57:32 volumio sudo[2172]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 09 06:57:32 volumio sudo[2172]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:32 volumio volumio[1776]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 09 06:57:32 volumio volumio[1776]: info: VolumeController:: Volume=100 Mute =false Jan 09 06:57:32 volumio volumio[1776]: info: CoreStateMachine::pushState Jan 09 06:57:32 volumio volumio[1776]: info: CorePlayQueue::getTrack 0 Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::volumioPushState Jan 09 06:57:32 volumio volumio[1776]: info: [squeezelite_mc] Server discovery started Jan 09 06:57:32 volumio volumio[1776]: info: [squeezelite_mc] Player finder started Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 09 06:57:32 volumio volumio[1776]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:32 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 09 06:57:32 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:32 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:33 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:57:33 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:33 volumio volumio[1776]: info: No need to fix Spotify hosts Jan 09 06:57:33 volumio go-librespot[2178]: go-librespot daemon starting... Jan 09 06:57:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:57:33 volumio go-librespot[2187]: time="2026-01-09T06:57:33-06:00" level=info msg="running go-librespot 0.4.0" Jan 09 06:57:33 volumio go-librespot[2187]: time="2026-01-09T06:57:33-06:00" level=debug msg="app state loaded" Jan 09 06:57:33 volumio go-librespot[2187]: time="2026-01-09T06:57:33-06:00" level=debug msg="stored credentials not found" Jan 09 06:57:33 volumio go-librespot[2187]: time="2026-01-09T06:57:33-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 09 06:57:33 volumio sudo[2172]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:33 volumio volumio[1776]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 09 06:57:33 volumio volumio[1776]: info: Volumio called home Jan 09 06:57:33 volumio volumio[1776]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Jan 09 06:57:33 volumio volumio[1776]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Jan 09 06:57:33 volumio volumio[1776]: 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 Jan 09 06:57:33 volumio volumio[1776]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 09 06:57:33 volumio volumio[1776]: SPOTIFY: BQD6z6fZ28rSoNBvcHHO_WaWQsGjvV2HDtQKTuW5xYCK8HQV6u3tCtAmkzd7D1DD6gSVRN27BGUcFteiLGlMYeGM7-aie6zXCryaUQIFIYsBF_D0unysGkIPjqnETzKD7N6T3TOhHrl_P9oyiD2kOO-XUBSKpOOiKITJl3T1A-ibXRHTH0o4LjVhj0jVXbQyqEdo3VZswguj6X_Jcs9kWxrNo6dzYBWpQSNr6nw Jan 09 06:57:33 volumio volumio[1776]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 09 06:57:33 volumio volumio[1776]: info: New Spotify access token = BQD6z6fZ28rSoNBvcHHO_WaWQsGjvV2HDtQKTuW5xYCK8HQV6u3tCtAmkzd7D1DD6gSVRN27BGUcFteiLGlMYeGM7-aie6zXCryaUQIFIYsBF_D0unysGkIPjqnETzKD7N6T3TOhHrl_P9oyiD2kOO-XUBSKpOOiKITJl3T1A-ibXRHTH0o4LjVhj0jVXbQyqEdo3VZswguj6X_Jcs9kWxrNo6dzYBWpQSNr6nw Jan 09 06:57:33 volumio volumio[1776]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 09 06:57:33 volumio go-librespot[2187]: time="2026-01-09T06:57:33-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]" Jan 09 06:57:33 volumio go-librespot[2187]: time="2026-01-09T06:57:33-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]" Jan 09 06:57:33 volumio go-librespot[2187]: time="2026-01-09T06:57:33-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]" Jan 09 06:57:33 volumio go-librespot[2187]: time="2026-01-09T06:57:33-06:00" level=info msg="zeroconf server listening on port 38877" Jan 09 06:57:33 volumio volumio[1776]: info: Starting Shairport Sync Jan 09 06:57:33 volumio volumio[1776]: info: Starting Shairport Sync Jan 09 06:57:33 volumio kernel: hwmon hwmon1: Voltage normalised Jan 09 06:57:33 volumio volumio[1776]: info: Starting Shairport Sync Jan 09 06:57:33 volumio sudo[2198]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 09 06:57:33 volumio sudo[2196]: 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 Jan 09 06:57:33 volumio sudo[2198]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:33 volumio sudo[2196]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:33 volumio sudo[2200]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 09 06:57:33 volumio sudo[2200]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:33 volumio go-librespot[2187]: time="2026-01-09T06:57:33-06:00" level=debug msg="obtained new client token: AAA3ncLk20uFxGfNF/tCygDZZmXN6vUv1Jlx5d8z7/9vu9grPwCPPcZf8Rm2o5j2UmnX4w5SXdRgeYqO2MQZ9gCQ879QDJJwPK/+ihQ+Cctbfv/Uev3Rkix688Wv8ay9S6NsbiB7K7lFt2Lv8GLu8PaRoxptjYcTbNN6GXbykJsC2HGzRniTpGG71JZ8NjcTaWY9N4rw4o92l+fzKEUF3idvgVQc9Y0ACWDzrgz8EOfKRz23bT3LfVWtOw==" Jan 09 06:57:33 volumio sudo[2203]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 09 06:57:33 volumio sudo[2203]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:33 volumio sudo[2196]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:33 volumio go-librespot[2187]: time="2026-01-09T06:57:33-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 09 06:57:33 volumio volumio[1776]: info: Asound.conf file unchanged, so no further update is needed Jan 09 06:57:33 volumio volumio[1776]: info: Output device has changed, restarting MPD Jan 09 06:57:33 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 09 06:57:33 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 09 06:57:33 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 09 06:57:33 volumio systemd[1]: shairport-sync.service: Consumed 1.932s CPU time. Jan 09 06:57:33 volumio go-librespot[2187]: time="2026-01-09T06:57:33-06:00" level=debug msg="completed keyexchange" Jan 09 06:57:33 volumio go-librespot[2187]: time="2026-01-09T06:57:33-06:00" level=debug msg="completed challenge" Jan 09 06:57:33 volumio volumio[1776]: info: Output device has changed, restarting Shairport Sync Jan 09 06:57:33 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:33 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:57:33 volumio sudo[2211]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 09 06:57:33 volumio sudo[2211]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:33 volumio go-librespot[2187]: time="2026-01-09T06:57:33-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 " Jan 09 06:57:33 volumio sudo[2209]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 09 06:57:33 volumio sudo[2209]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:33 volumio volumio[1776]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 09 06:57:33 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 09 06:57:33 volumio sudo[2209]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 09 06:57:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 09 06:57:33 volumio sudo[2200]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:33 volumio sudo[2198]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:33 volumio sudo[2203]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:33 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 09 06:57:33 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 09 06:57:33 volumio systemd[1]: mpd.service: Consumed 1.708s CPU time. Jan 09 06:57:33 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 09 06:57:33 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 09 06:57:33 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 09 06:57:33 volumio volumio[1776]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Jan 09 06:57:33 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 09 06:57:33 volumio sudo[2239]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Jan 09 06:57:33 volumio sudo[2239]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:33 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 09 06:57:33 volumio sudo[2239]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:33 volumio volumio[1776]: info: MPD Permissions set Jan 09 06:57:33 volumio volumio[1776]: info: Shairport-Sync Started Jan 09 06:57:33 volumio volumio[1776]: Error adding Membership: Error: addMembership EINVAL Jan 09 06:57:33 volumio volumio[1776]: info: Shairport-Sync Started Jan 09 06:57:33 volumio volumio[1776]: info: Shairport-Sync Started Jan 09 06:57:33 volumio volumio[1776]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Jan 09 06:57:34 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:34 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:34 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:34 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:34 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:34 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:34 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:34 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:34 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:57:34 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:34 volumio volumio[1776]: info: CoreCommandRouter::volumioGetState Jan 09 06:57:34 volumio volumio[1776]: info: CorePlayQueue::getTrack 0 Jan 09 06:57:34 volumio sudo[2245]: 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 Jan 09 06:57:34 volumio sudo[2245]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:34 volumio volumio[1776]: info: Starting Shairport Sync Jan 09 06:57:34 volumio sudo[2245]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:34 volumio sudo[2241]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 09 06:57:34 volumio sudo[2241]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 09 06:57:34 volumio sudo[2241]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:34 volumio volumio[1776]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Jan 09 06:57:34 volumio sudo[2253]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 09 06:57:34 volumio sudo[2253]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:34 volumio sudo[2258]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Jan 09 06:57:34 volumio sudo[2258]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:34 volumio volumio[1776]: 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"} Jan 09 06:57:34 volumio volumio[1776]: info: Spotify Successfully logged in Jan 09 06:57:34 volumio volumio[1776]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 09 06:57:34 volumio volumio[1776]: info: [1767963454251] CoreMusicLibrary::Adding element Spotify Jan 09 06:57:34 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 09 06:57:34 volumio volumio[1776]: Cannot find translation for source Bandcamp Discover Jan 09 06:57:34 volumio volumio[1776]: Cannot find translation for source SoundCloud Jan 09 06:57:34 volumio volumio[1776]: Cannot find translation for source YouTube2 Jan 09 06:57:34 volumio volumio[1776]: Cannot find translation for source YouTube Music Jan 09 06:57:34 volumio volumio[1776]: Cannot find translation for source Podcast Jan 09 06:57:34 volumio volumio[1776]: Cannot find translation for source Volusonic Jan 09 06:57:34 volumio volumio[1776]: Cannot find translation for source Spotify Jan 09 06:57:34 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 09 06:57:34 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 09 06:57:34 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 09 06:57:34 volumio systemd[1]: Reloading. Jan 09 06:57:35 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:35 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:35 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:57:35 volumio volumio[1776]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 09 06:57:35 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. Jan 09 06:57:35 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. Jan 09 06:57:36 volumio sudo[2258]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:36 volumio volumio[1776]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 09 06:57:36 volumio sudo[2299]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 09 06:57:36 volumio sudo[2299]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:36 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 09 06:57:36 volumio sudo[2253]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:36 volumio volumio[1776]: info: Shairport-Sync Started Jan 09 06:57:36 volumio volumio[1776]: info: go-librespot daemon successfully initialized Jan 09 06:57:36 volumio sudo[2299]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:36 volumio volumio[1776]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Jan 09 06:57:36 volumio sudo[2317]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Jan 09 06:57:36 volumio sudo[2317]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:36 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Jan 09 06:57:36 volumio systemd[1]: squeezelite.service: Deactivated successfully. Jan 09 06:57:36 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Jan 09 06:57:36 volumio sudo[2317]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 09 06:57:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:57:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:57:37 volumio go-librespot[2319]: go-librespot daemon starting... Jan 09 06:57:37 volumio go-librespot[2320]: time="2026-01-09T06:57:37-06:00" level=info msg="running go-librespot 0.4.0" Jan 09 06:57:37 volumio go-librespot[2320]: time="2026-01-09T06:57:37-06:00" level=debug msg="app state loaded" Jan 09 06:57:37 volumio go-librespot[2320]: time="2026-01-09T06:57:37-06:00" level=debug msg="stored credentials not found" Jan 09 06:57:37 volumio go-librespot[2320]: time="2026-01-09T06:57:37-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 09 06:57:37 volumio volumio[1776]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 09 06:57:37 volumio sudo[2327]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 09 06:57:37 volumio sudo[2327]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:37 volumio sudo[2327]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:37 volumio volumio[1776]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Jan 09 06:57:37 volumio go-librespot[2320]: time="2026-01-09T06:57:37-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]" Jan 09 06:57:37 volumio go-librespot[2320]: time="2026-01-09T06:57:37-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]" Jan 09 06:57:37 volumio go-librespot[2320]: time="2026-01-09T06:57:37-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]" Jan 09 06:57:37 volumio sudo[2332]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Jan 09 06:57:37 volumio sudo[2332]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:37 volumio go-librespot[2320]: time="2026-01-09T06:57:37-06:00" level=info msg="zeroconf server listening on port 33751" Jan 09 06:57:37 volumio sudo[2332]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:37 volumio volumio[1776]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Jan 09 06:57:37 volumio sudo[2335]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Jan 09 06:57:37 volumio sudo[2335]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:37 volumio go-librespot[2320]: time="2026-01-09T06:57:37-06:00" level=debug msg="obtained new client token: AABiTnKRF/XI58U/S1c2FYKuEIpimzrN7EMlLc/mM3T8u5Ts6+rMujY7J+lRfeq0vTz2e5B5sjXc6wIwxxyUD2Vo2GHliJYBuA9lQlfzL7wU53nS3XPjdotrcu91c840DkdAt9YL+wafjP6NWTHjfTzs5+w3IJFOTN1GkSmB0m10wlT3HWrGQnGiUwCfQKAQS0AJXbQ37SUGqFExAs2WAvhKVN/4jezb6MJ7pHBJk8LvUqvCmz/kiR2PeA==" Jan 09 06:57:37 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.157.133 Jan 09 06:57:37 volumio avahi-daemon[664]: Registering new address record for 169.254.157.133 on eth0.IPv4. Jan 09 06:57:37 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 09 06:57:37 volumio go-librespot[2320]: time="2026-01-09T06:57:37-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 09 06:57:37 volumio volumio[1776]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 09 06:57:37 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 09 06:57:37 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Jan 09 06:57:37 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Jan 09 06:57:37 volumio sudo[2335]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:37 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.157.133 Jan 09 06:57:37 volumio volumio[1776]: Error: addMembership ENODEV Jan 09 06:57:37 volumio volumio[1776]: at Socket.addMembership (node:dgram:860:11) Jan 09 06:57:37 volumio volumio[1776]: at addMembership (/volumio/node_modules/node-ssdp/lib/index.js:264:16) { Jan 09 06:57:37 volumio volumio[1776]: errno: -19, Jan 09 06:57:37 volumio volumio[1776]: code: 'ENODEV', Jan 09 06:57:37 volumio volumio[1776]: syscall: 'addMembership' Jan 09 06:57:37 volumio volumio[1776]: } Jan 09 06:57:37 volumio volumio[1776]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 09 06:57:37 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:37 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 09 06:57:37 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:37 volumio go-librespot[2320]: time="2026-01-09T06:57:37-06:00" level=debug msg="completed keyexchange" Jan 09 06:57:37 volumio go-librespot[2320]: time="2026-01-09T06:57:37-06:00" level=debug msg="completed challenge" Jan 09 06:57:37 volumio go-librespot[2320]: time="2026-01-09T06:57:37-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 " Jan 09 06:57:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 09 06:57:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 09 06:57:37 volumio mpd[2257]: 2026-01-09T06:57:37 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 09 06:57:38 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.157.133 Jan 09 06:57:38 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.157.133 Jan 09 06:57:38 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 09 06:57:38 volumio avahi-daemon[664]: Withdrawing address record for 169.254.157.133 on eth0. Jan 09 06:57:38 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 09 06:57:38 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 09 06:57:38 volumio sudo[2104]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:38 volumio sudo[2114]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:38 volumio sudo[2211]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:38 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:38 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 09 06:57:38 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:39 volumio sudo[2390]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-09 06:56' Jan 09 06:57:39 volumio sudo[2390]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:39 volumio sudo[2390]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:40 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 09 06:57:40 volumio volumio-remote-updater[14193]: [2026-01-09 06:57:40] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 09 06:57:40 volumio volumio-remote-updater[14193]: [2026-01-09 06:57:40] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 09 06:57:40 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 09 06:57:40 volumio systemd[1]: volumio.service: Consumed 46.119s CPU time. Jan 09 06:57:40 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 09 06:57:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 09 06:57:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:57:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:57:40 volumio go-librespot[2403]: go-librespot daemon starting... Jan 09 06:57:40 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 09 06:57:40 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 16165. Jan 09 06:57:40 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 09 06:57:40 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 09 06:57:40 volumio systemd[1]: volumio.service: Consumed 46.119s CPU time. Jan 09 06:57:40 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 09 06:57:40 volumio go-librespot[2406]: time="2026-01-09T06:57:40-06:00" level=info msg="running go-librespot 0.4.0" Jan 09 06:57:40 volumio go-librespot[2406]: time="2026-01-09T06:57:40-06:00" level=debug msg="app state loaded" Jan 09 06:57:40 volumio go-librespot[2406]: time="2026-01-09T06:57:40-06:00" level=debug msg="stored credentials not found" Jan 09 06:57:40 volumio go-librespot[2406]: time="2026-01-09T06:57:40-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 09 06:57:40 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 09 06:57:41 volumio go-librespot[2406]: time="2026-01-09T06:57:41-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]" Jan 09 06:57:41 volumio go-librespot[2406]: time="2026-01-09T06:57:41-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]" Jan 09 06:57:41 volumio go-librespot[2406]: time="2026-01-09T06:57:41-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]" Jan 09 06:57:41 volumio go-librespot[2406]: time="2026-01-09T06:57:41-06:00" level=info msg="zeroconf server listening on port 46819" Jan 09 06:57:41 volumio go-librespot[2406]: time="2026-01-09T06:57:41-06:00" level=debug msg="obtained new client token: AAC856HRKkwTHCht6K23iE+RAk7akmUzHO5Ahz5VFIplxaE6oguI9h6EHLyp2T756uWYLcYbwCtDWlolnhkI7nFVBg3NG3AxNc1Bwi8UtmorY32/vpSbaVgoc5XbitpeKtLsvIBDf0ZX6o5AgLkYTShk0UVROBlWoY+Y3oEpdyXE3cmBXdr/nvprHLnceL+Gcv0csmLPtdaH3E6kqaXXIo+wSfh4PZxECG9T+EWKQd+jz8cH54yj7yc=" Jan 09 06:57:41 volumio go-librespot[2406]: time="2026-01-09T06:57:41-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 09 06:57:41 volumio go-librespot[2406]: time="2026-01-09T06:57:41-06:00" level=debug msg="completed keyexchange" Jan 09 06:57:41 volumio go-librespot[2406]: time="2026-01-09T06:57:41-06:00" level=debug msg="completed challenge" Jan 09 06:57:41 volumio go-librespot[2406]: time="2026-01-09T06:57:41-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 " Jan 09 06:57:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 09 06:57:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 09 06:57:42 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.194.13 Jan 09 06:57:42 volumio avahi-daemon[664]: Registering new address record for 169.254.194.13 on eth0.IPv4. Jan 09 06:57:42 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 09 06:57:42 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:42 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 09 06:57:42 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:42 volumio volumio[2413]: info: ------------------------------------------- Jan 09 06:57:42 volumio volumio[2413]: info: ----- Volumio3 ---- Jan 09 06:57:42 volumio volumio[2413]: info: ------------------------------------------- Jan 09 06:57:42 volumio volumio[2413]: info: ----- System startup ---- Jan 09 06:57:42 volumio volumio[2413]: info: ------------------------------------------- Jan 09 06:57:43 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.194.13 Jan 09 06:57:43 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.194.13 Jan 09 06:57:43 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.194.13 Jan 09 06:57:43 volumio avahi-daemon[664]: Withdrawing address record for 169.254.194.13 on eth0. Jan 09 06:57:43 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 09 06:57:43 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 09 06:57:43 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:43 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 09 06:57:43 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:43 volumio volumio[2413]: info: MYVOLUMIO Environment detected Jan 09 06:57:43 volumio volumio[2413]: info: Plugin folders cleanup Jan 09 06:57:43 volumio volumio[2413]: info: Scanning into folder /volumio/app/plugins/ Jan 09 06:57:43 volumio volumio[2413]: info: Scanning category audio_interface Jan 09 06:57:43 volumio volumio[2413]: info: Scanning category miscellanea Jan 09 06:57:43 volumio volumio[2413]: info: Scanning category music_service Jan 09 06:57:43 volumio volumio[2413]: info: Scanning category plugins.json Jan 09 06:57:43 volumio volumio[2413]: info: Scanning category system_controller Jan 09 06:57:43 volumio volumio[2413]: info: Scanning category user_interface Jan 09 06:57:43 volumio volumio[2413]: info: Scanning into folder /data/plugins/ Jan 09 06:57:43 volumio volumio[2413]: info: Scanning category audio_interface Jan 09 06:57:43 volumio volumio[2413]: info: Scanning category music_service Jan 09 06:57:43 volumio volumio[2413]: info: Scanning category system_controller Jan 09 06:57:43 volumio volumio[2413]: info: Scanning category system_hardware Jan 09 06:57:43 volumio volumio[2413]: info: Scanning category user_interface Jan 09 06:57:43 volumio volumio[2413]: info: Plugin folders cleanup completed Jan 09 06:57:43 volumio volumio[2413]: info: ------------------------------------------- Jan 09 06:57:43 volumio volumio[2413]: info: ----- Core plugins startup ---- Jan 09 06:57:43 volumio volumio[2413]: info: ------------------------------------------- Jan 09 06:57:43 volumio volumio[2413]: info: Loading plugins from folder /volumio/app/plugins/ Jan 09 06:57:43 volumio volumio[2413]: info: Adding plugin upnp to MyMusic Plugins Jan 09 06:57:43 volumio volumio[2413]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 09 06:57:43 volumio volumio[2413]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 09 06:57:43 volumio volumio[2413]: info: Loading plugins from folder /data/plugins/ Jan 09 06:57:43 volumio volumio[2413]: info: Loading plugin "system"... Jan 09 06:57:43 volumio kernel: hwmon hwmon1: Voltage normalised Jan 09 06:57:43 volumio volumio[2413]: info: Loading plugin "appearance"... Jan 09 06:57:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 09 06:57:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:57:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:57:44 volumio go-librespot[2474]: go-librespot daemon starting... Jan 09 06:57:44 volumio go-librespot[2475]: time="2026-01-09T06:57:44-06:00" level=info msg="running go-librespot 0.4.0" Jan 09 06:57:44 volumio go-librespot[2475]: time="2026-01-09T06:57:44-06:00" level=debug msg="app state loaded" Jan 09 06:57:44 volumio go-librespot[2475]: time="2026-01-09T06:57:44-06:00" level=debug msg="stored credentials not found" Jan 09 06:57:44 volumio go-librespot[2475]: time="2026-01-09T06:57:44-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 09 06:57:44 volumio go-librespot[2475]: time="2026-01-09T06:57: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]" Jan 09 06:57:44 volumio go-librespot[2475]: time="2026-01-09T06:57: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]" Jan 09 06:57:44 volumio go-librespot[2475]: time="2026-01-09T06:57: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]" Jan 09 06:57:44 volumio go-librespot[2475]: time="2026-01-09T06:57:44-06:00" level=info msg="zeroconf server listening on port 34531" Jan 09 06:57:44 volumio go-librespot[2475]: time="2026-01-09T06:57:44-06:00" level=debug msg="obtained new client token: AACuZv7XfxkzMn5VAv+BhkLPM4w19E/qp72/e74Zsod4pjRROyGW/ggUKpGSdrEPeGBvKPFXQUmaPSSthpbZJRFX8yVCnT/vLSl1s/QuwmnmsmOzJDIdh+98rAiTPUKhPQPtKL/Mu/s6cOkWhcknkbruAQf1ANx/f7Y6DBDjrbR53wJClTH62+QXJVOzrvyzxmH7OuNP7ZRGIiBNhrvxLZlKcms4otkIP3/HJ4R0OvrnWX6I1SDGIelNJg==" Jan 09 06:57:44 volumio go-librespot[2475]: time="2026-01-09T06:57:44-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 09 06:57:44 volumio volumio[2413]: info: Loading plugin "network"... Jan 09 06:57:44 volumio volumio[2413]: info: Refreshing Cached IP Addresses Jan 09 06:57:45 volumio go-librespot[2475]: time="2026-01-09T06:57:45-06:00" level=debug msg="completed keyexchange" Jan 09 06:57:45 volumio sudo[2484]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 09 06:57:45 volumio sudo[2484]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:45 volumio go-librespot[2475]: time="2026-01-09T06:57:45-06:00" level=debug msg="completed challenge" Jan 09 06:57:45 volumio sudo[2484]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:45 volumio sudo[2486]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 09 06:57:45 volumio sudo[2486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:45 volumio sudo[2486]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:45 volumio volumio[2413]: info: Loading plugin "services"... Jan 09 06:57:45 volumio volumio[2413]: info: Loading plugin "alsa_controller"... Jan 09 06:57:45 volumio go-librespot[2475]: time="2026-01-09T06:57: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 " Jan 09 06:57:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 09 06:57:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 09 06:57:45 volumio sudo[2495]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 09 06:57:45 volumio sudo[2495]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:45 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 09 06:57:45 volumio volumio[2413]: info: Loading plugin "wizard"... Jan 09 06:57:45 volumio volumio[2413]: info: Loading plugin "networkfs"... Jan 09 06:57:45 volumio volumio[2413]: info: Starting Udev Watcher for removable devices Jan 09 06:57:45 volumio volumio[2413]: info: Ignoring mount for partition: boot Jan 09 06:57:45 volumio volumio[2413]: info: Ignoring mount for partition: volumio Jan 09 06:57:45 volumio volumio[2413]: info: Ignoring mount for partition: volumio_data Jan 09 06:57:45 volumio volumio[2413]: info: Mounting Device Wikipedia Jan 09 06:57:45 volumio sudo[2524]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Jan 09 06:57:45 volumio sudo[2524]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:57:45 volumio sudo[2524]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:45 volumio volumio[2413]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Jan 09 06:57:45 volumio volumio[2413]: dmesg(1) may have more information after failed mount system call. Jan 09 06:57:45 volumio volumio[2413]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Jan 09 06:57:45 volumio volumio[2413]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Jan 09 06:57:45 volumio volumio[2413]: dmesg(1) may have more information after failed mount system call. Jan 09 06:57:45 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 09 06:57:45 volumio volumio[2413]: info: Loading plugin "volumio_command_line_client"... Jan 09 06:57:45 volumio volumio[2413]: info: Loading plugin "upnp"... Jan 09 06:57:45 volumio volumio[2413]: info: [1767963465432] Starting Upmpd Daemon Jan 09 06:57:45 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 09 06:57:45 volumio volumio[2413]: info: Loading plugin "my_music"... Jan 09 06:57:45 volumio volumio[2413]: info: Loading plugin "mpd"... Jan 09 06:57:45 volumio sudo[2495]: pam_unix(sudo:session): session closed for user root Jan 09 06:57:45 volumio volumio-remote-updater[14193]: [2026-01-09 06:57:45] [connect] Successful connection Jan 09 06:57:45 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 09 06:57:46 volumio volumio[2413]: info: Loading plugin "upnp_browser"... Jan 09 06:57:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 09 06:57:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:57:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:57:48 volumio go-librespot[2529]: go-librespot daemon starting... Jan 09 06:57:48 volumio go-librespot[2530]: time="2026-01-09T06:57:48-06:00" level=info msg="running go-librespot 0.4.0" Jan 09 06:57:48 volumio go-librespot[2530]: time="2026-01-09T06:57:48-06:00" level=debug msg="app state loaded" Jan 09 06:57:48 volumio go-librespot[2530]: time="2026-01-09T06:57:48-06:00" level=debug msg="stored credentials not found" Jan 09 06:57:48 volumio go-librespot[2530]: time="2026-01-09T06:57:48-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 09 06:57:48 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.96.82 Jan 09 06:57:48 volumio avahi-daemon[664]: Registering new address record for 169.254.96.82 on eth0.IPv4. Jan 09 06:57:48 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 09 06:57:48 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:48 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.96.82 Jan 09 06:57:48 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 09 06:57:48 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:48 volumio go-librespot[2530]: time="2026-01-09T06:57: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-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 09 06:57:48 volumio go-librespot[2530]: time="2026-01-09T06:57:48-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]" Jan 09 06:57:48 volumio go-librespot[2530]: time="2026-01-09T06:57:48-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]" Jan 09 06:57:48 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.96.82 Jan 09 06:57:48 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.96.82 Jan 09 06:57:48 volumio avahi-daemon[664]: Withdrawing address record for 169.254.96.82 on eth0. Jan 09 06:57:48 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 09 06:57:48 volumio go-librespot[2530]: time="2026-01-09T06:57:48-06:00" level=info msg="zeroconf server listening on port 37431" Jan 09 06:57:48 volumio volumio[2413]: info: Loading plugin "alarm-clock"... Jan 09 06:57:48 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:48 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 09 06:57:48 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:48 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 09 06:57:48 volumio go-librespot[2530]: time="2026-01-09T06:57:48-06:00" level=debug msg="obtained new client token: AAA6letSVYySD/8x0oq9xA15+nMGj9pEr1Mdp+R+XcdDZ2TMYIpjLafBQXJQN60WZBYcVzVnJaGGzOrqsrzw4rphBTQCjs7Uz/ZnlBnswRMZcfdXHe0axrsGANKO8xN6wtuI1Jy8GMBr9UD7HYOo2PBr02NWiIqd8IFqpcqyAVIECCh8eFJfG0RrJO0agoj9YHSE6K/lCFou0KgFHaHjq+0hnQ5KJXnYVAEiixwETCYtHPej6N28dsfEfA==" Jan 09 06:57:48 volumio go-librespot[2530]: time="2026-01-09T06:57:48-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 09 06:57:48 volumio volumio[2413]: info: Loading plugin "airplay_emulation"... Jan 09 06:57:48 volumio go-librespot[2530]: time="2026-01-09T06:57:48-06:00" level=debug msg="completed keyexchange" Jan 09 06:57:48 volumio go-librespot[2530]: time="2026-01-09T06:57:48-06:00" level=debug msg="completed challenge" Jan 09 06:57:48 volumio volumio[2413]: info: Starting Shairport Sync Jan 09 06:57:48 volumio volumio[2413]: info: Loading plugin "last_100"... Jan 09 06:57:48 volumio volumio[2413]: info: Loading plugin "webradio"... Jan 09 06:57:48 volumio go-librespot[2530]: time="2026-01-09T06:57:48-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 " Jan 09 06:57:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 09 06:57:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 09 06:57:49 volumio volumio[2413]: info: Loading plugin "i2s_dacs"... Jan 09 06:57:49 volumio volumio[2413]: info: I2S DAC not set, start Auto-detection Jan 09 06:57:49 volumio volumio[2413]: info: Loading plugin "volumiodiscovery"... Jan 09 06:57:49 volumio volumio[2413]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 09 06:57:49 volumio volumio[2413]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 09 06:57:49 volumio volumio[2413]: *** WARNING *** For more information see Jan 09 06:57:49 volumio volumio[2413]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 09 06:57:49 volumio volumio[2413]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 09 06:57:49 volumio volumio[2413]: *** WARNING *** For more information see Jan 09 06:57:49 volumio node[2413]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 09 06:57:49 volumio node[2413]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 09 06:57:49 volumio node[2413]: *** WARNING *** For more information see Jan 09 06:57:49 volumio node[2413]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 09 06:57:49 volumio node[2413]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 09 06:57:49 volumio node[2413]: *** WARNING *** For more information see Jan 09 06:57:49 volumio volumio[2413]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 09 06:57:49 volumio volumio[2413]: info: Discovery: Started advertising with name: Volumio Jan 09 06:57:49 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 09 06:57:49 volumio volumio[2413]: info: Loading plugin "bandcamp"... Jan 09 06:57:50 volumio volumio[2413]: info: Plugin calmradio is not enabled Jan 09 06:57:50 volumio volumio[2413]: info: Loading plugin "soundcloud"... Jan 09 06:57:50 volumio volumio[2413]: info: Loading plugin "spop"... Jan 09 06:57:51 volumio volumio[2413]: info: Loading plugin "squeezelite_mc"... Jan 09 06:57:52 volumio kernel: hwmon hwmon1: Voltage normalised Jan 09 06:57:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 09 06:57:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:57:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:57:52 volumio go-librespot[2573]: go-librespot daemon starting... Jan 09 06:57:52 volumio go-librespot[2574]: time="2026-01-09T06:57:52-06:00" level=info msg="running go-librespot 0.4.0" Jan 09 06:57:52 volumio go-librespot[2574]: time="2026-01-09T06:57:52-06:00" level=debug msg="app state loaded" Jan 09 06:57:52 volumio go-librespot[2574]: time="2026-01-09T06:57:52-06:00" level=debug msg="stored credentials not found" Jan 09 06:57:52 volumio go-librespot[2574]: time="2026-01-09T06:57:52-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 09 06:57:52 volumio volumio[2413]: info: Loading plugin "youtube2"... Jan 09 06:57:52 volumio go-librespot[2574]: time="2026-01-09T06:57: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-gew1.spotify.com:80]" Jan 09 06:57:52 volumio go-librespot[2574]: time="2026-01-09T06:57:52-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]" Jan 09 06:57:52 volumio go-librespot[2574]: time="2026-01-09T06:57:52-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]" Jan 09 06:57:52 volumio go-librespot[2574]: time="2026-01-09T06:57:52-06:00" level=info msg="zeroconf server listening on port 36391" Jan 09 06:57:52 volumio go-librespot[2574]: time="2026-01-09T06:57:52-06:00" level=debug msg="obtained new client token: AAD2G5jtAF4iFhUQmsR8ODXZCE3EN6VwS75bOjuyyGPS3aiBcxs4EQrWeWv6eQbnq4vGnMn1tI00a+NmdsRGS3obfcW5kL799MBF27ZEWAiqMbfyHBYP8ENOipauMq7NFqYJ/WJriM1ld79zjAu6SsTA6X9bRx2QGWiKbknXmHQYrzZs2qvV78UMMduhHStkLWA5hj3sO9TdpihzDnq3pyaYmM6mMibMtDEkD0QEb+oeZA/TTwy9aIK4EQ==" Jan 09 06:57:52 volumio go-librespot[2574]: time="2026-01-09T06:57:52-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 09 06:57:53 volumio volumio[2413]: info: Loading plugin "ytcr"... Jan 09 06:57:53 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.251.154 Jan 09 06:57:53 volumio avahi-daemon[664]: Registering new address record for 169.254.251.154 on eth0.IPv4. Jan 09 06:57:53 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 09 06:57:53 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:53 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 09 06:57:53 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:54 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.251.154 Jan 09 06:57:54 volumio go-librespot[2574]: time="2026-01-09T06:57:54-06:00" level=debug msg="completed keyexchange" Jan 09 06:57:54 volumio go-librespot[2574]: time="2026-01-09T06:57:54-06:00" level=debug msg="completed challenge" Jan 09 06:57:54 volumio go-librespot[2574]: time="2026-01-09T06:57:54-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 " Jan 09 06:57:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 09 06:57:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 09 06:57:54 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 09 06:57:54 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.251.154 Jan 09 06:57:54 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.251.154 Jan 09 06:57:54 volumio avahi-daemon[664]: Withdrawing address record for 169.254.251.154 on eth0. Jan 09 06:57:54 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 09 06:57:54 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:54 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 09 06:57:54 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:54 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 09 06:57:55 volumio volumio[2413]: info: Loading plugin "ytmusic"... Jan 09 06:57:56 volumio nmbd[1048]: [2026/01/09 06:57:56.364869, 0] ../../source3/libsmb/nmblib.c:923(send_udp) Jan 09 06:57:56 volumio nmbd[1048]: Packet send failed to 169.254.255.255(137) ERRNO=Network is unreachable Jan 09 06:57:56 volumio nmbd[1048]: [2026/01/09 06:57:56.365126, 0] ../../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Jan 09 06:57:56 volumio nmbd[1048]: retransmit_or_expire_response_records: Failed to resend packet id 9047 to IP 169.254.255.255 on subnet 169.254.251.154 Jan 09 06:57:56 volumio nmbd[1048]: [2026/01/09 06:57:56.365223, 0] ../../source3/libsmb/nmblib.c:923(send_udp) Jan 09 06:57:56 volumio nmbd[1048]: Packet send failed to 169.254.255.255(137) ERRNO=Network is unreachable Jan 09 06:57:56 volumio nmbd[1048]: [2026/01/09 06:57:56.365304, 0] ../../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Jan 09 06:57:56 volumio nmbd[1048]: retransmit_or_expire_response_records: Failed to resend packet id 9048 to IP 169.254.255.255 on subnet 169.254.251.154 Jan 09 06:57:56 volumio nmbd[1048]: [2026/01/09 06:57:56.365412, 0] ../../source3/libsmb/nmblib.c:923(send_udp) Jan 09 06:57:56 volumio nmbd[1048]: Packet send failed to 169.254.255.255(137) ERRNO=Network is unreachable Jan 09 06:57:56 volumio nmbd[1048]: [2026/01/09 06:57:56.365485, 0] ../../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Jan 09 06:57:56 volumio nmbd[1048]: retransmit_or_expire_response_records: Failed to resend packet id 9049 to IP 169.254.255.255 on subnet 169.254.251.154 Jan 09 06:57:56 volumio nmbd[1048]: [2026/01/09 06:57:56.365560, 0] ../../source3/libsmb/nmblib.c:923(send_udp) Jan 09 06:57:56 volumio nmbd[1048]: Packet send failed to 169.254.255.255(137) ERRNO=Network is unreachable Jan 09 06:57:56 volumio nmbd[1048]: [2026/01/09 06:57:56.365631, 0] ../../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Jan 09 06:57:56 volumio nmbd[1048]: retransmit_or_expire_response_records: Failed to resend packet id 9050 to IP 169.254.255.255 on subnet 169.254.251.154 Jan 09 06:57:56 volumio nmbd[1048]: [2026/01/09 06:57:56.365705, 0] ../../source3/libsmb/nmblib.c:923(send_udp) Jan 09 06:57:56 volumio nmbd[1048]: Packet send failed to 169.254.255.255(137) ERRNO=Network is unreachable Jan 09 06:57:56 volumio nmbd[1048]: [2026/01/09 06:57:56.365776, 0] ../../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Jan 09 06:57:56 volumio nmbd[1048]: retransmit_or_expire_response_records: Failed to resend packet id 9051 to IP 169.254.255.255 on subnet 169.254.251.154 Jan 09 06:57:56 volumio volumio[2413]: info: Plugin now_playing is not enabled Jan 09 06:57:56 volumio volumio[2413]: info: Loading plugin "outputs"... Jan 09 06:57:56 volumio volumio[2413]: info: Loading plugin "albumart"... Jan 09 06:57:56 volumio volumio[2413]: info: Plugin example_plugin is not enabled Jan 09 06:57:56 volumio volumio[2413]: info: Loading plugin "inputs"... Jan 09 06:57:56 volumio volumio[2413]: info: Loading plugin "updater_comm"... Jan 09 06:57:56 volumio volumio[2413]: info: Plugin mpdemulation is not enabled Jan 09 06:57:56 volumio volumio[2413]: info: Loading plugin "rest_api"... Jan 09 06:57:56 volumio volumio[2413]: info: Loading plugin "websocket"... Jan 09 06:57:56 volumio volumio[2413]: info: Starting Socket.io Server version 1.7.4 Jan 09 06:57:56 volumio volumio[2413]: info: Plugin fusiondsp is not enabled Jan 09 06:57:56 volumio volumio[2413]: info: Plugin mpdoutput is not enabled Jan 09 06:57:56 volumio volumio[2413]: info: Plugin RoonBridge is not enabled Jan 09 06:57:56 volumio volumio[2413]: info: Loading plugin "podcast"... Jan 09 06:57:56 volumio volumio[2413]: info: ControllerPodcast::constructor Jan 09 06:57:56 volumio volumio[2413]: info: Loading plugin "volusonic"... Jan 09 06:57:57 volumio volumio[2628]: Forking 3 albumart workers Jan 09 06:57:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 09 06:57:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:57:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:57:57 volumio go-librespot[2667]: go-librespot daemon starting... Jan 09 06:57:57 volumio go-librespot[2669]: time="2026-01-09T06:57:57-06:00" level=info msg="running go-librespot 0.4.0" Jan 09 06:57:57 volumio go-librespot[2669]: time="2026-01-09T06:57:57-06:00" level=debug msg="app state loaded" Jan 09 06:57:57 volumio go-librespot[2669]: time="2026-01-09T06:57:57-06:00" level=debug msg="stored credentials not found" Jan 09 06:57:57 volumio go-librespot[2669]: time="2026-01-09T06:57:57-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 09 06:57:57 volumio nmbd[1048]: [2026/01/09 06:57:57.367260, 0] ../../source3/libsmb/nmblib.c:923(send_udp) Jan 09 06:57:57 volumio nmbd[1048]: Packet send failed to 169.254.255.255(137) ERRNO=Network is unreachable Jan 09 06:57:57 volumio nmbd[1048]: [2026/01/09 06:57:57.367580, 0] ../../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Jan 09 06:57:57 volumio nmbd[1048]: retransmit_or_expire_response_records: Failed to resend packet id 9047 to IP 169.254.255.255 on subnet 169.254.251.154 Jan 09 06:57:57 volumio nmbd[1048]: [2026/01/09 06:57:57.367974, 0] ../../source3/libsmb/nmblib.c:923(send_udp) Jan 09 06:57:57 volumio nmbd[1048]: Packet send failed to 169.254.255.255(137) ERRNO=Network is unreachable Jan 09 06:57:57 volumio nmbd[1048]: [2026/01/09 06:57:57.368323, 0] ../../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Jan 09 06:57:57 volumio nmbd[1048]: retransmit_or_expire_response_records: Failed to resend packet id 9048 to IP 169.254.255.255 on subnet 169.254.251.154 Jan 09 06:57:57 volumio nmbd[1048]: [2026/01/09 06:57:57.368434, 0] ../../source3/libsmb/nmblib.c:923(send_udp) Jan 09 06:57:57 volumio nmbd[1048]: Packet send failed to 169.254.255.255(137) ERRNO=Network is unreachable Jan 09 06:57:57 volumio nmbd[1048]: [2026/01/09 06:57:57.368521, 0] ../../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Jan 09 06:57:57 volumio nmbd[1048]: retransmit_or_expire_response_records: Failed to resend packet id 9049 to IP 169.254.255.255 on subnet 169.254.251.154 Jan 09 06:57:57 volumio nmbd[1048]: [2026/01/09 06:57:57.368595, 0] ../../source3/libsmb/nmblib.c:923(send_udp) Jan 09 06:57:57 volumio nmbd[1048]: Packet send failed to 169.254.255.255(137) ERRNO=Network is unreachable Jan 09 06:57:57 volumio nmbd[1048]: [2026/01/09 06:57:57.368666, 0] ../../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Jan 09 06:57:57 volumio nmbd[1048]: retransmit_or_expire_response_records: Failed to resend packet id 9050 to IP 169.254.255.255 on subnet 169.254.251.154 Jan 09 06:57:57 volumio nmbd[1048]: [2026/01/09 06:57:57.368739, 0] ../../source3/libsmb/nmblib.c:923(send_udp) Jan 09 06:57:57 volumio nmbd[1048]: Packet send failed to 169.254.255.255(137) ERRNO=Network is unreachable Jan 09 06:57:57 volumio nmbd[1048]: [2026/01/09 06:57:57.368809, 0] ../../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Jan 09 06:57:57 volumio nmbd[1048]: retransmit_or_expire_response_records: Failed to resend packet id 9051 to IP 169.254.255.255 on subnet 169.254.251.154 Jan 09 06:57:57 volumio go-librespot[2669]: time="2026-01-09T06:57:57-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]" Jan 09 06:57:57 volumio go-librespot[2669]: time="2026-01-09T06:57:57-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]" Jan 09 06:57:57 volumio go-librespot[2669]: time="2026-01-09T06:57:57-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]" Jan 09 06:57:57 volumio go-librespot[2669]: time="2026-01-09T06:57:57-06:00" level=info msg="zeroconf server listening on port 35739" Jan 09 06:57:58 volumio go-librespot[2669]: time="2026-01-09T06:57:58-06:00" level=debug msg="obtained new client token: AACK2dbMGI2cw1xWPlqY2Ogslvej7Pg+NOgGL8Tq4UaxQc4gnXMYgOzRivclpOKQ0iHNkE98Gv4FtqTEdH2D8a7OLB0qEKjNvX0kV0NDp7ZDFwUMpI5VoQA0vjurR34muULFXIKDLUi7AGCvqB9hDmILWb7xfWxZeQgbAskZYBKtDynB7gM0Dq8OWydtblwizNbKEWQeJ+Y4rrivcggEtHoBb9Qpxo9SJMEFe6DzFKxqrafn35emScM=" Jan 09 06:57:58 volumio go-librespot[2669]: time="2026-01-09T06:57:58-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 09 06:57:58 volumio go-librespot[2669]: time="2026-01-09T06:57:58-06:00" level=debug msg="completed keyexchange" Jan 09 06:57:58 volumio go-librespot[2669]: time="2026-01-09T06:57:58-06:00" level=debug msg="completed challenge" Jan 09 06:57:58 volumio volumio-remote-updater[14193]: [2026-01-09 06:57:58] [connect] Successful connection Jan 09 06:57:58 volumio go-librespot[2669]: time="2026-01-09T06:57:58-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 " Jan 09 06:57:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 09 06:57:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 09 06:57:58 volumio nmbd[1048]: [2026/01/09 06:57:58.369628, 0] ../../source3/libsmb/nmblib.c:923(send_udp) Jan 09 06:57:58 volumio nmbd[1048]: Packet send failed to 169.254.255.255(137) ERRNO=Network is unreachable Jan 09 06:57:58 volumio nmbd[1048]: [2026/01/09 06:57:58.370023, 0] ../../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Jan 09 06:57:58 volumio nmbd[1048]: retransmit_or_expire_response_records: Failed to resend packet id 9047 to IP 169.254.255.255 on subnet 169.254.251.154 Jan 09 06:57:58 volumio nmbd[1048]: [2026/01/09 06:57:58.370255, 0] ../../source3/libsmb/nmblib.c:923(send_udp) Jan 09 06:57:58 volumio nmbd[1048]: Packet send failed to 169.254.255.255(137) ERRNO=Network is unreachable Jan 09 06:57:58 volumio nmbd[1048]: [2026/01/09 06:57:58.370429, 0] ../../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Jan 09 06:57:58 volumio nmbd[1048]: retransmit_or_expire_response_records: Failed to resend packet id 9048 to IP 169.254.255.255 on subnet 169.254.251.154 Jan 09 06:57:58 volumio nmbd[1048]: [2026/01/09 06:57:58.370579, 0] ../../source3/libsmb/nmblib.c:923(send_udp) Jan 09 06:57:58 volumio nmbd[1048]: Packet send failed to 169.254.255.255(137) ERRNO=Network is unreachable Jan 09 06:57:58 volumio nmbd[1048]: [2026/01/09 06:57:58.370769, 0] ../../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Jan 09 06:57:58 volumio nmbd[1048]: retransmit_or_expire_response_records: Failed to resend packet id 9049 to IP 169.254.255.255 on subnet 169.254.251.154 Jan 09 06:57:58 volumio nmbd[1048]: [2026/01/09 06:57:58.370932, 0] ../../source3/libsmb/nmblib.c:923(send_udp) Jan 09 06:57:58 volumio nmbd[1048]: Packet send failed to 169.254.255.255(137) ERRNO=Network is unreachable Jan 09 06:57:58 volumio nmbd[1048]: [2026/01/09 06:57:58.371082, 0] ../../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Jan 09 06:57:58 volumio nmbd[1048]: retransmit_or_expire_response_records: Failed to resend packet id 9050 to IP 169.254.255.255 on subnet 169.254.251.154 Jan 09 06:57:58 volumio nmbd[1048]: [2026/01/09 06:57:58.371246, 0] ../../source3/libsmb/nmblib.c:923(send_udp) Jan 09 06:57:58 volumio nmbd[1048]: Packet send failed to 169.254.255.255(137) ERRNO=Network is unreachable Jan 09 06:57:58 volumio nmbd[1048]: [2026/01/09 06:57:58.371389, 0] ../../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Jan 09 06:57:58 volumio nmbd[1048]: retransmit_or_expire_response_records: Failed to resend packet id 9051 to IP 169.254.255.255 on subnet 169.254.251.154 Jan 09 06:57:59 volumio volumio[2413]: info: Applying required configuration parameters for plugin volusonic Jan 09 06:57:59 volumio volumio[2413]: info: Loading plugin "backup_restore"... Jan 09 06:57:59 volumio volumio[2640]: Starting albumart workers Jan 09 06:57:59 volumio volumio[2638]: Starting albumart workers Jan 09 06:57:59 volumio volumio[2413]: info: Applying required configuration parameters for plugin backup_restore Jan 09 06:57:59 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.248.157 Jan 09 06:57:59 volumio avahi-daemon[664]: Registering new address record for 169.254.248.157 on eth0.IPv4. Jan 09 06:57:59 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 09 06:57:59 volumio volumio[2413]: info: Plugin rpi_eeprom_config is not enabled Jan 09 06:57:59 volumio volumio[2413]: info: Plugin rpi_eeprom_updater is not enabled Jan 09 06:57:59 volumio volumio[2413]: info: Loading plugin "scheduledrestart"... Jan 09 06:57:59 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:57:59 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 09 06:57:59 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:58:00 volumio volumio[2639]: Starting albumart workers Jan 09 06:58:00 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.248.157 Jan 09 06:58:00 volumio volumio[2413]: info: Applying required configuration parameters for plugin scheduledrestart Jan 09 06:58:00 volumio volumio[2413]: info: Plugin Bluetoothremote is not enabled Jan 09 06:58:00 volumio volumio[2413]: info: Plugin music_services_shield is not enabled Jan 09 06:58:00 volumio volumio[2413]: info: Loading plugin "Systeminfo"... Jan 09 06:58:00 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.248.157 Jan 09 06:58:00 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.248.157 Jan 09 06:58:00 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 09 06:58:00 volumio avahi-daemon[664]: Withdrawing address record for 169.254.248.157 on eth0. Jan 09 06:58:00 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 09 06:58:00 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:58:00 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 09 06:58:00 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:58:00 volumio volumio[2413]: info: Plugin peppymeterbasic is not enabled Jan 09 06:58:00 volumio volumio[2413]: info: Loading plugin "peppyspectrum"... Jan 09 06:58:01 volumio volumio[2413]: info: Loading i18n strings for locale en Jan 09 06:58:01 volumio volumio[2413]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 09 06:58:01 volumio volumio[2413]: Updating browse sources language Jan 09 06:58:01 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 09 06:58:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 09 06:58:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:58:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:58:01 volumio go-librespot[2728]: go-librespot daemon starting... Jan 09 06:58:01 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 09 06:58:01 volumio volumio[2413]: info: CoreCommandRouter::initPlayerControls Jan 09 06:58:01 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:01 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:01 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:01 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:01 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:01 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:01 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:01 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:01 volumio go-librespot[2729]: time="2026-01-09T06:58:01-06:00" level=info msg="running go-librespot 0.4.0" Jan 09 06:58:01 volumio go-librespot[2729]: time="2026-01-09T06:58:01-06:00" level=debug msg="app state loaded" Jan 09 06:58:01 volumio go-librespot[2729]: time="2026-01-09T06:58:01-06:00" level=debug msg="stored credentials not found" Jan 09 06:58:01 volumio go-librespot[2729]: time="2026-01-09T06:58:01-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 09 06:58:01 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 09 06:58:01 volumio volumio[2413]: Express server listening on port 3000 Jan 09 06:58:01 volumio volumio[2413]: [Metrics] WebUI: 19s 163.52ms Jan 09 06:58:01 volumio volumio[2413]: info: CoreStateMachine::resetVolumioState Jan 09 06:58:01 volumio volumio[2413]: info: CoreStateMachine::getcurrentVolume Jan 09 06:58:01 volumio volumio[2413]: info: CoreCommandRouter::volumioRetrievevolume Jan 09 06:58:01 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:58:01 volumio sudo[2740]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 09 06:58:01 volumio sudo[2740]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:01 volumio sudo[2742]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 09 06:58:01 volumio sudo[2742]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:01 volumio sudo[2740]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:01 volumio sudo[2742]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:01 volumio volumio[2413]: info: Volumio Network Manager: Network status updated: 1 Jan 09 06:58:01 volumio go-librespot[2729]: time="2026-01-09T06:58:01-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]" Jan 09 06:58:01 volumio go-librespot[2729]: time="2026-01-09T06:58:01-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]" Jan 09 06:58:01 volumio go-librespot[2729]: time="2026-01-09T06:58:01-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]" Jan 09 06:58:01 volumio volumio[2413]: info: VolumeController:: Volume=100 Mute =false Jan 09 06:58:01 volumio volumio[2413]: info: CoreStateMachine::pushState Jan 09 06:58:01 volumio volumio[2413]: info: CorePlayQueue::getTrack 0 Jan 09 06:58:01 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 09 06:58:01 volumio go-librespot[2729]: time="2026-01-09T06:58:01-06:00" level=info msg="zeroconf server listening on port 44111" Jan 09 06:58:01 volumio volumio[2413]: info: CoreCommandRouter::volumioPushState Jan 09 06:58:01 volumio volumio[2413]: info: CoreStateMachine::updateTrackBlock Jan 09 06:58:01 volumio volumio[2413]: info: CorePlayQueue::getTrackBlock Jan 09 06:58:01 volumio volumio[2413]: info: CoreCommandRouter::volumioRetrievevolume Jan 09 06:58:01 volumio volumio-remote-updater[14193]: [2026-01-09 06:58:01] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1767963478 101 Jan 09 06:58:01 volumio volumio[2413]: 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 Jan 09 06:58:01 volumio volumio[2413]: info: Reloading queue from file Jan 09 06:58:01 volumio go-librespot[2729]: time="2026-01-09T06:58:01-06:00" level=debug msg="obtained new client token: AADxG7A38h5JAV5nm7vL6U3o+nQAh3aCBQ2eXRMYWl9FcdTG7UmN40FSz7SWMxU1Czyo6rieSuHKNzI08UvlBtg8fYidX5t2KXmXzKqzkaeRttkYPkC0ug5NBDyM570imoOKaqaxScy7SPVaH171I81EXb8sQxIBS+5KYLU/XQXpTD6pNJy49G7tsZF8Qv5HSGl3+FkvorHKGeQwDyXqWjPWfjC9PA0+ddiwkmeeuUwgZUcFn9eoQt+NbQ==" Jan 09 06:58:01 volumio volumio[2413]: info: CoreStateMachine::setRepeat null single undefined Jan 09 06:58:01 volumio volumio[2413]: info: CoreStateMachine::pushState Jan 09 06:58:01 volumio volumio[2413]: info: CorePlayQueue::getTrack 0 Jan 09 06:58:01 volumio volumio[2413]: info: CoreCommandRouter::volumioPushState Jan 09 06:58:01 volumio volumio[2413]: info: CoreStateMachine::setRandom null Jan 09 06:58:01 volumio volumio[2413]: info: CoreStateMachine::pushState Jan 09 06:58:01 volumio volumio[2413]: info: CorePlayQueue::getTrack 0 Jan 09 06:58:01 volumio volumio[2413]: info: CoreCommandRouter::volumioPushState Jan 09 06:58:01 volumio volumio[2413]: info: Setting Device type: Raspberry PI Jan 09 06:58:01 volumio go-librespot[2729]: time="2026-01-09T06:58:01-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 09 06:58:01 volumio volumio[2413]: info: VolumeController:: Volume=100 Mute =false Jan 09 06:58:01 volumio volumio[2413]: info: CoreStateMachine::pushState Jan 09 06:58:01 volumio volumio[2413]: info: CorePlayQueue::getTrack 0 Jan 09 06:58:01 volumio volumio[2413]: info: CoreCommandRouter::volumioPushState Jan 09 06:58:02 volumio volumio[2413]: info: Completed loading Core Plugins Jan 09 06:58:02 volumio volumio[2413]: info: Preparing to generate the ALSA configuration file Jan 09 06:58:02 volumio sudo[2756]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 09 06:58:02 volumio sudo[2756]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:02 volumio go-librespot[2729]: time="2026-01-09T06:58:02-06:00" level=debug msg="completed keyexchange" Jan 09 06:58:02 volumio go-librespot[2729]: time="2026-01-09T06:58:02-06:00" level=debug msg="completed challenge" Jan 09 06:58:02 volumio volumio[2413]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Jan 09 06:58:02 volumio volumio[2413]: info: Discovery: Found device Volumio Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::volumioGetState Jan 09 06:58:02 volumio volumio[2413]: info: CorePlayQueue::getTrack 0 Jan 09 06:58:02 volumio volumio[2413]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 09 06:58:02 volumio volumio[2413]: info: Reading ALSA contributions from plugins. Jan 09 06:58:02 volumio sudo[2756]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:02 volumio volumio[2413]: info: Upmpdcli Daemon Started Jan 09 06:58:02 volumio go-librespot[2729]: time="2026-01-09T06:58:02-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 " Jan 09 06:58:02 volumio volumio[2413]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Jan 09 06:58:02 volumio volumio[2413]: info: Discovery: Found device Volumio Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::volumioGetState Jan 09 06:58:02 volumio volumio[2413]: info: CorePlayQueue::getTrack 0 Jan 09 06:58:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 09 06:58:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 09 06:58:02 volumio volumio[2413]: info: Asound.conf file unchanged, so no further update is needed Jan 09 06:58:02 volumio volumio[2413]: info: Output device has changed, restarting MPD Jan 09 06:58:02 volumio volumio[2413]: info: Output device has changed, restarting Shairport Sync Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:58:02 volumio sudo[2759]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 09 06:58:02 volumio sudo[2759]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:02 volumio sudo[2759]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:02 volumio sudo[2761]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 09 06:58:02 volumio sudo[2761]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:02 volumio volumio[2413]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 09 06:58:02 volumio volumio[2413]: info: ___________ START PLUGINS ___________ Jan 09 06:58:02 volumio volumio[2413]: info: ControllerMpd::onStart: Initializing MPD Jan 09 06:58:02 volumio volumio[2413]: info: Creating MPD Configuration file Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 09 06:58:02 volumio volumio[2413]: info: [1767963482196] CoreMusicLibrary::Adding element Media Servers Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 09 06:58:02 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 09 06:58:02 volumio sudo[2769]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 09 06:58:02 volumio sudo[2771]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 09 06:58:02 volumio sudo[2771]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:02 volumio sudo[2769]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:02 volumio sudo[2769]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:58:02 volumio volumio[2413]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:58:02 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 09 06:58:02 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 09 06:58:02 volumio systemd[1]: mpd.service: Consumed 4.289s CPU time. Jan 09 06:58:02 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 09 06:58:02 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 09 06:58:02 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 09 06:58:02 volumio volumio[2413]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 09 06:58:02 volumio volumio[2413]: info: [1767963482337] CoreMusicLibrary::Adding element Last_100 Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 09 06:58:02 volumio volumio[2413]: info: [1767963482342] CoreMusicLibrary::Adding element Webradio Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 09 06:58:02 volumio volumio[2413]: info: Initializing BBC Radios Jan 09 06:58:02 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 09 06:58:02 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 09 06:58:02 volumio volumio[2413]: info: [1767963482422] CoreMusicLibrary::Adding element Bandcamp Discover Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 09 06:58:02 volumio volumio[2413]: Cannot find translation for source Bandcamp Discover Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 09 06:58:02 volumio volumio[2413]: info: [1767963482434] CoreMusicLibrary::Adding element SoundCloud Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 09 06:58:02 volumio volumio[2413]: Cannot find translation for source Bandcamp Discover Jan 09 06:58:02 volumio volumio[2413]: Cannot find translation for source SoundCloud Jan 09 06:58:02 volumio volumio[2413]: info: Creating Spotify config file Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:02 volumio sudo[2796]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 09 06:58:02 volumio sudo[2796]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 09 06:58:02 volumio sudo[2796]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:02 volumio volumio[2413]: info: [squeezelite_mc] Starting proxy server... Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 09 06:58:02 volumio volumio[2413]: info: [1767963482781] CoreMusicLibrary::Adding element YouTube2 Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 09 06:58:02 volumio volumio[2413]: Cannot find translation for source Bandcamp Discover Jan 09 06:58:02 volumio volumio[2413]: Cannot find translation for source SoundCloud Jan 09 06:58:02 volumio volumio[2413]: Cannot find translation for source YouTube2 Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 09 06:58:02 volumio volumio[2413]: info: [1767963482799] CoreMusicLibrary::Adding element YouTube Music Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 09 06:58:02 volumio volumio[2413]: Cannot find translation for source Bandcamp Discover Jan 09 06:58:02 volumio volumio[2413]: Cannot find translation for source SoundCloud Jan 09 06:58:02 volumio volumio[2413]: Cannot find translation for source YouTube2 Jan 09 06:58:02 volumio volumio[2413]: Cannot find translation for source YouTube Music Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 09 06:58:02 volumio volumio[2413]: info: [1767963482811] CoreMusicLibrary::Adding element Podcast Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 09 06:58:02 volumio volumio[2413]: Cannot find translation for source Bandcamp Discover Jan 09 06:58:02 volumio volumio[2413]: Cannot find translation for source SoundCloud Jan 09 06:58:02 volumio volumio[2413]: Cannot find translation for source YouTube2 Jan 09 06:58:02 volumio volumio[2413]: Cannot find translation for source YouTube Music Jan 09 06:58:02 volumio volumio[2413]: Cannot find translation for source Podcast Jan 09 06:58:02 volumio volumio[2413]: info: Loading i18n strings for locale en Jan 09 06:58:02 volumio volumio[2413]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 09 06:58:02 volumio volumio[2413]: Updating browse sources language Jan 09 06:58:02 volumio volumio[2413]: Cannot find translation for source Bandcamp Discover Jan 09 06:58:02 volumio volumio[2413]: Cannot find translation for source SoundCloud Jan 09 06:58:02 volumio volumio[2413]: Cannot find translation for source YouTube2 Jan 09 06:58:02 volumio volumio[2413]: Cannot find translation for source YouTube Music Jan 09 06:58:02 volumio volumio[2413]: Cannot find translation for source Podcast Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 09 06:58:02 volumio volumio[2413]: Cannot find translation for source Bandcamp Discover Jan 09 06:58:02 volumio volumio[2413]: Cannot find translation for source SoundCloud Jan 09 06:58:02 volumio volumio[2413]: Cannot find translation for source YouTube2 Jan 09 06:58:02 volumio volumio[2413]: Cannot find translation for source YouTube Music Jan 09 06:58:02 volumio volumio[2413]: Cannot find translation for source Podcast Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 09 06:58:02 volumio volumio[2413]: info: [1767963482865] CoreMusicLibrary::Adding element Volusonic Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 09 06:58:02 volumio volumio[2413]: Cannot find translation for source Bandcamp Discover Jan 09 06:58:02 volumio volumio[2413]: Cannot find translation for source SoundCloud Jan 09 06:58:02 volumio volumio[2413]: Cannot find translation for source YouTube2 Jan 09 06:58:02 volumio volumio[2413]: Cannot find translation for source YouTube Music Jan 09 06:58:02 volumio volumio[2413]: Cannot find translation for source Podcast Jan 09 06:58:02 volumio volumio[2413]: Cannot find translation for source Volusonic Jan 09 06:58:02 volumio volumio[2413]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Jan 09 06:58:02 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jan 09 06:58:02 volumio volumio[2413]: info: Volumio Calling Home Jan 09 06:58:03 volumio volumio[2413]: info: [squeezelite_mc] Proxy server started on port 37595 Jan 09 06:58:03 volumio volumio[2413]: info: Preparing to generate the ALSA configuration file Jan 09 06:58:03 volumio volumio[2413]: info: CoreCommandRouter::volumioRetrievevolume Jan 09 06:58:03 volumio volumio[2413]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 09 06:58:03 volumio volumio[2413]: info: Reading ALSA contributions from plugins. Jan 09 06:58:03 volumio volumio[2413]: info: MPD Permissions set Jan 09 06:58:03 volumio volumio[2413]: info: MPD Permissions set Jan 09 06:58:03 volumio volumio[2413]: info: Spotify config file written Jan 09 06:58:03 volumio sudo[2807]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 09 06:58:03 volumio sudo[2807]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:03 volumio volumio[2413]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 09 06:58:03 volumio volumio[2413]: info: VolumeController:: Volume=100 Mute =false Jan 09 06:58:03 volumio volumio[2413]: info: CoreStateMachine::pushState Jan 09 06:58:03 volumio volumio[2413]: info: CorePlayQueue::getTrack 0 Jan 09 06:58:03 volumio volumio[2413]: info: CoreCommandRouter::volumioPushState Jan 09 06:58:03 volumio volumio[2413]: info: [squeezelite_mc] Server discovery started Jan 09 06:58:03 volumio volumio[2413]: info: [squeezelite_mc] Player finder started Jan 09 06:58:03 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:03 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:03 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:03 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 09 06:58:03 volumio volumio[2413]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Jan 09 06:58:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:58:03 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:03 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:03 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:03 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:03 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:03 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:03 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:03 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:03 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:58:03 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:03 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:03 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:03 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:03 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:03 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:03 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:03 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:03 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:58:03 volumio go-librespot[2811]: go-librespot daemon starting... Jan 09 06:58:03 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:58:03 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:03 volumio volumio[2413]: info: No need to fix Spotify hosts Jan 09 06:58:03 volumio sudo[2807]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:03 volumio go-librespot[2822]: time="2026-01-09T06:58:03-06:00" level=info msg="running go-librespot 0.4.0" Jan 09 06:58:03 volumio go-librespot[2822]: time="2026-01-09T06:58:03-06:00" level=debug msg="app state loaded" Jan 09 06:58:03 volumio go-librespot[2822]: time="2026-01-09T06:58:03-06:00" level=debug msg="stored credentials not found" Jan 09 06:58:03 volumio go-librespot[2822]: time="2026-01-09T06:58:03-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 09 06:58:03 volumio volumio[2413]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 09 06:58:03 volumio volumio[2413]: info: Volumio called home Jan 09 06:58:03 volumio volumio[2413]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Jan 09 06:58:03 volumio volumio[2413]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Jan 09 06:58:03 volumio volumio[2413]: 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 Jan 09 06:58:03 volumio go-librespot[2822]: time="2026-01-09T06:58: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]" Jan 09 06:58:03 volumio go-librespot[2822]: time="2026-01-09T06:58: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]" Jan 09 06:58:03 volumio go-librespot[2822]: time="2026-01-09T06:58: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]" Jan 09 06:58:03 volumio volumio[2413]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 09 06:58:03 volumio volumio[2413]: SPOTIFY: BQCZhPbRKRlhnFe0OF35UlLJ1EG4xAS7ijytitP1ohnNMM-jZjhCjHNSJwrfd9K_qwQNLmR06uD1s0X62CADnFjPCrfuDqS36jllbdc7UNWv_v6-Oy-AnAl-w9VtHul1UYStY5LPr4BTT9bCkltF9eNGjXOPSIjgCyGLP9H_QFp1cd6VEYl4UiLgHm9VsTXghKFbK47aClUdBCwR-1Pd-47bs9d0JhoukBATeew Jan 09 06:58:03 volumio volumio[2413]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 09 06:58:03 volumio volumio[2413]: info: New Spotify access token = BQCZhPbRKRlhnFe0OF35UlLJ1EG4xAS7ijytitP1ohnNMM-jZjhCjHNSJwrfd9K_qwQNLmR06uD1s0X62CADnFjPCrfuDqS36jllbdc7UNWv_v6-Oy-AnAl-w9VtHul1UYStY5LPr4BTT9bCkltF9eNGjXOPSIjgCyGLP9H_QFp1cd6VEYl4UiLgHm9VsTXghKFbK47aClUdBCwR-1Pd-47bs9d0JhoukBATeew Jan 09 06:58:03 volumio volumio[2413]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 09 06:58:03 volumio go-librespot[2822]: time="2026-01-09T06:58:03-06:00" level=info msg="zeroconf server listening on port 35047" Jan 09 06:58:03 volumio volumio[2413]: info: Starting Shairport Sync Jan 09 06:58:03 volumio volumio[2413]: info: Starting Shairport Sync Jan 09 06:58:03 volumio volumio[2413]: info: Starting Shairport Sync Jan 09 06:58:03 volumio sudo[2832]: 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 Jan 09 06:58:03 volumio sudo[2832]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:03 volumio sudo[2834]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 09 06:58:03 volumio sudo[2832]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:03 volumio go-librespot[2822]: time="2026-01-09T06:58:03-06:00" level=debug msg="obtained new client token: AAAarnbTuR9iMWQ59jivWb6Plw5Im4Y1fu1kL3Yb2poN9uZrikvXGzGcW3qp7LcwObj98cLoyL78cUbOOBiv0Pp+T1byeh1zhNwRZfEtb3KYkcvXckvGSlAF/HfpkMss/bhIMtLU074WVBXNBkDf+D0PrLJ3MO1UjT5PAuygc7U01xwlD2YqR0yYPNiOGrbsWpq8BkMhiW1Z1P8gkdwuW5UQ1MnOVRr99jdMH5IWB80UBCkTg0VT3M4yAQ==" Jan 09 06:58:03 volumio sudo[2834]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:03 volumio sudo[2838]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 09 06:58:03 volumio sudo[2838]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:03 volumio sudo[2839]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 09 06:58:03 volumio sudo[2839]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:03 volumio go-librespot[2822]: time="2026-01-09T06:58:03-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 09 06:58:03 volumio volumio[2413]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Jan 09 06:58:03 volumio volumio[2413]: info: Asound.conf file unchanged, so no further update is needed Jan 09 06:58:03 volumio volumio[2413]: info: Output device has changed, restarting MPD Jan 09 06:58:03 volumio go-librespot[2822]: time="2026-01-09T06:58:03-06:00" level=debug msg="completed keyexchange" Jan 09 06:58:03 volumio go-librespot[2822]: time="2026-01-09T06:58:03-06:00" level=debug msg="completed challenge" Jan 09 06:58:03 volumio sudo[2845]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Jan 09 06:58:03 volumio sudo[2845]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:03 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 09 06:58:03 volumio volumio[2413]: info: Output device has changed, restarting Shairport Sync Jan 09 06:58:03 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:03 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:58:03 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 09 06:58:03 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 09 06:58:03 volumio systemd[1]: shairport-sync.service: Consumed 1.919s CPU time. Jan 09 06:58:03 volumio go-librespot[2822]: time="2026-01-09T06:58: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 " Jan 09 06:58:04 volumio sudo[2847]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 09 06:58:04 volumio sudo[2847]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:04 volumio sudo[2845]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:04 volumio sudo[2847]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:04 volumio volumio[2413]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 09 06:58:04 volumio sudo[2850]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 09 06:58:04 volumio sudo[2850]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:04 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 09 06:58:04 volumio sudo[2838]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 09 06:58:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 09 06:58:04 volumio sudo[2839]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:04 volumio sudo[2834]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:04 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 09 06:58:04 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 09 06:58:04 volumio systemd[1]: mpd.service: Consumed 1.611s CPU time. Jan 09 06:58:04 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 09 06:58:04 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 09 06:58:04 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 09 06:58:04 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 09 06:58:04 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 09 06:58:04 volumio volumio[2413]: info: MPD Permissions set Jan 09 06:58:04 volumio volumio[2413]: info: Shairport-Sync Started Jan 09 06:58:04 volumio volumio[2413]: Error adding Membership: Error: addMembership EINVAL Jan 09 06:58:04 volumio volumio[2413]: info: Shairport-Sync Started Jan 09 06:58:04 volumio volumio[2413]: info: Shairport-Sync Started Jan 09 06:58:04 volumio volumio[2413]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Jan 09 06:58:04 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:04 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:04 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:04 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:04 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:04 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:04 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:04 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:04 volumio sudo[2880]: 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 Jan 09 06:58:04 volumio sudo[2880]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:04 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:58:04 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:04 volumio sudo[2880]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:04 volumio sudo[2875]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 09 06:58:04 volumio sudo[2875]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 09 06:58:04 volumio sudo[2875]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:04 volumio volumio[2413]: info: CoreCommandRouter::volumioGetState Jan 09 06:58:04 volumio volumio[2413]: info: CorePlayQueue::getTrack 0 Jan 09 06:58:04 volumio volumio[2413]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Jan 09 06:58:04 volumio volumio[2413]: info: Starting Shairport Sync Jan 09 06:58:04 volumio sudo[2890]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Jan 09 06:58:04 volumio sudo[2890]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:04 volumio sudo[2893]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 09 06:58:04 volumio sudo[2893]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:04 volumio volumio[2413]: 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"} Jan 09 06:58:04 volumio volumio[2413]: info: Spotify Successfully logged in Jan 09 06:58:04 volumio volumio[2413]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 09 06:58:04 volumio volumio[2413]: info: [1767963484610] CoreMusicLibrary::Adding element Spotify Jan 09 06:58:04 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 09 06:58:04 volumio volumio[2413]: Cannot find translation for source Bandcamp Discover Jan 09 06:58:04 volumio volumio[2413]: Cannot find translation for source SoundCloud Jan 09 06:58:04 volumio volumio[2413]: Cannot find translation for source YouTube2 Jan 09 06:58:04 volumio volumio[2413]: Cannot find translation for source YouTube Music Jan 09 06:58:04 volumio volumio[2413]: Cannot find translation for source Podcast Jan 09 06:58:04 volumio volumio[2413]: Cannot find translation for source Volusonic Jan 09 06:58:04 volumio volumio[2413]: Cannot find translation for source Spotify Jan 09 06:58:04 volumio kernel: hwmon hwmon1: Voltage normalised Jan 09 06:58:04 volumio systemd[1]: Reloading. Jan 09 06:58:05 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:05 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:05 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 06:58:05 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 09 06:58:05 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.236.178 Jan 09 06:58:05 volumio avahi-daemon[664]: Registering new address record for 169.254.236.178 on eth0.IPv4. Jan 09 06:58:05 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 09 06:58:06 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.236.178 Jan 09 06:58:06 volumio volumio[2413]: info: go-librespot daemon successfully initialized Jan 09 06:58:06 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 09 06:58:07 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.236.178 Jan 09 06:58:07 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.236.178 Jan 09 06:58:07 volumio avahi-daemon[664]: Withdrawing address record for 169.254.236.178 on eth0. Jan 09 06:58:07 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 09 06:58:07 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 09 06:58:07 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. Jan 09 06:58:07 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. Jan 09 06:58:08 volumio sudo[2890]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:08 volumio volumio[2413]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 09 06:58:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 09 06:58:08 volumio sudo[2961]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 09 06:58:08 volumio sudo[2961]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:08 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:58:08 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 09 06:58:08 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:58:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:58:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:58:08 volumio go-librespot[2964]: go-librespot daemon starting... Jan 09 06:58:08 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 09 06:58:08 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 09 06:58:08 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 09 06:58:08 volumio systemd[1]: shairport-sync.service: Consumed 1.499s CPU time. Jan 09 06:58:08 volumio go-librespot[2965]: time="2026-01-09T06:58:08-06:00" level=info msg="running go-librespot 0.4.0" Jan 09 06:58:08 volumio go-librespot[2965]: time="2026-01-09T06:58:08-06:00" level=debug msg="app state loaded" Jan 09 06:58:08 volumio go-librespot[2965]: time="2026-01-09T06:58:08-06:00" level=debug msg="stored credentials not found" Jan 09 06:58:08 volumio go-librespot[2965]: time="2026-01-09T06:58:08-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 09 06:58:08 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:58:08 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 09 06:58:08 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:58:08 volumio sudo[2961]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:08 volumio volumio[2413]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Jan 09 06:58:08 volumio sudo[2973]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Jan 09 06:58:08 volumio sudo[2973]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:08 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 09 06:58:08 volumio sudo[2893]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:08 volumio volumio[2413]: info: Shairport-Sync Started Jan 09 06:58:08 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Jan 09 06:58:08 volumio systemd[1]: squeezelite.service: Deactivated successfully. Jan 09 06:58:08 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Jan 09 06:58:08 volumio go-librespot[2965]: time="2026-01-09T06:58: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]" Jan 09 06:58:08 volumio go-librespot[2965]: time="2026-01-09T06:58: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]" Jan 09 06:58:08 volumio go-librespot[2965]: time="2026-01-09T06:58: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]" Jan 09 06:58:08 volumio sudo[2973]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:08 volumio go-librespot[2965]: time="2026-01-09T06:58:08-06:00" level=info msg="zeroconf server listening on port 37077" Jan 09 06:58:08 volumio go-librespot[2965]: time="2026-01-09T06:58:08-06:00" level=debug msg="obtained new client token: AAA+CiqXo1/h8prg2IeHrm852HoNbDicZUqrd5S/z2qMur/X1/cXq3oHC+LxKvT2t2bEMgagW5jQlvYWluOgpg6ytp+pKe6hpz8LHFlfHSwOU8M6OdNvRCUvYomW8nPGNF+qGlcv0aMltq5YHQ/z6eIMXuAu+41e1mHJoQ0B2Q0MVvly/nBY8GGSEpxoUmbcJIYppuwbNHwwKb/GV6WuQTtRRS7sVJwGqohCSpM86CGLDoFFUEMgGly9kg==" Jan 09 06:58:08 volumio go-librespot[2965]: time="2026-01-09T06:58:08-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 09 06:58:08 volumio go-librespot[2965]: time="2026-01-09T06:58:08-06:00" level=debug msg="completed keyexchange" Jan 09 06:58:08 volumio go-librespot[2965]: time="2026-01-09T06:58:08-06:00" level=debug msg="completed challenge" Jan 09 06:58:08 volumio go-librespot[2965]: time="2026-01-09T06:58: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 " Jan 09 06:58:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 09 06:58:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 09 06:58:09 volumio volumio[2413]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 09 06:58:09 volumio sudo[2992]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 09 06:58:09 volumio sudo[2992]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:09 volumio sudo[2992]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:09 volumio volumio[2413]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Jan 09 06:58:09 volumio sudo[2996]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Jan 09 06:58:09 volumio sudo[2996]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:09 volumio sudo[2996]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:09 volumio volumio[2413]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Jan 09 06:58:09 volumio sudo[2999]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Jan 09 06:58:09 volumio sudo[2999]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:09 volumio mpd[2888]: 2026-01-09T06:58:09 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 09 06:58:09 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Jan 09 06:58:09 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Jan 09 06:58:09 volumio sudo[2999]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:09 volumio volumio[2413]: info: Initializing connection to go-librespot Websocket Jan 09 06:58:09 volumio volumio[2413]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 09 06:58:09 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 09 06:58:09 volumio sudo[2850]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:09 volumio sudo[2771]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:09 volumio sudo[2761]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:09 volumio volumio[2413]: error: MPD error: The expression evaluated to a falsy value: Jan 09 06:58:09 volumio volumio[2413]: assert.ok(self.idling) Jan 09 06:58:09 volumio volumio[2413]: error: The expression evaluated to a falsy value: Jan 09 06:58:09 volumio volumio[2413]: assert.ok(self.idling) Jan 09 06:58:09 volumio volumio[2413]: error: MPD error: The expression evaluated to a falsy value: Jan 09 06:58:09 volumio volumio[2413]: assert.ok(self.idling) Jan 09 06:58:09 volumio volumio[2413]: error: The expression evaluated to a falsy value: Jan 09 06:58:09 volumio volumio[2413]: assert.ok(self.idling) Jan 09 06:58:09 volumio volumio[2413]: info: MPD running with PID2888 Jan 09 06:58:09 volumio volumio[2413]: ,establishing connection Jan 09 06:58:09 volumio volumio[2413]: error: updateQueue error: null Jan 09 06:58:09 volumio volumio[2413]: error: updateQueue error: null Jan 09 06:58:10 volumio volumio[2413]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 09 06:58:10 volumio sudo[3011]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 09 06:58:10 volumio sudo[3011]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:10 volumio sudo[3011]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:10 volumio volumio[2413]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 09 06:58:10 volumio sudo[3014]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 09 06:58:10 volumio sudo[3014]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:10 volumio sudo[3014]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:10 volumio kernel: hwmon hwmon1: Voltage normalised Jan 09 06:58:11 volumio volumio[2413]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 09 06:58:11 volumio sudo[3018]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 09 06:58:11 volumio sudo[3018]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:11 volumio sudo[3018]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:11 volumio volumio[2413]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 09 06:58:11 volumio sudo[3021]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 09 06:58:11 volumio sudo[3021]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 09 06:58:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:58:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:58:12 volumio go-librespot[3023]: go-librespot daemon starting... Jan 09 06:58:12 volumio sudo[3021]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:12 volumio go-librespot[3024]: time="2026-01-09T06:58:12-06:00" level=info msg="running go-librespot 0.4.0" Jan 09 06:58:12 volumio go-librespot[3024]: time="2026-01-09T06:58:12-06:00" level=debug msg="app state loaded" Jan 09 06:58:12 volumio go-librespot[3024]: time="2026-01-09T06:58:12-06:00" level=debug msg="stored credentials not found" Jan 09 06:58:12 volumio go-librespot[3024]: time="2026-01-09T06:58:12-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 09 06:58:12 volumio go-librespot[3024]: time="2026-01-09T06:58: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 09 06:58:12 volumio go-librespot[3024]: time="2026-01-09T06:58:12-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]" Jan 09 06:58:12 volumio go-librespot[3024]: time="2026-01-09T06:58:12-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]" Jan 09 06:58:12 volumio go-librespot[3024]: time="2026-01-09T06:58:12-06:00" level=info msg="zeroconf server listening on port 37553" Jan 09 06:58:12 volumio go-librespot[3024]: time="2026-01-09T06:58:12-06:00" level=debug msg="obtained new client token: AAA0RoXhGPL/MYtigttJpQy7GHJTjXWDSdPa97PzjgWKgb8YXNdbsaFectRoIfrJB4g+ZwSjpzSAFvJ/8n72ElbfQKgtNN6AWBQ51lAPKZboTS+hyQtK9v7AkwIQa318yRFIO9Dzc637kCzx+Xbmd083lTZ/Aaf8CDIkzJ5ew2OyxmLK+4wsfB0dIavsIEBw9I7GHH6V4fSiUb80lUX32abEEMPCPf5GDHilc+cpLr+axOW3OiZsLQ/phg==" Jan 09 06:58:12 volumio go-librespot[3024]: time="2026-01-09T06:58:12-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 09 06:58:12 volumio go-librespot[3024]: time="2026-01-09T06:58:12-06:00" level=debug msg="completed keyexchange" Jan 09 06:58:12 volumio go-librespot[3024]: time="2026-01-09T06:58:12-06:00" level=debug msg="completed challenge" Jan 09 06:58:12 volumio go-librespot[3024]: time="2026-01-09T06:58: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 " Jan 09 06:58:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 09 06:58:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 09 06:58:12 volumio volumio[2413]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 09 06:58:12 volumio sudo[3032]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 09 06:58:12 volumio sudo[3032]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:12 volumio sudo[3032]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:12 volumio volumio[2413]: info: Completed starting Core Plugins Jan 09 06:58:12 volumio volumio[2413]: info: ------------------------------------------- Jan 09 06:58:12 volumio volumio[2413]: info: ----- MyVolumio plugins startup ---- Jan 09 06:58:12 volumio volumio[2413]: info: ------------------------------------------- Jan 09 06:58:12 volumio volumio[2413]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 09 06:58:12 volumio volumio[2413]: info: Initializing connection to go-librespot Websocket Jan 09 06:58:12 volumio volumio[2413]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 09 06:58:12 volumio sudo[3035]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 09 06:58:12 volumio sudo[3035]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:12 volumio sudo[3037]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 09 06:58:12 volumio sudo[3037]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:12 volumio sudo[3039]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 09 06:58:12 volumio sudo[3039]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:12 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 09 06:58:12 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 09 06:58:12 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 09 06:58:12 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 09 06:58:12 volumio sudo[3035]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:12 volumio mpd_monitor.sh[3043]: MPD Monitor Service: Starting MPD Monitor Service Jan 09 06:58:12 volumio sudo[3039]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:12 volumio sudo[3037]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:12 volumio volumio[2413]: info: Successfully started MPD Monitor Jan 09 06:58:12 volumio volumio[2413]: info: Successfully started MPD Monitor Jan 09 06:58:12 volumio volumio[2413]: info: Successfully started MPD Monitor Jan 09 06:58:13 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.121.210 Jan 09 06:58:13 volumio avahi-daemon[664]: Registering new address record for 169.254.121.210 on eth0.IPv4. Jan 09 06:58:13 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 09 06:58:13 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:58:13 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 09 06:58:13 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:58:13 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.121.210 Jan 09 06:58:14 volumio ntpd[872]: IO: Listen normally on 10347 eth0 169.254.121.210:123 Jan 09 06:58:14 volumio ntpd[872]: IO: new interface(s) found: waking up resolver Jan 09 06:58:14 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.121.210 Jan 09 06:58:14 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.121.210 Jan 09 06:58:14 volumio avahi-daemon[664]: Withdrawing address record for 169.254.121.210 on eth0. Jan 09 06:58:14 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 09 06:58:14 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 09 06:58:14 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:58:14 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 09 06:58:14 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:58:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 09 06:58:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:58:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:58:15 volumio go-librespot[3093]: go-librespot daemon starting... Jan 09 06:58:15 volumio go-librespot[3094]: time="2026-01-09T06:58:15-06:00" level=info msg="running go-librespot 0.4.0" Jan 09 06:58:15 volumio go-librespot[3094]: time="2026-01-09T06:58:15-06:00" level=debug msg="app state loaded" Jan 09 06:58:15 volumio go-librespot[3094]: time="2026-01-09T06:58:15-06:00" level=debug msg="stored credentials not found" Jan 09 06:58:15 volumio go-librespot[3094]: time="2026-01-09T06:58:15-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 09 06:58:16 volumio volumio[2413]: info: Initializing connection to go-librespot Websocket Jan 09 06:58:16 volumio go-librespot[3094]: time="2026-01-09T06:58: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-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 09 06:58:16 volumio go-librespot[3094]: time="2026-01-09T06:58:16-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]" Jan 09 06:58:16 volumio go-librespot[3094]: time="2026-01-09T06:58:16-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]" Jan 09 06:58:16 volumio go-librespot[3094]: time="2026-01-09T06:58:16-06:00" level=info msg="zeroconf server listening on port 38001" Jan 09 06:58:16 volumio ntpd[872]: IO: Deleting interface #10347 eth0, 169.254.121.210#123, interface stats: received=0, sent=0, dropped=0, active_time=2 secs Jan 09 06:58:16 volumio go-librespot[3094]: time="2026-01-09T06:58:16-06:00" level=debug msg="obtained new client token: AABjmK41B2/tNEGdH2kHLas/HaS/QoEkbAemT1cLvZ2IRyE9HcAQmSdMUfwCsbilX7XzStLLHAG/LB7ZrwhEnmlzwfP8h9kEI0gDgYd6j98K+IKiXVA7OmAhr3NBa1j4MwLV/4Ef+dO4OnXCwTG7FKqKlMVwWBT3r321NzAGxz9NVGqnlQA8TGry2KCGer7kx8AP6kQIsMvud7y1U7IpvFs34OL07vC76hjQwiXGne1Cxc5VMqy8WP0vmA==" Jan 09 06:58:16 volumio go-librespot[3094]: time="2026-01-09T06:58:16-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 09 06:58:16 volumio go-librespot[3094]: time="2026-01-09T06:58:16-06:00" level=debug msg="completed keyexchange" Jan 09 06:58:16 volumio go-librespot[3094]: time="2026-01-09T06:58:16-06:00" level=debug msg="completed challenge" Jan 09 06:58:16 volumio go-librespot[3094]: time="2026-01-09T06:58: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 " Jan 09 06:58:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 09 06:58:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 09 06:58:16 volumio volumio[2413]: info: Error connecting to go-librespot Websocket: Error: socket hang up Jan 09 06:58:17 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 09 06:58:19 volumio volumio[2413]: info: Initializing connection to go-librespot Websocket Jan 09 06:58:19 volumio volumio[2413]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 09 06:58:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Jan 09 06:58:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:58:19 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.188.163 Jan 09 06:58:19 volumio avahi-daemon[664]: Registering new address record for 169.254.188.163 on eth0.IPv4. Jan 09 06:58:19 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 09 06:58:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:58:20 volumio go-librespot[3103]: go-librespot daemon starting... Jan 09 06:58:20 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:58:20 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 09 06:58:20 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:58:20 volumio go-librespot[3111]: time="2026-01-09T06:58:20-06:00" level=info msg="running go-librespot 0.4.0" Jan 09 06:58:20 volumio go-librespot[3111]: time="2026-01-09T06:58:20-06:00" level=debug msg="app state loaded" Jan 09 06:58:20 volumio go-librespot[3111]: time="2026-01-09T06:58:20-06:00" level=debug msg="stored credentials not found" Jan 09 06:58:20 volumio go-librespot[3111]: time="2026-01-09T06:58:20-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 09 06:58:20 volumio go-librespot[3111]: time="2026-01-09T06:58: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]" Jan 09 06:58:20 volumio go-librespot[3111]: time="2026-01-09T06:58: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]" Jan 09 06:58:20 volumio go-librespot[3111]: time="2026-01-09T06:58: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]" Jan 09 06:58:20 volumio go-librespot[3111]: time="2026-01-09T06:58:20-06:00" level=info msg="zeroconf server listening on port 36503" Jan 09 06:58:20 volumio go-librespot[3111]: time="2026-01-09T06:58:20-06:00" level=debug msg="obtained new client token: AABi6HbPE/0dJ7ZDPTQHTXGggaTcXBmepzt7y6niIwGddaaeGxrfCguiNxqppPikC/auf4GHDTSqjtSm5tWub/nZVRLiRL87sGptDnxpxxJPw/a48QwktTSeeA7Y7az7W2I4q0+FRew52xQgildoioKHySuT3u/a46+wHZZzx5nUwcOv5Vqiw3kGyIayoXrlxcC3z3G3i2Ob29VqeiU4E0C9D0FAMhWD/LQFglIGHafWeA2P8GGZlOM4RQ==" Jan 09 06:58:20 volumio go-librespot[3111]: time="2026-01-09T06:58:20-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 09 06:58:20 volumio go-librespot[3111]: time="2026-01-09T06:58:20-06:00" level=debug msg="completed keyexchange" Jan 09 06:58:20 volumio go-librespot[3111]: time="2026-01-09T06:58:20-06:00" level=debug msg="completed challenge" Jan 09 06:58:20 volumio go-librespot[3111]: time="2026-01-09T06:58: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 " Jan 09 06:58:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 09 06:58:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 09 06:58:20 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.188.163 Jan 09 06:58:20 volumio volumio[2413]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 09 06:58:20 volumio volumio[2413]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 09 06:58:20 volumio volumio[2413]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 09 06:58:20 volumio volumio[2413]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 09 06:58:20 volumio volumio[2413]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 09 06:58:20 volumio volumio[2413]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 09 06:58:20 volumio volumio[2413]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 09 06:58:20 volumio volumio[2413]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 09 06:58:20 volumio volumio[2413]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 09 06:58:20 volumio volumio[2413]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 09 06:58:20 volumio volumio[2413]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 09 06:58:20 volumio volumio[2413]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 09 06:58:20 volumio volumio[2413]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 09 06:58:20 volumio volumio[2413]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 09 06:58:20 volumio volumio[2413]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 09 06:58:20 volumio volumio[2413]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 09 06:58:20 volumio volumio[2413]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 09 06:58:20 volumio volumio[2413]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 09 06:58:20 volumio volumio[2413]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 09 06:58:20 volumio volumio[2413]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 09 06:58:20 volumio volumio[2413]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 09 06:58:20 volumio volumio[2413]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 09 06:58:20 volumio volumio[2413]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 09 06:58:20 volumio volumio[2413]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 09 06:58:20 volumio volumio[2413]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 09 06:58:20 volumio volumio[2413]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 09 06:58:20 volumio volumio[2413]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 09 06:58:20 volumio volumio[2413]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 09 06:58:20 volumio volumio[2413]: info: Adding plugin bluetooth to MyMusic Plugins Jan 09 06:58:20 volumio volumio[2413]: info: Adding plugin multiroom to MyMusic Plugins Jan 09 06:58:20 volumio volumio[2413]: info: Adding plugin metavolumio to MyMusic Plugins Jan 09 06:58:20 volumio volumio[2413]: info: Adding plugin cd_controller to MyMusic Plugins Jan 09 06:58:20 volumio volumio[2413]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 09 06:58:20 volumio volumio[2413]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 09 06:58:20 volumio volumio[2413]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 09 06:58:20 volumio volumio[2413]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 09 06:58:20 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.188.163 Jan 09 06:58:20 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.188.163 Jan 09 06:58:20 volumio avahi-daemon[664]: Withdrawing address record for 169.254.188.163 on eth0. Jan 09 06:58:20 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 09 06:58:21 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 09 06:58:21 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:58:21 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 09 06:58:21 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:58:21 volumio kernel: hwmon hwmon1: Voltage normalised Jan 09 06:58:21 volumio volumio[2413]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 09 06:58:21 volumio volumio[2413]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 09 06:58:21 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:58:21 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:58:21 volumio volumio[2413]: info: Starting MyVolumio Remote Streaming Endpoints Jan 09 06:58:21 volumio volumio[2413]: info: MyVolumio login type: Token Jan 09 06:58:21 volumio volumio[2413]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 09 06:58:21 volumio volumio[2413]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 09 06:58:22 volumio volumio[2413]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 09 06:58:22 volumio volumio[2413]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 09 06:58:22 volumio volumio[2413]: info: Streaming services startup Jan 09 06:58:22 volumio volumio[2413]: info: Starting Streaming Daemon Jan 09 06:58:22 volumio sudo[3145]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 09 06:58:22 volumio sudo[3145]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:22 volumio volumio[2413]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 09 06:58:22 volumio sudo[3145]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:22 volumio volumio[2413]: error: Cannot start Volumio Streaming Daemon Jan 09 06:58:22 volumio volumio[2413]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 09 06:58:22 volumio volumio[2413]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 09 06:58:22 volumio volumio[2413]: info: Initializing connection to go-librespot Websocket Jan 09 06:58:22 volumio volumio[2413]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 09 06:58:23 volumio volumio[2413]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 09 06:58:23 volumio volumio[2413]: info: MyVolumio token set successfully Jan 09 06:58:23 volumio volumio[2413]: info: MYVOLUMIO: Adding device Jan 09 06:58:23 volumio volumio[2413]: info: MYVOLUMIO: Evaluating Server Jan 09 06:58:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jan 09 06:58:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:58:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:58:23 volumio go-librespot[3157]: go-librespot daemon starting... Jan 09 06:58:23 volumio go-librespot[3162]: time="2026-01-09T06:58:23-06:00" level=info msg="running go-librespot 0.4.0" Jan 09 06:58:23 volumio go-librespot[3162]: time="2026-01-09T06:58:23-06:00" level=debug msg="app state loaded" Jan 09 06:58:23 volumio go-librespot[3162]: time="2026-01-09T06:58:23-06:00" level=debug msg="stored credentials not found" Jan 09 06:58:23 volumio go-librespot[3162]: time="2026-01-09T06:58:23-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 09 06:58:23 volumio volumio[2413]: info: MyVolumio status changed Jan 09 06:58:23 volumio volumio[2413]: info: Streaming services startup Jan 09 06:58:23 volumio volumio[2413]: info: Starting Streaming Daemon Jan 09 06:58:23 volumio volumio[2413]: info: Removing browser output: myVolumio user plan is not superstar Jan 09 06:58:23 volumio volumio[2413]: info: Removing audio output: Jan 09 06:58:23 volumio volumio[2413]: info: Stoppping Tunnel 1 Jan 09 06:58:23 volumio sudo[3181]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 09 06:58:23 volumio sudo[3181]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:23 volumio sudo[3183]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 09 06:58:23 volumio sudo[3183]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 06:58:23 volumio sudo[3181]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:23 volumio volumio[2413]: error: Cannot start Volumio Streaming Daemon Jan 09 06:58:23 volumio volumio[2413]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 09 06:58:23 volumio volumio[2413]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 09 06:58:24 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 09 06:58:24 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 09 06:58:24 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 09 06:58:24 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 09 06:58:24 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 09 06:58:24 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 09 06:58:24 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 09 06:58:24 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 09 06:58:24 volumio sudo[3183]: pam_unix(sudo:session): session closed for user root Jan 09 06:58:24 volumio go-librespot[3162]: time="2026-01-09T06:58: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 09 06:58:24 volumio go-librespot[3162]: time="2026-01-09T06:58:24-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]" Jan 09 06:58:24 volumio go-librespot[3162]: time="2026-01-09T06:58:24-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]" Jan 09 06:58:24 volumio volumio[2413]: info: Remote SSH Stopped Jan 09 06:58:24 volumio go-librespot[3162]: time="2026-01-09T06:58:24-06:00" level=info msg="zeroconf server listening on port 35999" Jan 09 06:58:24 volumio volumio[2413]: info: Setting Geolocation for MyVolumio to us4 Jan 09 06:58:24 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:58:24 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:58:24 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:58:24 volumio go-librespot[3162]: time="2026-01-09T06:58:24-06:00" level=debug msg="obtained new client token: AADEGJFKB6oVABwAklo3YyI08ynrNNgqgjVt8HrmLCHoubDTjnEw82g4Es3LvjgLQO0OuA2MneqgUezlg2a51ipseMSiuJusKKZZh3Zf5b2JEF0/ww6iTrA15H7qJj712aq7AqdhgUjTUE4Ksa1qi/09nvPxlGA/+doaTVkci0zQKlYQ0meq+9h7tI6PKlI2tfFde3cO7pvei72BYlEARelcQndVN9fo8X9/3t56sRKegiy9FEt1uMY=" Jan 09 06:58:24 volumio go-librespot[3162]: time="2026-01-09T06:58:24-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 09 06:58:24 volumio go-librespot[3162]: time="2026-01-09T06:58:24-06:00" level=debug msg="completed keyexchange" Jan 09 06:58:24 volumio go-librespot[3162]: time="2026-01-09T06:58:24-06:00" level=debug msg="completed challenge" Jan 09 06:58:24 volumio go-librespot[3162]: time="2026-01-09T06:58: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 " Jan 09 06:58:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 09 06:58:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 09 06:58:24 volumio volumio[2413]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 09 06:58:25 volumio volumio[2413]: info: Updating MyVolumio device info Jan 09 06:58:25 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:58:25 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:58:25 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:58:25 volumio volumio[2413]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jan 09 06:58:25 volumio volumio[2413]: info: Initializing connection to go-librespot Websocket Jan 09 06:58:25 volumio volumio[2413]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 09 06:58:25 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.179.173 Jan 09 06:58:25 volumio avahi-daemon[664]: Registering new address record for 169.254.179.173 on eth0.IPv4. Jan 09 06:58:25 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 09 06:58:26 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:58:26 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 09 06:58:26 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:58:26 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.179.173 Jan 09 06:58:26 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.179.173 Jan 09 06:58:26 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.179.173 Jan 09 06:58:26 volumio avahi-daemon[664]: Withdrawing address record for 169.254.179.173 on eth0. Jan 09 06:58:26 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 09 06:58:26 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 09 06:58:26 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:58:26 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 09 06:58:26 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:58:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Jan 09 06:58:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:58:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:58:27 volumio go-librespot[3232]: go-librespot daemon starting... Jan 09 06:58:27 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 09 06:58:27 volumio go-librespot[3233]: time="2026-01-09T06:58:27-06:00" level=info msg="running go-librespot 0.4.0" Jan 09 06:58:27 volumio go-librespot[3233]: time="2026-01-09T06:58:27-06:00" level=debug msg="app state loaded" Jan 09 06:58:27 volumio go-librespot[3233]: time="2026-01-09T06:58:27-06:00" level=debug msg="stored credentials not found" Jan 09 06:58:27 volumio go-librespot[3233]: time="2026-01-09T06:58:27-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 09 06:58:27 volumio go-librespot[3233]: time="2026-01-09T06:58:27-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]" Jan 09 06:58:27 volumio go-librespot[3233]: time="2026-01-09T06:58:27-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]" Jan 09 06:58:27 volumio go-librespot[3233]: time="2026-01-09T06:58:27-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]" Jan 09 06:58:27 volumio go-librespot[3233]: time="2026-01-09T06:58:27-06:00" level=info msg="zeroconf server listening on port 46845" Jan 09 06:58:28 volumio go-librespot[3233]: time="2026-01-09T06:58:28-06:00" level=debug msg="obtained new client token: AADnvKNG3dL+vnRfi2uuUbc8Nd/awErav0b3o2ttEisuyMM066NQcgKIimVW1gBmfSi3hdC9bfBJv0n1zg0Kgt9Qz3tGfS3hNTivsZYKot6Bk+iH2iKCa2PMXuPhhcwXj5XZSdRKqpv0ULqyFCB1Lmk6PO9ojytDDsxZaNUxkcjghWl7HHQw4bxM1DNlmIR6QeBfHidyb1XsWiqLGQfs8MJzyC4uRM9cZvvGLtOXCsMqh4XJAIJ8V8w=" Jan 09 06:58:28 volumio go-librespot[3233]: time="2026-01-09T06:58:28-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 09 06:58:28 volumio go-librespot[3233]: time="2026-01-09T06:58:28-06:00" level=debug msg="completed keyexchange" Jan 09 06:58:28 volumio go-librespot[3233]: time="2026-01-09T06:58:28-06:00" level=debug msg="completed challenge" Jan 09 06:58:28 volumio go-librespot[3233]: time="2026-01-09T06:58: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 " Jan 09 06:58:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 09 06:58:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 09 06:58:28 volumio volumio[2413]: info: MYVOLUMIO: Adding device Jan 09 06:58:28 volumio volumio[2413]: info: MYVOLUMIO: Evaluating Server Jan 09 06:58:28 volumio volumio[2413]: info: Initializing connection to go-librespot Websocket Jan 09 06:58:28 volumio volumio[2413]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 09 06:58:28 volumio volumio[2413]: info: Setting Geolocation for MyVolumio to us4 Jan 09 06:58:28 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:58:28 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:58:28 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:58:29 volumio volumio[2413]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 09 06:58:29 volumio volumio[2413]: info: Updating MyVolumio device info Jan 09 06:58:29 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:58:29 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:58:29 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:58:30 volumio volumio[2413]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jan 09 06:58:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Jan 09 06:58:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:58:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:58:31 volumio go-librespot[3259]: go-librespot daemon starting... Jan 09 06:58:31 volumio go-librespot[3260]: time="2026-01-09T06:58:31-06:00" level=info msg="running go-librespot 0.4.0" Jan 09 06:58:31 volumio go-librespot[3260]: time="2026-01-09T06:58:31-06:00" level=debug msg="app state loaded" Jan 09 06:58:31 volumio go-librespot[3260]: time="2026-01-09T06:58:31-06:00" level=debug msg="stored credentials not found" Jan 09 06:58:31 volumio go-librespot[3260]: time="2026-01-09T06:58:31-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 09 06:58:31 volumio kernel: hwmon hwmon1: Voltage normalised Jan 09 06:58:31 volumio go-librespot[3260]: time="2026-01-09T06:58:31-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]" Jan 09 06:58:31 volumio go-librespot[3260]: time="2026-01-09T06:58:31-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]" Jan 09 06:58:31 volumio go-librespot[3260]: time="2026-01-09T06:58:31-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]" Jan 09 06:58:31 volumio go-librespot[3260]: time="2026-01-09T06:58:31-06:00" level=info msg="zeroconf server listening on port 38303" Jan 09 06:58:31 volumio go-librespot[3260]: time="2026-01-09T06:58:31-06:00" level=debug msg="obtained new client token: AABW9sJqjl0dxH0kdpOeuP4Uj68YEU6UVWwZGmJA8T5+NgYznUKs9unrl9t1R7jy0XhSIOGcxtsw1XnDpZqzNLjg8esFCW/I6cmPNSZFK1hQY9jZuV6zkChl3roxR/4sJR593JHI+1wuUizbOpYrLlPG8jTfcelL/XhnAe3DqN0vwF9XC+Xh2VIdszScDxGKrTMBqgQh18UjNBid2ZA23G3u1ybQzl1lG09sZ4BO+RecXhdwFR9R7FahSQ==" Jan 09 06:58:31 volumio go-librespot[3260]: time="2026-01-09T06:58:31-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 09 06:58:31 volumio go-librespot[3260]: time="2026-01-09T06:58:31-06:00" level=debug msg="completed keyexchange" Jan 09 06:58:31 volumio go-librespot[3260]: time="2026-01-09T06:58:31-06:00" level=debug msg="completed challenge" Jan 09 06:58:31 volumio volumio[2413]: info: Initializing connection to go-librespot Websocket Jan 09 06:58:31 volumio go-librespot[3260]: time="2026-01-09T06:58:31-06:00" level=debug msg="new websocket client" Jan 09 06:58:31 volumio volumio[2413]: info: Connection to go-librespot Websocket established Jan 09 06:58:31 volumio go-librespot[3260]: time="2026-01-09T06:58:31-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 " Jan 09 06:58:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 09 06:58:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 09 06:58:31 volumio volumio[2413]: info: Connection to go-librespot Websocket closed Jan 09 06:58:32 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.171.117 Jan 09 06:58:32 volumio avahi-daemon[664]: Registering new address record for 169.254.171.117 on eth0.IPv4. Jan 09 06:58:32 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 09 06:58:32 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:58:32 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 09 06:58:32 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:58:32 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.171.117 Jan 09 06:58:32 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 09 06:58:32 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 06:58:32 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 09 06:58:32 volumio volumio-remote-updater[14193]: Test mode disabled Jan 09 06:58:32 volumio volumio-remote-updater[14193]: Alpha mode disabled Jan 09 06:58:32 volumio volumio-remote-updater[14193]: Alpha legacy test mode disabled Jan 09 06:58:32 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Jan 09 06:58:33 volumio volumio[2413]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

ANNOUNCEMENT

\n
    \n
  • Production line
    • \n
\n

FIX

\n
    \n
  • Nodejs 20.5.1 version pinning with static package fallback
    • \n
\n","title":"Update v4.073","updateavailable":true} Jan 09 06:58:33 volumio volumio[2413]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Jan 09 06:58:33 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.171.117 Jan 09 06:58:33 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.171.117 Jan 09 06:58:33 volumio avahi-daemon[664]: Withdrawing address record for 169.254.171.117 on eth0. Jan 09 06:58:33 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 09 06:58:33 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 09 06:58:33 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:58:33 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 09 06:58:33 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 09 06:58:34 volumio volumio[2413]: info: Getting Spotify volume Jan 09 06:58:34 volumio volumio[2413]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 09 06:58:35 volumio volumio[2413]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 09 06:58:35 volumio volumio[2413]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 09 06:58:35 volumio volumio[2413]: errno: -111, Jan 09 06:58:35 volumio volumio[2413]: code: 'ECONNREFUSED', Jan 09 06:58:35 volumio volumio[2413]: syscall: 'connect', Jan 09 06:58:35 volumio volumio[2413]: address: '127.0.0.1', Jan 09 06:58:35 volumio volumio[2413]: port: 9879, Jan 09 06:58:35 volumio volumio[2413]: response: undefined Jan 09 06:58:35 volumio volumio[2413]: } Jan 09 06:58:35 volumio volumio[2413]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 09 06:58:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Jan 09 06:58:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:58:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 09 06:58:35 volumio go-librespot[3319]: go-librespot daemon starting... Jan 09 06:58:35 volumio go-librespot[3320]: time="2026-01-09T06:58:35-06:00" level=info msg="running go-librespot 0.4.0" Jan 09 06:58:35 volumio go-librespot[3320]: time="2026-01-09T06:58:35-06:00" level=debug msg="app state loaded" Jan 09 06:58:35 volumio go-librespot[3320]: time="2026-01-09T06:58:35-06:00" level=debug msg="stored credentials not found" Jan 09 06:58:35 volumio go-librespot[3320]: time="2026-01-09T06:58:35-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 09 06:58:35 volumio go-librespot[3320]: time="2026-01-09T06:58:35-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]" Jan 09 06:58:35 volumio go-librespot[3320]: time="2026-01-09T06:58:35-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]" Jan 09 06:58:35 volumio go-librespot[3320]: time="2026-01-09T06:58:35-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]" Jan 09 06:58:35 volumio go-librespot[3320]: time="2026-01-09T06:58:35-06:00" level=info msg="zeroconf server listening on port 34173" Jan 09 06:58:35 volumio go-librespot[3320]: time="2026-01-09T06:58:35-06:00" level=debug msg="obtained new client token: AAA77GFjHPGhUz10tGrD9K7mfyfXhtOVb3ngt80VJ+pI6+Q/Pv+9AU+aVr7VQKMf4mvfqctyyB30eIpvMb3FgQ2yV90ZHJT67ZglI89Tep7N0msOInMrwAnmLDc3+9d0cXtto2iD01yPc9uIhYx04NbWwA1xwmoUu8RWvTYaDjrGbBDgVc0F0h/DGuU23d+MmaXz88y3LM5olA/4QX3Rc6THvAz8afYUGV37r87i97Ve8jyg0wX29Ut3Jw==" Jan 09 06:58:35 volumio go-librespot[3320]: time="2026-01-09T06:58:35-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 09 06:58:35 volumio go-librespot[3320]: time="2026-01-09T06:58:35-06:00" level=debug msg="completed keyexchange" Jan 09 06:58:35 volumio go-librespot[3320]: time="2026-01-09T06:58:35-06:00" level=debug msg="completed challenge" Jan 09 06:58:35 volumio go-librespot[3320]: time="2026-01-09T06:58:35-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 " Jan 09 06:58:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 09 06:58:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 09 06:58:35 volumio sudo[3343]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-09 06:57' Jan 09 06:58:35 volumio sudo[3343]: 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"