Feb 26 13:27:00 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 26 13:27:00 volumio volumio[2289]: info: go-librespot daemon successfully initialized Feb 26 13:27:01 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. Feb 26 13:27:01 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. Feb 26 13:27:02 volumio sudo[2658]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:02 volumio volumio[2289]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 26 13:27:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Feb 26 13:27:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:27:02 volumio sudo[2696]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 26 13:27:02 volumio sudo[2696]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:27:02 volumio go-librespot[2697]: go-librespot daemon starting... Feb 26 13:27:02 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 26 13:27:02 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 26 13:27:02 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 26 13:27:02 volumio systemd[1]: shairport-sync.service: Consumed 1.501s CPU time. Feb 26 13:27:02 volumio go-librespot[2699]: time="2026-02-26T13:27:02-06:00" level=info msg="running go-librespot 0.4.0" Feb 26 13:27:02 volumio go-librespot[2699]: time="2026-02-26T13:27:02-06:00" level=debug msg="app state loaded" Feb 26 13:27:02 volumio go-librespot[2699]: time="2026-02-26T13:27:02-06:00" level=debug msg="stored credentials not found" Feb 26 13:27:02 volumio go-librespot[2699]: time="2026-02-26T13:27:02-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 13:27:02 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 26 13:27:02 volumio sudo[2660]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:02 volumio volumio[2289]: info: Shairport-Sync Started Feb 26 13:27:02 volumio sudo[2696]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:02 volumio volumio[2289]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Feb 26 13:27:02 volumio sudo[2720]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Feb 26 13:27:02 volumio sudo[2720]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:02 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 26 13:27:02 volumio go-librespot[2699]: time="2026-02-26T13:27:02-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]" Feb 26 13:27:02 volumio go-librespot[2699]: time="2026-02-26T13:27:02-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]" Feb 26 13:27:02 volumio go-librespot[2699]: time="2026-02-26T13:27:02-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]" Feb 26 13:27:02 volumio go-librespot[2699]: time="2026-02-26T13:27:02-06:00" level=info msg="zeroconf server listening on port 43399" Feb 26 13:27:02 volumio go-librespot[2699]: time="2026-02-26T13:27:02-06:00" level=debug msg="obtained new client token: AADzAH17IoFC7FZ+EztfIc5qMKQJYXED8EsMBa9zbRvSjy9s8RHuYJa4OlOcidOdhb+lHtR0CepN+dvvNV6j6gMK6WfyUxEDZnlE6/bdiURkxtgFmJxgAr8YidAHTObygCpg0+Muc0Hyxe6jMqWYr1iRQi9wjYliCa23DcODKqhtbZL4Ac5Bie/nxu2HgQt1ZXLcL4r1k3qBpyT9/F7IgHU/MwMAnyvlVKsN6PER8dEuYQqc5KrLjENprA==" Feb 26 13:27:02 volumio go-librespot[2699]: time="2026-02-26T13:27:02-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 26 13:27:02 volumio systemd[1]: squeezelite.service: Deactivated successfully. Feb 26 13:27:02 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 26 13:27:02 volumio sudo[2720]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:02 volumio go-librespot[2699]: time="2026-02-26T13:27:02-06:00" level=debug msg="completed keyexchange" Feb 26 13:27:02 volumio go-librespot[2699]: time="2026-02-26T13:27:02-06:00" level=debug msg="completed challenge" Feb 26 13:27:03 volumio go-librespot[2699]: time="2026-02-26T13:27: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 " Feb 26 13:27:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 13:27:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 13:27:03 volumio volumio[2289]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 26 13:27:03 volumio sudo[2725]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 26 13:27:03 volumio sudo[2725]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:03 volumio mpd[2652]: 2026-02-26T13:27:03 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 26 13:27:03 volumio sudo[2725]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:03 volumio volumio[2289]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Feb 26 13:27:03 volumio sudo[2729]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Feb 26 13:27:03 volumio sudo[2729]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:03 volumio sudo[2729]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:03 volumio volumio[2289]: info: Initializing connection to go-librespot Websocket Feb 26 13:27:03 volumio volumio[2289]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Feb 26 13:27:03 volumio volumio[2289]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 13:27:03 volumio sudo[2732]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Feb 26 13:27:03 volumio sudo[2732]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:03 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 26 13:27:03 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 26 13:27:03 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 26 13:27:03 volumio sudo[2615]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:03 volumio sudo[2540]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:03 volumio sudo[2530]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:03 volumio sudo[2732]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:03 volumio volumio[2289]: error: MPD error: The expression evaluated to a falsy value: Feb 26 13:27:03 volumio volumio[2289]: assert.ok(self.idling) Feb 26 13:27:03 volumio volumio[2289]: error: The expression evaluated to a falsy value: Feb 26 13:27:03 volumio volumio[2289]: assert.ok(self.idling) Feb 26 13:27:03 volumio volumio[2289]: error: MPD error: The expression evaluated to a falsy value: Feb 26 13:27:03 volumio volumio[2289]: assert.ok(self.idling) Feb 26 13:27:03 volumio volumio[2289]: error: The expression evaluated to a falsy value: Feb 26 13:27:03 volumio volumio[2289]: assert.ok(self.idling) Feb 26 13:27:03 volumio volumio[2289]: info: MPD running with PID2652 Feb 26 13:27:03 volumio volumio[2289]: ,establishing connection Feb 26 13:27:03 volumio volumio[2289]: error: updateQueue error: null Feb 26 13:27:03 volumio volumio[2289]: error: updateQueue error: null Feb 26 13:27:04 volumio volumio[2289]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 26 13:27:04 volumio sudo[2743]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 26 13:27:04 volumio sudo[2743]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:04 volumio sudo[2743]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:04 volumio kernel: hwmon hwmon1: Voltage normalised Feb 26 13:27:04 volumio volumio[2289]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 26 13:27:04 volumio sudo[2747]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 26 13:27:04 volumio sudo[2747]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:04 volumio sudo[2747]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:05 volumio volumio[2289]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 26 13:27:05 volumio sudo[2750]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 26 13:27:05 volumio sudo[2750]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:05 volumio sudo[2750]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:06 volumio volumio[2289]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 26 13:27:06 volumio sudo[2753]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 26 13:27:06 volumio sudo[2753]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:06 volumio sudo[2753]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Feb 26 13:27:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:27:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:27:06 volumio go-librespot[2755]: go-librespot daemon starting... Feb 26 13:27:06 volumio go-librespot[2756]: time="2026-02-26T13:27:06-06:00" level=info msg="running go-librespot 0.4.0" Feb 26 13:27:06 volumio go-librespot[2756]: time="2026-02-26T13:27:06-06:00" level=debug msg="app state loaded" Feb 26 13:27:06 volumio go-librespot[2756]: time="2026-02-26T13:27:06-06:00" level=debug msg="stored credentials not found" Feb 26 13:27:06 volumio go-librespot[2756]: time="2026-02-26T13:27:06-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 13:27:06 volumio volumio[2289]: info: Initializing connection to go-librespot Websocket Feb 26 13:27:06 volumio go-librespot[2756]: time="2026-02-26T13:27:06-06:00" level=debug msg="new websocket client" Feb 26 13:27:06 volumio volumio[2289]: info: Connection to go-librespot Websocket established Feb 26 13:27:06 volumio volumio[2289]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 26 13:27:06 volumio sudo[2764]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 26 13:27:06 volumio sudo[2764]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:06 volumio go-librespot[2756]: time="2026-02-26T13:27:06-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 26 13:27:06 volumio go-librespot[2756]: time="2026-02-26T13:27:06-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]" Feb 26 13:27:06 volumio go-librespot[2756]: time="2026-02-26T13:27:06-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]" Feb 26 13:27:06 volumio sudo[2764]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:06 volumio go-librespot[2756]: time="2026-02-26T13:27:06-06:00" level=info msg="zeroconf server listening on port 42699" Feb 26 13:27:06 volumio volumio[2289]: info: Completed starting Core Plugins Feb 26 13:27:06 volumio volumio[2289]: info: ------------------------------------------- Feb 26 13:27:06 volumio volumio[2289]: info: ----- MyVolumio plugins startup ---- Feb 26 13:27:06 volumio volumio[2289]: info: ------------------------------------------- Feb 26 13:27:06 volumio volumio[2289]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 26 13:27:06 volumio sudo[2767]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 26 13:27:06 volumio sudo[2767]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:06 volumio sudo[2769]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 26 13:27:06 volumio sudo[2769]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:06 volumio sudo[2771]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 26 13:27:06 volumio sudo[2771]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:06 volumio go-librespot[2756]: time="2026-02-26T13:27:06-06:00" level=debug msg="obtained new client token: AAAPttGRV+FnNuyn7bwrnviYFoApiqN1JPBBkwPWnscpVaevXCnvJpMeIj5VwVJ5bXgD3JkQW/GEjurelw/Dtv8prbpCe87bh3TJDmXBpOHm/MGMTgcXlBmQvqYprPtRAIHLwsf1lM//EFDl7N8YqgdKNEggOCeRiwE4AHuk5c2KF1z2X176BU7ZIYT3T15L0GnMQja/pYl9knJbL49ldYomcl4w/ptNNMCGSS1K3DOdnF/ljigBZBz/HQ==" Feb 26 13:27:06 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 26 13:27:06 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 26 13:27:06 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 26 13:27:06 volumio go-librespot[2756]: time="2026-02-26T13:27:06-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 26 13:27:06 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 26 13:27:06 volumio go-librespot[2756]: time="2026-02-26T13:27:06-06:00" level=debug msg="completed keyexchange" Feb 26 13:27:06 volumio go-librespot[2756]: time="2026-02-26T13:27:06-06:00" level=debug msg="completed challenge" Feb 26 13:27:06 volumio mpd_monitor.sh[2775]: MPD Monitor Service: Starting MPD Monitor Service Feb 26 13:27:06 volumio sudo[2771]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:06 volumio sudo[2769]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:06 volumio sudo[2767]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:06 volumio volumio[2289]: info: Successfully started MPD Monitor Feb 26 13:27:06 volumio volumio[2289]: info: Successfully started MPD Monitor Feb 26 13:27:06 volumio volumio[2289]: info: Successfully started MPD Monitor Feb 26 13:27:06 volumio go-librespot[2756]: time="2026-02-26T13:27:06-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 " Feb 26 13:27:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 13:27:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 13:27:07 volumio volumio[2289]: info: Connection to go-librespot Websocket closed Feb 26 13:27:09 volumio volumio[2289]: info: Getting Spotify volume Feb 26 13:27:09 volumio volumio[2289]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 26 13:27:09 volumio volumio[2289]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 13:27:09 volumio volumio[2289]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 26 13:27:09 volumio volumio[2289]: errno: -111, Feb 26 13:27:09 volumio volumio[2289]: code: 'ECONNREFUSED', Feb 26 13:27:09 volumio volumio[2289]: syscall: 'connect', Feb 26 13:27:09 volumio volumio[2289]: address: '127.0.0.1', Feb 26 13:27:09 volumio volumio[2289]: port: 9879, Feb 26 13:27:09 volumio volumio[2289]: response: undefined Feb 26 13:27:09 volumio volumio[2289]: } Feb 26 13:27:09 volumio volumio[2289]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 26 13:27:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Feb 26 13:27:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:27:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:27:10 volumio go-librespot[2792]: go-librespot daemon starting... Feb 26 13:27:10 volumio go-librespot[2793]: time="2026-02-26T13:27:10-06:00" level=info msg="running go-librespot 0.4.0" Feb 26 13:27:10 volumio go-librespot[2793]: time="2026-02-26T13:27:10-06:00" level=debug msg="app state loaded" Feb 26 13:27:10 volumio go-librespot[2793]: time="2026-02-26T13:27:10-06:00" level=debug msg="stored credentials not found" Feb 26 13:27:10 volumio go-librespot[2793]: time="2026-02-26T13:27:10-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 13:27:10 volumio sudo[2803]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-26 13:26' Feb 26 13:27:10 volumio sudo[2803]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:10 volumio go-librespot[2793]: time="2026-02-26T13:27:10-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 26 13:27:10 volumio go-librespot[2793]: time="2026-02-26T13:27:10-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]" Feb 26 13:27:10 volumio go-librespot[2793]: time="2026-02-26T13:27:10-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]" Feb 26 13:27:10 volumio go-librespot[2793]: time="2026-02-26T13:27:10-06:00" level=info msg="zeroconf server listening on port 42187" Feb 26 13:27:10 volumio sudo[2803]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:10 volumio go-librespot[2793]: time="2026-02-26T13:27:10-06:00" level=debug msg="obtained new client token: AABf2NmzCxHpApGyu+oOp3bMLKSk184fOzKkmVAzgFFqvM5xVNJe1Sma2o2LppJyv0cGi1XjpnCxQPiTAO4E4lLWujAe2WNqcCIK+55wbkNG2iVUr+q3lOrj6VaAcBJ1aTpyBQem64xnmJQI6vLe68mvvtCSkZqEGu5chyF0gKIfrPdbvJ3hxnWa1q1/gfyorL0pSdDMiS7MswfEfXNxZRlxfDJ+EXwiisixLlyX9l5NWnqqbwyWCge/Ag==" Feb 26 13:27:10 volumio go-librespot[2793]: time="2026-02-26T13:27:10-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 26 13:27:10 volumio volumio-remote-updater[13697]: [2026-02-26 13:27:10] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 26 13:27:10 volumio volumio-remote-updater[13697]: [2026-02-26 13:27:10] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 26 13:27:10 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 26 13:27:10 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 26 13:27:10 volumio systemd[1]: volumio.service: Consumed 39.081s CPU time. Feb 26 13:27:10 volumio go-librespot[2793]: time="2026-02-26T13:27:10-06:00" level=debug msg="completed keyexchange" Feb 26 13:27:10 volumio go-librespot[2793]: time="2026-02-26T13:27:10-06:00" level=debug msg="completed challenge" Feb 26 13:27:10 volumio go-librespot[2793]: time="2026-02-26T13:27:10-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 " Feb 26 13:27:10 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 26 13:27:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 13:27:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 13:27:10 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 26 13:27:11 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 6503. Feb 26 13:27:11 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 26 13:27:11 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 26 13:27:11 volumio systemd[1]: volumio.service: Consumed 39.081s CPU time. Feb 26 13:27:11 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 26 13:27:11 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 26 13:27:13 volumio volumio[2825]: info: ------------------------------------------- Feb 26 13:27:13 volumio volumio[2825]: info: ----- Volumio3 ---- Feb 26 13:27:13 volumio volumio[2825]: info: ------------------------------------------- Feb 26 13:27:13 volumio volumio[2825]: info: ----- System startup ---- Feb 26 13:27:13 volumio volumio[2825]: info: ------------------------------------------- Feb 26 13:27:13 volumio volumio[2825]: info: MYVOLUMIO Environment detected Feb 26 13:27:13 volumio volumio[2825]: info: Plugin folders cleanup Feb 26 13:27:13 volumio volumio[2825]: info: Scanning into folder /volumio/app/plugins/ Feb 26 13:27:13 volumio volumio[2825]: info: Scanning category audio_interface Feb 26 13:27:13 volumio volumio[2825]: info: Scanning category miscellanea Feb 26 13:27:13 volumio volumio[2825]: info: Scanning category music_service Feb 26 13:27:13 volumio volumio[2825]: info: Scanning category plugins.json Feb 26 13:27:13 volumio volumio[2825]: info: Scanning category system_controller Feb 26 13:27:13 volumio volumio[2825]: info: Scanning category user_interface Feb 26 13:27:13 volumio volumio[2825]: info: Scanning into folder /data/plugins/ Feb 26 13:27:13 volumio volumio[2825]: info: Scanning category audio_interface Feb 26 13:27:13 volumio volumio[2825]: info: Scanning category music_service Feb 26 13:27:14 volumio volumio[2825]: info: Scanning category system_controller Feb 26 13:27:14 volumio volumio[2825]: info: Scanning category system_hardware Feb 26 13:27:14 volumio volumio[2825]: info: Scanning category user_interface Feb 26 13:27:14 volumio volumio[2825]: info: Plugin folders cleanup completed Feb 26 13:27:14 volumio volumio[2825]: info: ------------------------------------------- Feb 26 13:27:14 volumio volumio[2825]: info: ----- Core plugins startup ---- Feb 26 13:27:14 volumio volumio[2825]: info: ------------------------------------------- Feb 26 13:27:14 volumio volumio[2825]: info: Loading plugins from folder /volumio/app/plugins/ Feb 26 13:27:14 volumio volumio[2825]: info: Adding plugin upnp to MyMusic Plugins Feb 26 13:27:14 volumio volumio[2825]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 26 13:27:14 volumio volumio[2825]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 26 13:27:14 volumio volumio[2825]: info: Loading plugins from folder /data/plugins/ Feb 26 13:27:14 volumio volumio[2825]: info: Loading plugin "system"... Feb 26 13:27:14 volumio volumio[2825]: info: Loading plugin "appearance"... Feb 26 13:27:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Feb 26 13:27:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:27:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:27:14 volumio go-librespot[2852]: go-librespot daemon starting... Feb 26 13:27:14 volumio go-librespot[2853]: time="2026-02-26T13:27:14-06:00" level=info msg="running go-librespot 0.4.0" Feb 26 13:27:14 volumio go-librespot[2853]: time="2026-02-26T13:27:14-06:00" level=debug msg="app state loaded" Feb 26 13:27:14 volumio go-librespot[2853]: time="2026-02-26T13:27:14-06:00" level=debug msg="stored credentials not found" Feb 26 13:27:14 volumio go-librespot[2853]: time="2026-02-26T13:27:14-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 13:27:14 volumio go-librespot[2853]: time="2026-02-26T13:27:14-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 26 13:27:14 volumio go-librespot[2853]: time="2026-02-26T13:27:14-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]" Feb 26 13:27:14 volumio go-librespot[2853]: time="2026-02-26T13:27:14-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]" Feb 26 13:27:14 volumio go-librespot[2853]: time="2026-02-26T13:27:14-06:00" level=info msg="zeroconf server listening on port 33961" Feb 26 13:27:14 volumio go-librespot[2853]: time="2026-02-26T13:27:14-06:00" level=debug msg="obtained new client token: AABzWsoD67y+OdEEfifoRCbfsfCokGeemyJBj6u8qpCeqL/DdX+V6ectmrZadi557mrbmpmwiwf3PG9YAIyrPUxQF7MDG3+Jf1AUPSKG4eJeCEXBm6ri7uYTj7i8lZzIbfP5FjzT1jUA235+p6XOXXg1pQIVtOLw2vj/IMONvUJ5UKDFfrvPoFUKmdWi+WgqJD+8VnP93ize+Zmf5dvHwXjwojqHf83+dno00mI7b0B4DCNSP1TDf6yUyA==" Feb 26 13:27:14 volumio go-librespot[2853]: time="2026-02-26T13:27:14-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 26 13:27:14 volumio go-librespot[2853]: time="2026-02-26T13:27:14-06:00" level=debug msg="completed keyexchange" Feb 26 13:27:14 volumio go-librespot[2853]: time="2026-02-26T13:27:14-06:00" level=debug msg="completed challenge" Feb 26 13:27:14 volumio go-librespot[2853]: time="2026-02-26T13:27:14-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 " Feb 26 13:27:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 13:27:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 13:27:15 volumio volumio[2825]: info: Loading plugin "network"... Feb 26 13:27:15 volumio volumio[2825]: info: Refreshing Cached IP Addresses Feb 26 13:27:15 volumio sudo[2861]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 26 13:27:15 volumio sudo[2861]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:15 volumio sudo[2863]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 26 13:27:15 volumio sudo[2863]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:15 volumio sudo[2863]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:15 volumio sudo[2861]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:15 volumio volumio[2825]: info: Loading plugin "services"... Feb 26 13:27:15 volumio volumio[2825]: info: Loading plugin "alsa_controller"... Feb 26 13:27:15 volumio sudo[2871]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 26 13:27:15 volumio sudo[2871]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:15 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 26 13:27:15 volumio volumio[2825]: info: Loading plugin "wizard"... Feb 26 13:27:15 volumio volumio[2825]: info: Loading plugin "networkfs"... Feb 26 13:27:15 volumio volumio[2825]: info: Starting Udev Watcher for removable devices Feb 26 13:27:15 volumio volumio[2825]: info: Ignoring mount for partition: boot Feb 26 13:27:15 volumio volumio[2825]: info: Ignoring mount for partition: volumio Feb 26 13:27:15 volumio volumio[2825]: info: Ignoring mount for partition: volumio_data Feb 26 13:27:15 volumio volumio[2825]: info: Mounting Device Wikipedia Feb 26 13:27:15 volumio sudo[2900]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Feb 26 13:27:15 volumio sudo[2900]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:15 volumio sudo[2900]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:15 volumio volumio[2825]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Feb 26 13:27:15 volumio volumio[2825]: dmesg(1) may have more information after failed mount system call. Feb 26 13:27:15 volumio volumio[2825]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Feb 26 13:27:15 volumio volumio[2825]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Feb 26 13:27:15 volumio volumio[2825]: dmesg(1) may have more information after failed mount system call. Feb 26 13:27:15 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 26 13:27:15 volumio volumio[2825]: info: Loading plugin "volumio_command_line_client"... Feb 26 13:27:15 volumio volumio[2825]: info: Loading plugin "upnp"... Feb 26 13:27:15 volumio volumio[2825]: info: [1772134035642] Starting Upmpd Daemon Feb 26 13:27:15 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 26 13:27:15 volumio volumio[2825]: info: Loading plugin "my_music"... Feb 26 13:27:15 volumio volumio[2825]: info: Loading plugin "mpd"... Feb 26 13:27:15 volumio volumio-remote-updater[13697]: [2026-02-26 13:27:15] [connect] Successful connection Feb 26 13:27:15 volumio sudo[2871]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:16 volumio volumio[2825]: info: Loading plugin "upnp_browser"... Feb 26 13:27:16 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 26 13:27:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Feb 26 13:27:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:27:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:27:17 volumio go-librespot[2904]: go-librespot daemon starting... Feb 26 13:27:18 volumio go-librespot[2905]: time="2026-02-26T13:27:18-06:00" level=info msg="running go-librespot 0.4.0" Feb 26 13:27:18 volumio go-librespot[2905]: time="2026-02-26T13:27:18-06:00" level=debug msg="app state loaded" Feb 26 13:27:18 volumio go-librespot[2905]: time="2026-02-26T13:27:18-06:00" level=debug msg="stored credentials not found" Feb 26 13:27:18 volumio go-librespot[2905]: time="2026-02-26T13:27:18-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 13:27:18 volumio go-librespot[2905]: time="2026-02-26T13:27:18-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]" Feb 26 13:27:18 volumio go-librespot[2905]: time="2026-02-26T13:27:18-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]" Feb 26 13:27:18 volumio go-librespot[2905]: time="2026-02-26T13:27:18-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]" Feb 26 13:27:18 volumio go-librespot[2905]: time="2026-02-26T13:27:18-06:00" level=info msg="zeroconf server listening on port 40811" Feb 26 13:27:18 volumio go-librespot[2905]: time="2026-02-26T13:27:18-06:00" level=debug msg="obtained new client token: AACta96bFYwg9WPrgQrvqBQh8dqD6LIoQVpyJBLlo2L6cW0IB+SjiHMOSKyIxIFAzgVxJJi5lzDIQhVHounqFgF7R7bb0q/deTA6l++3sObxvboDyD0KW64YA2eUpQpXnT1EIKQZepOzLIb6j8uFLyUlPiIdX5dLratHaDyCBnNVi1arHl/cK/8Ctj9VrthelubRYwRXr4eeBn4Jsv/5prahahJCOZSU0iAfcm0cEm2xP/sV82lU2CZGEA==" Feb 26 13:27:18 volumio go-librespot[2905]: time="2026-02-26T13:27:18-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 26 13:27:18 volumio go-librespot[2905]: time="2026-02-26T13:27:18-06:00" level=debug msg="completed keyexchange" Feb 26 13:27:18 volumio go-librespot[2905]: time="2026-02-26T13:27:18-06:00" level=debug msg="completed challenge" Feb 26 13:27:18 volumio go-librespot[2905]: time="2026-02-26T13:27:18-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 " Feb 26 13:27:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 13:27:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 13:27:18 volumio volumio[2825]: info: Loading plugin "alarm-clock"... Feb 26 13:27:19 volumio volumio[2825]: info: Loading plugin "airplay_emulation"... Feb 26 13:27:19 volumio volumio[2825]: info: Starting Shairport Sync Feb 26 13:27:19 volumio volumio[2825]: info: Loading plugin "last_100"... Feb 26 13:27:19 volumio volumio[2825]: info: Loading plugin "webradio"... Feb 26 13:27:19 volumio volumio[2825]: info: Loading plugin "i2s_dacs"... Feb 26 13:27:19 volumio volumio[2825]: info: I2S DAC not set, start Auto-detection Feb 26 13:27:19 volumio volumio[2825]: info: Loading plugin "volumiodiscovery"... Feb 26 13:27:19 volumio volumio[2825]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 26 13:27:19 volumio volumio[2825]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 26 13:27:19 volumio volumio[2825]: *** WARNING *** For more information see Feb 26 13:27:19 volumio volumio[2825]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 26 13:27:19 volumio volumio[2825]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 26 13:27:19 volumio volumio[2825]: *** WARNING *** For more information see Feb 26 13:27:19 volumio node[2825]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 26 13:27:19 volumio node[2825]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 26 13:27:19 volumio node[2825]: *** WARNING *** For more information see Feb 26 13:27:19 volumio node[2825]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 26 13:27:19 volumio node[2825]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 26 13:27:19 volumio node[2825]: *** WARNING *** For more information see Feb 26 13:27:19 volumio volumio[2825]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 26 13:27:19 volumio volumio[2825]: info: Discovery: Started advertising with name: Volumio Feb 26 13:27:19 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 26 13:27:19 volumio volumio[2825]: info: Loading plugin "bandcamp"... Feb 26 13:27:20 volumio volumio[2825]: info: Plugin calmradio is not enabled Feb 26 13:27:20 volumio volumio[2825]: info: Loading plugin "soundcloud"... Feb 26 13:27:20 volumio volumio[2825]: info: Loading plugin "spop"... Feb 26 13:27:21 volumio kernel: hwmon hwmon1: Voltage normalised Feb 26 13:27:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Feb 26 13:27:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:27:21 volumio volumio[2825]: info: Loading plugin "squeezelite_mc"... Feb 26 13:27:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:27:21 volumio go-librespot[2916]: go-librespot daemon starting... Feb 26 13:27:22 volumio go-librespot[2917]: time="2026-02-26T13:27:22-06:00" level=info msg="running go-librespot 0.4.0" Feb 26 13:27:22 volumio go-librespot[2917]: time="2026-02-26T13:27:22-06:00" level=debug msg="app state loaded" Feb 26 13:27:22 volumio go-librespot[2917]: time="2026-02-26T13:27:22-06:00" level=debug msg="stored credentials not found" Feb 26 13:27:22 volumio go-librespot[2917]: time="2026-02-26T13:27:22-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 13:27:22 volumio go-librespot[2917]: time="2026-02-26T13:27:22-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 26 13:27:22 volumio go-librespot[2917]: time="2026-02-26T13:27:22-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]" Feb 26 13:27:22 volumio go-librespot[2917]: time="2026-02-26T13:27:22-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]" Feb 26 13:27:22 volumio go-librespot[2917]: time="2026-02-26T13:27:22-06:00" level=info msg="zeroconf server listening on port 43611" Feb 26 13:27:22 volumio go-librespot[2917]: time="2026-02-26T13:27:22-06:00" level=debug msg="obtained new client token: AAB4gNSwkXjZmmiIV7oHVoX3s2QdKHdLaxGZlUSk2yyIPCREx9IxT3ho3RBsucSMUMCj72uUvGei6rminvpH1O1jU9wdzg+SMq9PpR2aPmqgwWWKA+6kKv3zsvtKfkJznfv6RSlwLOuLE5deBg8mID9Dkca809fcI6o7/D54kkKNzGkD+VBXbs8C0Y00xKWW2R027w3pudKXAsijBePLMU1NHBa+NDKX0c9rTOa3yCEVn/7ANhTM7c40lA==" Feb 26 13:27:22 volumio go-librespot[2917]: time="2026-02-26T13:27:22-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 26 13:27:22 volumio go-librespot[2917]: time="2026-02-26T13:27:22-06:00" level=debug msg="completed keyexchange" Feb 26 13:27:22 volumio go-librespot[2917]: time="2026-02-26T13:27:22-06:00" level=debug msg="completed challenge" Feb 26 13:27:22 volumio go-librespot[2917]: time="2026-02-26T13:27:22-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 13:27:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 13:27:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 13:27:22 volumio volumio[2825]: info: Loading plugin "youtube2"... Feb 26 13:27:23 volumio volumio[2825]: info: Loading plugin "ytcr"... Feb 26 13:27:24 volumio volumio[2825]: info: Loading plugin "ytmusic"... Feb 26 13:27:25 volumio volumio[2825]: info: Plugin now_playing is not enabled Feb 26 13:27:25 volumio volumio[2825]: info: Loading plugin "outputs"... Feb 26 13:27:25 volumio volumio[2825]: info: Loading plugin "albumart"... Feb 26 13:27:25 volumio volumio[2825]: info: Plugin example_plugin is not enabled Feb 26 13:27:25 volumio volumio[2825]: info: Loading plugin "inputs"... Feb 26 13:27:25 volumio volumio[2825]: info: Loading plugin "updater_comm"... Feb 26 13:27:25 volumio volumio[2825]: info: Plugin mpdemulation is not enabled Feb 26 13:27:25 volumio volumio[2825]: info: Loading plugin "rest_api"... Feb 26 13:27:25 volumio volumio[2825]: info: Loading plugin "websocket"... Feb 26 13:27:25 volumio volumio[2825]: info: Starting Socket.io Server version 1.7.4 Feb 26 13:27:25 volumio volumio[2825]: info: Plugin fusiondsp is not enabled Feb 26 13:27:25 volumio volumio[2825]: info: Plugin mpdoutput is not enabled Feb 26 13:27:25 volumio volumio[2825]: info: Plugin RoonBridge is not enabled Feb 26 13:27:25 volumio volumio[2825]: info: Loading plugin "podcast"... Feb 26 13:27:25 volumio volumio[2825]: info: ControllerPodcast::constructor Feb 26 13:27:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Feb 26 13:27:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:27:25 volumio volumio[2825]: info: Loading plugin "volusonic"... Feb 26 13:27:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:27:25 volumio go-librespot[2948]: go-librespot daemon starting... Feb 26 13:27:25 volumio go-librespot[2949]: time="2026-02-26T13:27:25-06:00" level=info msg="running go-librespot 0.4.0" Feb 26 13:27:25 volumio go-librespot[2949]: time="2026-02-26T13:27:25-06:00" level=debug msg="app state loaded" Feb 26 13:27:25 volumio go-librespot[2949]: time="2026-02-26T13:27:25-06:00" level=debug msg="stored credentials not found" Feb 26 13:27:25 volumio volumio[2924]: Forking 3 albumart workers Feb 26 13:27:25 volumio go-librespot[2949]: time="2026-02-26T13:27:25-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 13:27:26 volumio go-librespot[2949]: time="2026-02-26T13:27:26-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]" Feb 26 13:27:26 volumio go-librespot[2949]: time="2026-02-26T13:27:26-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]" Feb 26 13:27:26 volumio go-librespot[2949]: time="2026-02-26T13:27:26-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]" Feb 26 13:27:26 volumio go-librespot[2949]: time="2026-02-26T13:27:26-06:00" level=info msg="zeroconf server listening on port 40313" Feb 26 13:27:26 volumio go-librespot[2949]: time="2026-02-26T13:27:26-06:00" level=debug msg="obtained new client token: AAANLIIcvpLfL63tK506kmOC/JTmhLSBh/VFTN2CQOcrbs767YZ51NOd6/oQ5mFSBWxnDnm+PGBtjkH7P0i09FkItYKUsouJrkU2K51QyhNTlddpVsFmeSSAoBi92c9LIs4cwyhcZMIID9+pF3IZEV2ytwUexl9hHTg2LNr/FNj40OCz2pzsQQDhjjcKFnm5bZFnPF1h9/3nn5rTIOJJWqLujeiED0YKksijIvtBHJStuQp+G+dQqYs=" Feb 26 13:27:26 volumio go-librespot[2949]: time="2026-02-26T13:27:26-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 26 13:27:26 volumio go-librespot[2949]: time="2026-02-26T13:27:26-06:00" level=debug msg="completed keyexchange" Feb 26 13:27:26 volumio go-librespot[2949]: time="2026-02-26T13:27:26-06:00" level=debug msg="completed challenge" Feb 26 13:27:26 volumio go-librespot[2949]: time="2026-02-26T13:27:26-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 " Feb 26 13:27:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 13:27:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 13:27:27 volumio volumio[2825]: info: Applying required configuration parameters for plugin volusonic Feb 26 13:27:27 volumio volumio[2825]: info: Loading plugin "backup_restore"... Feb 26 13:27:27 volumio volumio[2958]: Starting albumart workers Feb 26 13:27:27 volumio volumio[2957]: Starting albumart workers Feb 26 13:27:27 volumio volumio[2956]: Starting albumart workers Feb 26 13:27:27 volumio volumio[2825]: info: Applying required configuration parameters for plugin backup_restore Feb 26 13:27:27 volumio volumio[2825]: info: Plugin rpi_eeprom_config is not enabled Feb 26 13:27:27 volumio volumio[2825]: info: Plugin rpi_eeprom_updater is not enabled Feb 26 13:27:27 volumio volumio[2825]: info: Loading plugin "scheduledrestart"... Feb 26 13:27:27 volumio volumio[2825]: info: Applying required configuration parameters for plugin scheduledrestart Feb 26 13:27:27 volumio volumio[2825]: info: Plugin Bluetoothremote is not enabled Feb 26 13:27:27 volumio volumio[2825]: info: Plugin music_services_shield is not enabled Feb 26 13:27:27 volumio volumio[2825]: info: Loading plugin "Systeminfo"... Feb 26 13:27:28 volumio volumio-remote-updater[13697]: [2026-02-26 13:27:28] [connect] Successful connection Feb 26 13:27:28 volumio volumio[2825]: info: Plugin peppymeterbasic is not enabled Feb 26 13:27:28 volumio volumio[2825]: info: Loading plugin "peppyspectrum"... Feb 26 13:27:28 volumio volumio[2825]: info: Loading i18n strings for locale en Feb 26 13:27:28 volumio volumio[2825]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Feb 26 13:27:28 volumio volumio[2825]: Updating browse sources language Feb 26 13:27:28 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 13:27:28 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 13:27:28 volumio volumio[2825]: info: CoreCommandRouter::initPlayerControls Feb 26 13:27:28 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:28 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:28 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:28 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:28 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:28 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:28 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:28 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:28 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 13:27:28 volumio volumio[2825]: Express server listening on port 3000 Feb 26 13:27:28 volumio volumio[2825]: [Metrics] WebUI: 16s 264.94ms Feb 26 13:27:28 volumio volumio[2825]: info: CoreStateMachine::resetVolumioState Feb 26 13:27:28 volumio volumio[2825]: info: CoreStateMachine::getcurrentVolume Feb 26 13:27:28 volumio volumio[2825]: info: CoreCommandRouter::volumioRetrievevolume Feb 26 13:27:28 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 13:27:28 volumio sudo[3012]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 26 13:27:28 volumio sudo[3012]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:28 volumio sudo[3012]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:28 volumio sudo[3014]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 26 13:27:28 volumio sudo[3014]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:29 volumio sudo[3014]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:29 volumio volumio[2825]: info: Volumio Network Manager: Network status updated: 1 Feb 26 13:27:29 volumio volumio[2825]: info: VolumeController:: Volume=100 Mute =false Feb 26 13:27:29 volumio volumio[2825]: info: CoreStateMachine::pushState Feb 26 13:27:29 volumio volumio[2825]: info: CorePlayQueue::getTrack 0 Feb 26 13:27:29 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 13:27:29 volumio volumio[2825]: info: CoreCommandRouter::volumioPushState Feb 26 13:27:29 volumio volumio[2825]: info: CoreStateMachine::updateTrackBlock Feb 26 13:27:29 volumio volumio[2825]: info: CorePlayQueue::getTrackBlock Feb 26 13:27:29 volumio volumio[2825]: info: CoreCommandRouter::volumioRetrievevolume Feb 26 13:27:29 volumio volumio-remote-updater[13697]: [2026-02-26 13:27:29] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1772134048 101 Feb 26 13:27:29 volumio volumio[2825]: 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 Feb 26 13:27:29 volumio volumio[2825]: info: Reloading queue from file Feb 26 13:27:29 volumio volumio[2825]: info: CoreStateMachine::setRepeat null single undefined Feb 26 13:27:29 volumio volumio[2825]: info: CoreStateMachine::pushState Feb 26 13:27:29 volumio volumio[2825]: info: CorePlayQueue::getTrack 0 Feb 26 13:27:29 volumio volumio[2825]: info: CoreCommandRouter::volumioPushState Feb 26 13:27:29 volumio volumio[2825]: info: CoreStateMachine::setRandom null Feb 26 13:27:29 volumio volumio[2825]: info: CoreStateMachine::pushState Feb 26 13:27:29 volumio volumio[2825]: info: CorePlayQueue::getTrack 0 Feb 26 13:27:29 volumio volumio[2825]: info: CoreCommandRouter::volumioPushState Feb 26 13:27:29 volumio volumio[2825]: info: Setting Device type: Raspberry PI Feb 26 13:27:29 volumio volumio[2825]: info: VolumeController:: Volume=100 Mute =false Feb 26 13:27:29 volumio volumio[2825]: info: CoreStateMachine::pushState Feb 26 13:27:29 volumio volumio[2825]: info: CorePlayQueue::getTrack 0 Feb 26 13:27:29 volumio volumio[2825]: info: CoreCommandRouter::volumioPushState Feb 26 13:27:29 volumio volumio[2825]: info: Completed loading Core Plugins Feb 26 13:27:29 volumio volumio[2825]: info: Preparing to generate the ALSA configuration file Feb 26 13:27:29 volumio sudo[3028]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 26 13:27:29 volumio sudo[3028]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:29 volumio volumio[2825]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Feb 26 13:27:29 volumio volumio[2825]: info: Discovery: Found device Volumio Feb 26 13:27:29 volumio volumio[2825]: info: CoreCommandRouter::volumioGetState Feb 26 13:27:29 volumio volumio[2825]: info: CorePlayQueue::getTrack 0 Feb 26 13:27:29 volumio volumio[2825]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Feb 26 13:27:29 volumio volumio[2825]: info: Reading ALSA contributions from plugins. Feb 26 13:27:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Feb 26 13:27:29 volumio volumio[2825]: info: Asound.conf file unchanged, so no further update is needed Feb 26 13:27:29 volumio volumio[2825]: info: Output device has changed, restarting MPD Feb 26 13:27:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:27:29 volumio volumio[2825]: info: Output device has changed, restarting Shairport Sync Feb 26 13:27:29 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:29 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 13:27:29 volumio sudo[3032]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 26 13:27:29 volumio sudo[3032]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:29 volumio sudo[3032]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:29 volumio sudo[3034]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 26 13:27:29 volumio sudo[3034]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:29 volumio volumio[2825]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 26 13:27:29 volumio volumio[2825]: info: ___________ START PLUGINS ___________ Feb 26 13:27:29 volumio volumio[2825]: info: ControllerMpd::onStart: Initializing MPD Feb 26 13:27:29 volumio volumio[2825]: info: Creating MPD Configuration file Feb 26 13:27:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:27:29 volumio go-librespot[3031]: go-librespot daemon starting... Feb 26 13:27:29 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 13:27:29 volumio volumio[2825]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 26 13:27:29 volumio volumio[2825]: info: [1772134049471] CoreMusicLibrary::Adding element Media Servers Feb 26 13:27:29 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 13:27:29 volumio sudo[3042]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 26 13:27:29 volumio sudo[3042]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:29 volumio sudo[3042]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:29 volumio sudo[3028]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:29 volumio sudo[3044]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 26 13:27:29 volumio go-librespot[3045]: time="2026-02-26T13:27:29-06:00" level=info msg="running go-librespot 0.4.0" Feb 26 13:27:29 volumio go-librespot[3045]: time="2026-02-26T13:27:29-06:00" level=debug msg="app state loaded" Feb 26 13:27:29 volumio go-librespot[3045]: time="2026-02-26T13:27:29-06:00" level=debug msg="stored credentials not found" Feb 26 13:27:29 volumio go-librespot[3045]: time="2026-02-26T13:27:29-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 13:27:29 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 26 13:27:29 volumio sudo[3044]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:29 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:29 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 13:27:29 volumio volumio[2825]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 26 13:27:29 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:29 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 13:27:29 volumio volumio[2825]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 26 13:27:29 volumio volumio[2825]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 26 13:27:29 volumio volumio[2825]: info: [1772134049632] CoreMusicLibrary::Adding element Last_100 Feb 26 13:27:29 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 13:27:29 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 26 13:27:29 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 26 13:27:29 volumio systemd[1]: mpd.service: Consumed 5.741s CPU time. Feb 26 13:27:29 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 26 13:27:29 volumio volumio[2825]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 26 13:27:29 volumio volumio[2825]: info: [1772134049637] CoreMusicLibrary::Adding element Webradio Feb 26 13:27:29 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 26 13:27:29 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 26 13:27:29 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 13:27:29 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 26 13:27:29 volumio volumio[2825]: info: Initializing BBC Radios Feb 26 13:27:29 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 26 13:27:29 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 26 13:27:29 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 26 13:27:29 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 13:27:29 volumio volumio[2825]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 26 13:27:29 volumio volumio[2825]: info: [1772134049744] CoreMusicLibrary::Adding element Bandcamp Discover Feb 26 13:27:29 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 13:27:29 volumio volumio[2825]: Cannot find translation for source Bandcamp Discover Feb 26 13:27:29 volumio volumio[2825]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 26 13:27:29 volumio volumio[2825]: info: [1772134049757] CoreMusicLibrary::Adding element SoundCloud Feb 26 13:27:29 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 13:27:29 volumio volumio[2825]: Cannot find translation for source Bandcamp Discover Feb 26 13:27:29 volumio volumio[2825]: Cannot find translation for source SoundCloud Feb 26 13:27:29 volumio volumio[2825]: info: Creating Spotify config file Feb 26 13:27:29 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:29 volumio go-librespot[3045]: time="2026-02-26T13:27:29-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]" Feb 26 13:27:29 volumio go-librespot[3045]: time="2026-02-26T13:27:29-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]" Feb 26 13:27:29 volumio go-librespot[3045]: time="2026-02-26T13:27:29-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]" Feb 26 13:27:29 volumio go-librespot[3045]: time="2026-02-26T13:27:29-06:00" level=info msg="zeroconf server listening on port 33293" Feb 26 13:27:29 volumio go-librespot[3045]: time="2026-02-26T13:27:29-06:00" level=debug msg="obtained new client token: AADL8P1DfVEp2IPjUAjMGiYcIuCsj23se+oY/Loq9iXCnuMupWl6SHM1GW5fKvDulVj27W6tf96xGLYK4l/x1tiLyKsXJEbQpagbbJrQT1aYutO0/oyiLI40rKCbrTnP9Eu2rBX9zKwPibxFEXAKvRlCAS0v9+2fAB893Tq58D+mN+05QQrT9DXdf6aDUv5ggoAjNcP38B8+eyWHXfkMnmyeZ4t+jmceWsSe/xCvQElQJNf8cqGPDaqFwg==" Feb 26 13:27:29 volumio sudo[3073]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 26 13:27:29 volumio sudo[3073]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 26 13:27:29 volumio sudo[3073]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:29 volumio go-librespot[3045]: time="2026-02-26T13:27:29-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 26 13:27:30 volumio go-librespot[3045]: time="2026-02-26T13:27:30-06:00" level=debug msg="completed keyexchange" Feb 26 13:27:30 volumio go-librespot[3045]: time="2026-02-26T13:27:30-06:00" level=debug msg="completed challenge" Feb 26 13:27:30 volumio go-librespot[3045]: time="2026-02-26T13:27:30-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 " Feb 26 13:27:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 13:27:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 13:27:30 volumio volumio[2825]: info: [squeezelite_mc] Starting proxy server... Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 26 13:27:30 volumio volumio[2825]: info: [1772134050148] CoreMusicLibrary::Adding element YouTube2 Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 13:27:30 volumio volumio[2825]: Cannot find translation for source Bandcamp Discover Feb 26 13:27:30 volumio volumio[2825]: Cannot find translation for source SoundCloud Feb 26 13:27:30 volumio volumio[2825]: Cannot find translation for source YouTube2 Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 26 13:27:30 volumio volumio[2825]: info: [1772134050167] CoreMusicLibrary::Adding element YouTube Music Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 13:27:30 volumio volumio[2825]: Cannot find translation for source Bandcamp Discover Feb 26 13:27:30 volumio volumio[2825]: Cannot find translation for source SoundCloud Feb 26 13:27:30 volumio volumio[2825]: Cannot find translation for source YouTube2 Feb 26 13:27:30 volumio volumio[2825]: Cannot find translation for source YouTube Music Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 26 13:27:30 volumio volumio[2825]: info: [1772134050179] CoreMusicLibrary::Adding element Podcast Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 13:27:30 volumio volumio[2825]: Cannot find translation for source Bandcamp Discover Feb 26 13:27:30 volumio volumio[2825]: Cannot find translation for source SoundCloud Feb 26 13:27:30 volumio volumio[2825]: Cannot find translation for source YouTube2 Feb 26 13:27:30 volumio volumio[2825]: Cannot find translation for source YouTube Music Feb 26 13:27:30 volumio volumio[2825]: Cannot find translation for source Podcast Feb 26 13:27:30 volumio volumio[2825]: info: Loading i18n strings for locale en Feb 26 13:27:30 volumio volumio[2825]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Feb 26 13:27:30 volumio volumio[2825]: Updating browse sources language Feb 26 13:27:30 volumio volumio[2825]: Cannot find translation for source Bandcamp Discover Feb 26 13:27:30 volumio volumio[2825]: Cannot find translation for source SoundCloud Feb 26 13:27:30 volumio volumio[2825]: Cannot find translation for source YouTube2 Feb 26 13:27:30 volumio volumio[2825]: Cannot find translation for source YouTube Music Feb 26 13:27:30 volumio volumio[2825]: Cannot find translation for source Podcast Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 13:27:30 volumio volumio[2825]: Cannot find translation for source Bandcamp Discover Feb 26 13:27:30 volumio volumio[2825]: Cannot find translation for source SoundCloud Feb 26 13:27:30 volumio volumio[2825]: Cannot find translation for source YouTube2 Feb 26 13:27:30 volumio volumio[2825]: Cannot find translation for source YouTube Music Feb 26 13:27:30 volumio volumio[2825]: Cannot find translation for source Podcast Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 26 13:27:30 volumio volumio[2825]: info: [1772134050228] CoreMusicLibrary::Adding element Volusonic Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 13:27:30 volumio volumio[2825]: Cannot find translation for source Bandcamp Discover Feb 26 13:27:30 volumio volumio[2825]: Cannot find translation for source SoundCloud Feb 26 13:27:30 volumio volumio[2825]: Cannot find translation for source YouTube2 Feb 26 13:27:30 volumio volumio[2825]: Cannot find translation for source YouTube Music Feb 26 13:27:30 volumio volumio[2825]: Cannot find translation for source Podcast Feb 26 13:27:30 volumio volumio[2825]: Cannot find translation for source Volusonic Feb 26 13:27:30 volumio volumio[2825]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Feb 26 13:27:30 volumio volumio[2825]: info: Volumio Calling Home Feb 26 13:27:30 volumio volumio[2825]: info: [squeezelite_mc] Proxy server started on port 43059 Feb 26 13:27:30 volumio volumio[2825]: info: Preparing to generate the ALSA configuration file Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::volumioRetrievevolume Feb 26 13:27:30 volumio volumio[2825]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Feb 26 13:27:30 volumio volumio[2825]: info: Discovery: Found device Volumio Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::volumioGetState Feb 26 13:27:30 volumio volumio[2825]: info: CorePlayQueue::getTrack 0 Feb 26 13:27:30 volumio volumio[2825]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Feb 26 13:27:30 volumio volumio[2825]: info: Reading ALSA contributions from plugins. Feb 26 13:27:30 volumio volumio[2825]: info: MPD Permissions set Feb 26 13:27:30 volumio volumio[2825]: info: MPD Permissions set Feb 26 13:27:30 volumio volumio[2825]: info: Upmpdcli Daemon Started Feb 26 13:27:30 volumio volumio[2825]: info: Spotify config file written Feb 26 13:27:30 volumio sudo[3088]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 26 13:27:30 volumio sudo[3088]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:27:30 volumio volumio[2825]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 26 13:27:30 volumio volumio[2825]: info: VolumeController:: Volume=100 Mute =false Feb 26 13:27:30 volumio volumio[2825]: info: CoreStateMachine::pushState Feb 26 13:27:30 volumio volumio[2825]: info: CorePlayQueue::getTrack 0 Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::volumioPushState Feb 26 13:27:30 volumio volumio[2825]: info: [squeezelite_mc] Server discovery started Feb 26 13:27:30 volumio volumio[2825]: info: [squeezelite_mc] Player finder started Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 13:27:30 volumio volumio[2825]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 13:27:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:30 volumio go-librespot[3090]: go-librespot daemon starting... Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:30 volumio sudo[3088]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 13:27:30 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:30 volumio go-librespot[3098]: time="2026-02-26T13:27:30-06:00" level=info msg="running go-librespot 0.4.0" Feb 26 13:27:30 volumio volumio[2825]: info: No need to fix Spotify hosts Feb 26 13:27:30 volumio go-librespot[3098]: time="2026-02-26T13:27:30-06:00" level=debug msg="app state loaded" Feb 26 13:27:30 volumio go-librespot[3098]: time="2026-02-26T13:27:30-06:00" level=debug msg="stored credentials not found" Feb 26 13:27:30 volumio go-librespot[3098]: time="2026-02-26T13:27:30-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 13:27:30 volumio volumio[2825]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 26 13:27:30 volumio volumio[2825]: info: Volumio called home Feb 26 13:27:31 volumio volumio[2825]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Feb 26 13:27:31 volumio volumio[2825]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Feb 26 13:27:31 volumio volumio[2825]: 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 Feb 26 13:27:31 volumio volumio[2825]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 26 13:27:31 volumio volumio[2825]: SPOTIFY: BQCpZu6_UkUz5wI3uam_MaFMNLWoz7e31XvEOiUa-UtcTBAMGgj0BNoB61W1a1RbgXaIKXih2OW8iMtup61ymPC2Qgv5FNIBfbavh3hLau98QFNwlOWo7p35lHj7StmNM616bVnG3KIZGfPrH2K4kjd6krK5NiNRs_X06EIeKGReHLbF-Gs9-k9gT2jLW2G5vxTzeNlAqGRHrPXrwDO1MHnk19i0ffg1sQ5lFO4 Feb 26 13:27:31 volumio volumio[2825]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 26 13:27:31 volumio volumio[2825]: info: New Spotify access token = BQCpZu6_UkUz5wI3uam_MaFMNLWoz7e31XvEOiUa-UtcTBAMGgj0BNoB61W1a1RbgXaIKXih2OW8iMtup61ymPC2Qgv5FNIBfbavh3hLau98QFNwlOWo7p35lHj7StmNM616bVnG3KIZGfPrH2K4kjd6krK5NiNRs_X06EIeKGReHLbF-Gs9-k9gT2jLW2G5vxTzeNlAqGRHrPXrwDO1MHnk19i0ffg1sQ5lFO4 Feb 26 13:27:31 volumio volumio[2825]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 26 13:27:31 volumio go-librespot[3098]: time="2026-02-26T13:27: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 26 13:27:31 volumio go-librespot[3098]: time="2026-02-26T13:27:31-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]" Feb 26 13:27:31 volumio go-librespot[3098]: time="2026-02-26T13:27:31-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]" Feb 26 13:27:31 volumio go-librespot[3098]: time="2026-02-26T13:27:31-06:00" level=info msg="zeroconf server listening on port 33501" Feb 26 13:27:31 volumio sudo[3112]: 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 Feb 26 13:27:31 volumio sudo[3112]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:31 volumio volumio[2825]: info: Starting Shairport Sync Feb 26 13:27:31 volumio sudo[3112]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:31 volumio volumio[2825]: info: Starting Shairport Sync Feb 26 13:27:31 volumio volumio[2825]: info: Starting Shairport Sync Feb 26 13:27:31 volumio sudo[3115]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 26 13:27:31 volumio sudo[3115]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:31 volumio sudo[3117]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 26 13:27:31 volumio sudo[3117]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:31 volumio go-librespot[3098]: time="2026-02-26T13:27:31-06:00" level=debug msg="obtained new client token: AABtlwiGfD+OrC0ng7C6AGrXOVLsnQn4TpYkqN+a85DxCQ0v1GiLBMwDcAY+Wcn36ZlvUUmO9pnkRpp0JsBY8SEQGDx/Eh+LpAIriBqTLhtD8J9MHph/p8yQnGvliVNXVeQNr+i/hL1jijtz2iwNdZNI0yJlIfJ2w/R4Qb4G0y6ZH8tXMZyPMCDZHRJ3UZmO/lrgnwoJpp5xJRm+GGPwJSSr24nzU/3NzzmNJtxXaFDQ3pritDHyy9g=" Feb 26 13:27:31 volumio sudo[3119]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 26 13:27:31 volumio sudo[3119]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:31 volumio go-librespot[3098]: time="2026-02-26T13:27:31-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 26 13:27:31 volumio volumio[2825]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Feb 26 13:27:31 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 26 13:27:31 volumio volumio[2825]: info: Asound.conf file unchanged, so no further update is needed Feb 26 13:27:31 volumio volumio[2825]: info: Output device has changed, restarting MPD Feb 26 13:27:31 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 26 13:27:31 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 26 13:27:31 volumio systemd[1]: shairport-sync.service: Consumed 1.925s CPU time. Feb 26 13:27:31 volumio go-librespot[3098]: time="2026-02-26T13:27:31-06:00" level=debug msg="completed keyexchange" Feb 26 13:27:31 volumio go-librespot[3098]: time="2026-02-26T13:27:31-06:00" level=debug msg="completed challenge" Feb 26 13:27:31 volumio sudo[3125]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Feb 26 13:27:31 volumio sudo[3125]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:31 volumio volumio[2825]: info: Output device has changed, restarting Shairport Sync Feb 26 13:27:31 volumio sudo[3127]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 26 13:27:31 volumio sudo[3127]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:31 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:31 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 13:27:31 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 26 13:27:31 volumio go-librespot[3098]: time="2026-02-26T13:27: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 " Feb 26 13:27:31 volumio sudo[3125]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:31 volumio sudo[3117]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:31 volumio sudo[3127]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:31 volumio sudo[3115]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 13:27:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 13:27:31 volumio sudo[3131]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 26 13:27:31 volumio sudo[3131]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:31 volumio sudo[3119]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:31 volumio volumio[2825]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 26 13:27:31 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 26 13:27:31 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 26 13:27:31 volumio systemd[1]: mpd.service: Consumed 1.689s CPU time. Feb 26 13:27:31 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 26 13:27:31 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 26 13:27:31 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 26 13:27:31 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 26 13:27:31 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 26 13:27:31 volumio volumio[2825]: info: MPD Permissions set Feb 26 13:27:31 volumio volumio[2825]: info: Shairport-Sync Started Feb 26 13:27:31 volumio volumio[2825]: Error adding Membership: Error: addMembership EINVAL Feb 26 13:27:31 volumio volumio[2825]: info: Shairport-Sync Started Feb 26 13:27:31 volumio volumio[2825]: info: Shairport-Sync Started Feb 26 13:27:31 volumio volumio[2825]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Feb 26 13:27:31 volumio sudo[3160]: 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 Feb 26 13:27:31 volumio sudo[3160]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:31 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:31 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:31 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:31 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:31 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:31 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:31 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:31 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:31 volumio sudo[3160]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:31 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 13:27:31 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:31 volumio volumio[2825]: info: CoreCommandRouter::volumioGetState Feb 26 13:27:31 volumio volumio[2825]: info: CorePlayQueue::getTrack 0 Feb 26 13:27:31 volumio volumio[2825]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Feb 26 13:27:31 volumio volumio[2825]: info: Starting Shairport Sync Feb 26 13:27:31 volumio sudo[3168]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Feb 26 13:27:31 volumio sudo[3168]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:31 volumio sudo[3157]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 26 13:27:31 volumio sudo[3170]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 26 13:27:31 volumio sudo[3157]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 26 13:27:31 volumio sudo[3170]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:31 volumio sudo[3157]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:31 volumio volumio[2825]: 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"} Feb 26 13:27:31 volumio volumio[2825]: info: Spotify Successfully logged in Feb 26 13:27:31 volumio volumio[2825]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 26 13:27:31 volumio volumio[2825]: info: [1772134051987] CoreMusicLibrary::Adding element Spotify Feb 26 13:27:31 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 13:27:31 volumio volumio[2825]: Cannot find translation for source Bandcamp Discover Feb 26 13:27:31 volumio volumio[2825]: Cannot find translation for source SoundCloud Feb 26 13:27:31 volumio volumio[2825]: Cannot find translation for source YouTube2 Feb 26 13:27:31 volumio volumio[2825]: Cannot find translation for source YouTube Music Feb 26 13:27:31 volumio volumio[2825]: Cannot find translation for source Podcast Feb 26 13:27:31 volumio volumio[2825]: Cannot find translation for source Volusonic Feb 26 13:27:31 volumio volumio[2825]: Cannot find translation for source Spotify Feb 26 13:27:32 volumio systemd[1]: Reloading. Feb 26 13:27:33 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:33 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:33 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:27:33 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 13:27:33 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. Feb 26 13:27:33 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. Feb 26 13:27:33 volumio sudo[3168]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:34 volumio volumio[2825]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 26 13:27:34 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 26 13:27:34 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 26 13:27:34 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 26 13:27:34 volumio systemd[1]: shairport-sync.service: Consumed 1.492s CPU time. Feb 26 13:27:34 volumio volumio[2825]: info: go-librespot daemon successfully initialized Feb 26 13:27:34 volumio sudo[3193]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 26 13:27:34 volumio sudo[3193]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:34 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 26 13:27:34 volumio sudo[3170]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:34 volumio volumio[2825]: info: Shairport-Sync Started Feb 26 13:27:34 volumio sudo[3193]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:34 volumio volumio[2825]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Feb 26 13:27:34 volumio sudo[3210]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Feb 26 13:27:34 volumio sudo[3210]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:34 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 26 13:27:34 volumio systemd[1]: squeezelite.service: Deactivated successfully. Feb 26 13:27:34 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 26 13:27:34 volumio sudo[3210]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Feb 26 13:27:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:27:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:27:34 volumio go-librespot[3213]: go-librespot daemon starting... Feb 26 13:27:34 volumio go-librespot[3214]: time="2026-02-26T13:27:34-06:00" level=info msg="running go-librespot 0.4.0" Feb 26 13:27:34 volumio go-librespot[3214]: time="2026-02-26T13:27:34-06:00" level=debug msg="app state loaded" Feb 26 13:27:34 volumio go-librespot[3214]: time="2026-02-26T13:27:34-06:00" level=debug msg="stored credentials not found" Feb 26 13:27:34 volumio go-librespot[3214]: time="2026-02-26T13:27:34-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 13:27:34 volumio go-librespot[3214]: time="2026-02-26T13:27:34-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]" Feb 26 13:27:34 volumio go-librespot[3214]: time="2026-02-26T13:27:34-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]" Feb 26 13:27:34 volumio go-librespot[3214]: time="2026-02-26T13:27:34-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]" Feb 26 13:27:34 volumio go-librespot[3214]: time="2026-02-26T13:27:34-06:00" level=info msg="zeroconf server listening on port 46423" Feb 26 13:27:34 volumio volumio[2825]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 26 13:27:34 volumio go-librespot[3214]: time="2026-02-26T13:27:34-06:00" level=debug msg="obtained new client token: AAA57KvaUK9viV2zziG6hAND+oWuEGffot2VYsnfIv/TpoHgnaDZEpjLHBQUd1wCBqlaayilypQSIeDqsNcgcMdsaqQiYbu7W9QHt5xQzrqZc+30nH3c9j9z0EnzFZL19Lhujw1Ff8otVNcDd6SgPkn/d4/uOsWOCPrfsz7bEImNa7qy4t2qk6SV8c6unvpaCXRLGozikLavu4F32J9sXePmUnp0oKMb95dBevzjcouK1P/H5EFug+DwFg==" Feb 26 13:27:35 volumio sudo[3223]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 26 13:27:35 volumio sudo[3223]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:35 volumio go-librespot[3214]: time="2026-02-26T13:27:35-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 26 13:27:35 volumio sudo[3223]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:35 volumio go-librespot[3214]: time="2026-02-26T13:27:35-06:00" level=debug msg="completed keyexchange" Feb 26 13:27:35 volumio go-librespot[3214]: time="2026-02-26T13:27:35-06:00" level=debug msg="completed challenge" Feb 26 13:27:35 volumio volumio[2825]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Feb 26 13:27:35 volumio sudo[3227]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Feb 26 13:27:35 volumio sudo[3227]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:35 volumio go-librespot[3214]: time="2026-02-26T13:27: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 " Feb 26 13:27:35 volumio sudo[3227]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 13:27:35 volumio volumio[2825]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Feb 26 13:27:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 13:27:35 volumio sudo[3230]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Feb 26 13:27:35 volumio sudo[3230]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:35 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 26 13:27:35 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 26 13:27:35 volumio sudo[3230]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:35 volumio mpd[3174]: 2026-02-26T13:27:35 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 26 13:27:35 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 26 13:27:35 volumio sudo[3131]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:35 volumio sudo[3044]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:35 volumio sudo[3034]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:35 volumio volumio[2825]: error: MPD error: The expression evaluated to a falsy value: Feb 26 13:27:35 volumio volumio[2825]: assert.ok(self.idling) Feb 26 13:27:35 volumio volumio[2825]: error: The expression evaluated to a falsy value: Feb 26 13:27:35 volumio volumio[2825]: assert.ok(self.idling) Feb 26 13:27:35 volumio volumio[2825]: error: MPD error: The expression evaluated to a falsy value: Feb 26 13:27:35 volumio volumio[2825]: assert.ok(self.idling) Feb 26 13:27:35 volumio volumio[2825]: error: The expression evaluated to a falsy value: Feb 26 13:27:35 volumio volumio[2825]: assert.ok(self.idling) Feb 26 13:27:35 volumio volumio[2825]: info: MPD running with PID3174 Feb 26 13:27:35 volumio volumio[2825]: ,establishing connection Feb 26 13:27:35 volumio volumio[2825]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 26 13:27:35 volumio volumio[2825]: error: updateQueue error: null Feb 26 13:27:35 volumio volumio[2825]: error: updateQueue error: null Feb 26 13:27:35 volumio sudo[3255]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 26 13:27:35 volumio sudo[3255]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:36 volumio sudo[3255]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:36 volumio volumio[2825]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 26 13:27:36 volumio sudo[3259]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 26 13:27:36 volumio sudo[3259]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:36 volumio sudo[3259]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:37 volumio volumio[2825]: info: Initializing connection to go-librespot Websocket Feb 26 13:27:37 volumio volumio[2825]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 13:27:37 volumio volumio[2825]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 26 13:27:37 volumio sudo[3262]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 26 13:27:37 volumio sudo[3262]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:37 volumio sudo[3262]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:37 volumio volumio[2825]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 26 13:27:37 volumio sudo[3265]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 26 13:27:37 volumio sudo[3265]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:37 volumio sudo[3265]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:38 volumio volumio[2825]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 26 13:27:38 volumio sudo[3268]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 26 13:27:38 volumio sudo[3268]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Feb 26 13:27:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:27:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:27:38 volumio go-librespot[3270]: go-librespot daemon starting... Feb 26 13:27:38 volumio sudo[3268]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:38 volumio go-librespot[3271]: time="2026-02-26T13:27:38-06:00" level=info msg="running go-librespot 0.4.0" Feb 26 13:27:38 volumio go-librespot[3271]: time="2026-02-26T13:27:38-06:00" level=debug msg="app state loaded" Feb 26 13:27:38 volumio go-librespot[3271]: time="2026-02-26T13:27:38-06:00" level=debug msg="stored credentials not found" Feb 26 13:27:38 volumio go-librespot[3271]: time="2026-02-26T13:27:38-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 13:27:38 volumio volumio[2825]: info: Completed starting Core Plugins Feb 26 13:27:38 volumio volumio[2825]: info: ------------------------------------------- Feb 26 13:27:38 volumio volumio[2825]: info: ----- MyVolumio plugins startup ---- Feb 26 13:27:38 volumio volumio[2825]: info: ------------------------------------------- Feb 26 13:27:38 volumio volumio[2825]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 26 13:27:38 volumio go-librespot[3271]: time="2026-02-26T13:27:38-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]" Feb 26 13:27:38 volumio go-librespot[3271]: time="2026-02-26T13:27:38-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]" Feb 26 13:27:38 volumio go-librespot[3271]: time="2026-02-26T13:27:38-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]" Feb 26 13:27:38 volumio go-librespot[3271]: time="2026-02-26T13:27:38-06:00" level=info msg="zeroconf server listening on port 35023" Feb 26 13:27:38 volumio go-librespot[3271]: time="2026-02-26T13:27:38-06:00" level=debug msg="obtained new client token: AAA+hSCVW0yUkn+Jv9mmsv1rnE1ziVaKvAz6zcTX0n7bLvUf0PtOsX6yEYvI8X2n42HROzFAiHC0mn7kSHgiUMYqI7X15K/u3+jgM3WUqZdL4zZ+G5O53JEn9U/5D3MJksu2Zl1Ljg4x2wzv4cvBNmJVX7l2WSmw79ZNUaWhoUqTf7XP2tcFbE4kgLHM6D/IK6HhPhMn9q6wKH4DM0CulN4wYJL+LJK8n7S0R2r79CXNgvM3JTZrLEdNpQ==" Feb 26 13:27:38 volumio sudo[3279]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 26 13:27:38 volumio sudo[3279]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:38 volumio sudo[3281]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 26 13:27:38 volumio sudo[3281]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:38 volumio go-librespot[3271]: time="2026-02-26T13:27:38-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 26 13:27:38 volumio sudo[3283]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 26 13:27:38 volumio sudo[3283]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:38 volumio go-librespot[3271]: time="2026-02-26T13:27:38-06:00" level=debug msg="completed keyexchange" Feb 26 13:27:38 volumio go-librespot[3271]: time="2026-02-26T13:27:38-06:00" level=debug msg="completed challenge" Feb 26 13:27:38 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 26 13:27:38 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 26 13:27:38 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 26 13:27:38 volumio go-librespot[3271]: time="2026-02-26T13:27:38-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 " Feb 26 13:27:39 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 26 13:27:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 13:27:39 volumio mpd_monitor.sh[3287]: MPD Monitor Service: Starting MPD Monitor Service Feb 26 13:27:39 volumio sudo[3279]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 13:27:39 volumio sudo[3283]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:39 volumio sudo[3281]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:39 volumio volumio[2825]: info: Successfully started MPD Monitor Feb 26 13:27:39 volumio volumio[2825]: info: Successfully started MPD Monitor Feb 26 13:27:39 volumio volumio[2825]: info: Successfully started MPD Monitor Feb 26 13:27:40 volumio volumio[2825]: info: Initializing connection to go-librespot Websocket Feb 26 13:27:40 volumio volumio[2825]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 13:27:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Feb 26 13:27:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:27:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:27:42 volumio go-librespot[3292]: go-librespot daemon starting... Feb 26 13:27:42 volumio go-librespot[3293]: time="2026-02-26T13:27:42-06:00" level=info msg="running go-librespot 0.4.0" Feb 26 13:27:42 volumio go-librespot[3293]: time="2026-02-26T13:27:42-06:00" level=debug msg="app state loaded" Feb 26 13:27:42 volumio go-librespot[3293]: time="2026-02-26T13:27:42-06:00" level=debug msg="stored credentials not found" Feb 26 13:27:42 volumio go-librespot[3293]: time="2026-02-26T13:27:42-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 13:27:42 volumio go-librespot[3293]: time="2026-02-26T13:27:42-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]" Feb 26 13:27:42 volumio go-librespot[3293]: time="2026-02-26T13:27:42-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]" Feb 26 13:27:42 volumio go-librespot[3293]: time="2026-02-26T13:27:42-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]" Feb 26 13:27:42 volumio go-librespot[3293]: time="2026-02-26T13:27:42-06:00" level=info msg="zeroconf server listening on port 41951" Feb 26 13:27:42 volumio go-librespot[3293]: time="2026-02-26T13:27:42-06:00" level=debug msg="obtained new client token: AACPv3kwzRUOCETcvc665nLDs0W6GmSX7/OP0EAG3W//BHspI8aUWBBQhqLKa59CyZ0ULknxpCxyvv41L7hMJH7+HRbB5nzDh/oQfxPJGLNHcZ0piDFKgX2nttExNMdq6oS1t/tvG9WUt90LqAYxJ+Jvq2TyebOHxDtRRvvxQqHIi5WtuVSwKtgySI/fVdkGcOXfEpOj4rbWmGkOf3tepQsGAj/5rxf8BrmJOGrCuQiHdqqNeyrE2JHYmA==" Feb 26 13:27:42 volumio go-librespot[3293]: time="2026-02-26T13:27:42-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 26 13:27:43 volumio go-librespot[3293]: time="2026-02-26T13:27:43-06:00" level=debug msg="completed keyexchange" Feb 26 13:27:43 volumio go-librespot[3293]: time="2026-02-26T13:27:43-06:00" level=debug msg="completed challenge" Feb 26 13:27:43 volumio go-librespot[3293]: time="2026-02-26T13:27:43-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 " Feb 26 13:27:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 13:27:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 13:27:43 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 26 13:27:44 volumio volumio[2825]: info: Initializing connection to go-librespot Websocket Feb 26 13:27:44 volumio volumio[2825]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 13:27:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Feb 26 13:27:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:27:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:27:46 volumio go-librespot[3315]: go-librespot daemon starting... Feb 26 13:27:46 volumio go-librespot[3316]: time="2026-02-26T13:27:46-06:00" level=info msg="running go-librespot 0.4.0" Feb 26 13:27:46 volumio go-librespot[3316]: time="2026-02-26T13:27:46-06:00" level=debug msg="app state loaded" Feb 26 13:27:46 volumio go-librespot[3316]: time="2026-02-26T13:27:46-06:00" level=debug msg="stored credentials not found" Feb 26 13:27:46 volumio go-librespot[3316]: time="2026-02-26T13:27:46-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 13:27:46 volumio go-librespot[3316]: time="2026-02-26T13:27:46-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]" Feb 26 13:27:46 volumio go-librespot[3316]: time="2026-02-26T13:27:46-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]" Feb 26 13:27:46 volumio go-librespot[3316]: time="2026-02-26T13:27:46-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]" Feb 26 13:27:46 volumio go-librespot[3316]: time="2026-02-26T13:27:46-06:00" level=info msg="zeroconf server listening on port 39995" Feb 26 13:27:46 volumio go-librespot[3316]: time="2026-02-26T13:27:46-06:00" level=debug msg="obtained new client token: AACW6EiHOrfMx4EIE2IXE5FQZRtdWvWzidWQgKml+XQ63yuJdnkQOlMLdJwolfWbvhehzZcPSOW1IQk44n4QsSeWYE/DO2ho3/RSOwf9IYqpMWW8uKMHxRw9sF/aC78uEHZWkm0esjoQNwiTGyKVgRV774wu3yhAio+cq1W9MJkLspt9bcQhCWzrdrlUPpVKxAx2mvZh40imvpF2uOKRqmOJkE1MgOzpFFIk3O+g2AogozO9eHjEeapSCw==" Feb 26 13:27:46 volumio go-librespot[3316]: time="2026-02-26T13:27:46-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 26 13:27:46 volumio go-librespot[3316]: time="2026-02-26T13:27:46-06:00" level=debug msg="completed keyexchange" Feb 26 13:27:46 volumio go-librespot[3316]: time="2026-02-26T13:27:46-06:00" level=debug msg="completed challenge" Feb 26 13:27:46 volumio volumio[2825]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 26 13:27:46 volumio volumio[2825]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 26 13:27:46 volumio volumio[2825]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 26 13:27:46 volumio volumio[2825]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 26 13:27:46 volumio volumio[2825]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 26 13:27:46 volumio volumio[2825]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 26 13:27:46 volumio volumio[2825]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 26 13:27:46 volumio volumio[2825]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 26 13:27:46 volumio go-librespot[3316]: time="2026-02-26T13:27:46-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 " Feb 26 13:27:46 volumio volumio[2825]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 26 13:27:46 volumio volumio[2825]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 26 13:27:46 volumio volumio[2825]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 26 13:27:46 volumio volumio[2825]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 26 13:27:46 volumio volumio[2825]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 26 13:27:46 volumio volumio[2825]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 26 13:27:46 volumio volumio[2825]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 26 13:27:46 volumio volumio[2825]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 26 13:27:46 volumio volumio[2825]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 26 13:27:46 volumio volumio[2825]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 26 13:27:46 volumio volumio[2825]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 26 13:27:46 volumio volumio[2825]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 26 13:27:46 volumio volumio[2825]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 26 13:27:46 volumio volumio[2825]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 26 13:27:46 volumio volumio[2825]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 26 13:27:46 volumio volumio[2825]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 26 13:27:46 volumio volumio[2825]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 26 13:27:46 volumio volumio[2825]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 26 13:27:46 volumio volumio[2825]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 26 13:27:46 volumio volumio[2825]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 26 13:27:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 13:27:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 13:27:46 volumio volumio[2825]: info: Adding plugin bluetooth to MyMusic Plugins Feb 26 13:27:46 volumio volumio[2825]: info: Adding plugin multiroom to MyMusic Plugins Feb 26 13:27:46 volumio volumio[2825]: info: Adding plugin metavolumio to MyMusic Plugins Feb 26 13:27:46 volumio volumio[2825]: info: Adding plugin cd_controller to MyMusic Plugins Feb 26 13:27:46 volumio volumio[2825]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 26 13:27:46 volumio volumio[2825]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 26 13:27:46 volumio volumio[2825]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 26 13:27:46 volumio volumio[2825]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 26 13:27:47 volumio volumio[2825]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 26 13:27:47 volumio volumio[2825]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 26 13:27:47 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 13:27:47 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 13:27:47 volumio volumio[2825]: info: Starting MyVolumio Remote Streaming Endpoints Feb 26 13:27:47 volumio volumio[2825]: info: MyVolumio login type: Token Feb 26 13:27:47 volumio volumio[2825]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 26 13:27:47 volumio volumio[2825]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 26 13:27:48 volumio kernel: hwmon hwmon1: Voltage normalised Feb 26 13:27:48 volumio volumio[2825]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 26 13:27:48 volumio volumio[2825]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 26 13:27:48 volumio volumio[2825]: info: Streaming services startup Feb 26 13:27:48 volumio volumio[2825]: info: Starting Streaming Daemon Feb 26 13:27:48 volumio sudo[3326]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 26 13:27:48 volumio sudo[3326]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:27:48 volumio volumio[2825]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 26 13:27:48 volumio sudo[3326]: pam_unix(sudo:session): session closed for user root Feb 26 13:27:48 volumio volumio[2825]: info: Initializing connection to go-librespot Websocket Feb 26 13:27:48 volumio volumio[2825]: error: Cannot start Volumio Streaming Daemon Feb 26 13:27:48 volumio volumio[2825]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 26 13:27:48 volumio volumio[2825]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 26 13:27:48 volumio volumio[2825]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 13:27:48 volumio volumio[2825]: error: MyVolumio FAILED LOGIN: Invalid assertion format. 3 dot separated segments required. Feb 26 13:27:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Feb 26 13:27:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:27:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:27:49 volumio go-librespot[3332]: go-librespot daemon starting... Feb 26 13:27:49 volumio go-librespot[3333]: time="2026-02-26T13:27:49-06:00" level=info msg="running go-librespot 0.4.0" Feb 26 13:27:49 volumio go-librespot[3333]: time="2026-02-26T13:27:49-06:00" level=debug msg="app state loaded" Feb 26 13:27:49 volumio go-librespot[3333]: time="2026-02-26T13:27:49-06:00" level=debug msg="stored credentials not found" Feb 26 13:27:49 volumio go-librespot[3333]: time="2026-02-26T13:27:49-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 13:27:50 volumio go-librespot[3333]: time="2026-02-26T13:27:50-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]" Feb 26 13:27:50 volumio go-librespot[3333]: time="2026-02-26T13:27:50-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]" Feb 26 13:27:50 volumio go-librespot[3333]: time="2026-02-26T13:27:50-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]" Feb 26 13:27:50 volumio go-librespot[3333]: time="2026-02-26T13:27:50-06:00" level=info msg="zeroconf server listening on port 45707" Feb 26 13:27:50 volumio go-librespot[3333]: time="2026-02-26T13:27:50-06:00" level=debug msg="obtained new client token: AABHz+jGWKtgbv2mGjshDSPGWGKF9Ss7hbwsVIw88Rgps5haEXs9l5zwvxphiLjqY0KOOpShrtURZH6cI/xkE3cqA/Zizgt/0ywkSSLZarRkOWo8jQY8SfliuPhHxsllmQ6E5IRCDZaMhJT+IcydnP0cNxZft8TRlaRhk2xjGtc/rcX3o8WqopEm4hKurUIAsfj1UdcVqu1qZRALaaXXrxAWEaskyNXI4gnJ+0osHOt69jljXXiIxtrnjA==" Feb 26 13:27:50 volumio go-librespot[3333]: time="2026-02-26T13:27:50-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 26 13:27:50 volumio go-librespot[3333]: time="2026-02-26T13:27:50-06:00" level=debug msg="completed keyexchange" Feb 26 13:27:50 volumio go-librespot[3333]: time="2026-02-26T13:27:50-06:00" level=debug msg="completed challenge" Feb 26 13:27:50 volumio go-librespot[3333]: time="2026-02-26T13:27:50-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 " Feb 26 13:27:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 13:27:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 13:27:51 volumio volumio[2825]: info: Initializing connection to go-librespot Websocket Feb 26 13:27:51 volumio volumio[2825]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 13:27:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Feb 26 13:27:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:27:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:27:53 volumio go-librespot[3341]: go-librespot daemon starting... Feb 26 13:27:53 volumio go-librespot[3342]: time="2026-02-26T13:27:53-06:00" level=info msg="running go-librespot 0.4.0" Feb 26 13:27:53 volumio go-librespot[3342]: time="2026-02-26T13:27:53-06:00" level=debug msg="app state loaded" Feb 26 13:27:53 volumio go-librespot[3342]: time="2026-02-26T13:27:53-06:00" level=debug msg="stored credentials not found" Feb 26 13:27:53 volumio go-librespot[3342]: time="2026-02-26T13:27:53-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 13:27:53 volumio go-librespot[3342]: time="2026-02-26T13:27:53-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]" Feb 26 13:27:53 volumio go-librespot[3342]: time="2026-02-26T13:27:53-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]" Feb 26 13:27:53 volumio go-librespot[3342]: time="2026-02-26T13:27:53-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]" Feb 26 13:27:53 volumio go-librespot[3342]: time="2026-02-26T13:27:53-06:00" level=info msg="zeroconf server listening on port 45081" Feb 26 13:27:54 volumio go-librespot[3342]: time="2026-02-26T13:27:54-06:00" level=debug msg="obtained new client token: AAAG586PVl+xaRbddsVnb6fSuzY6EdGaAvSQFdxb+lja6h04T2M1pH2GEiHDVMV7PuP2fPPxmzktB+t8QvNBNVwHC6t4puE8tD5GxusyMDsHtsdqvRPf0X9l/PFGoDrd6X1u1wo29KWKovDVBpAR4bljF+mFjlaZz6+qj5TaeTWof8ofQhT9QOSRCYrUt/wq/er2LmkIGt2TyD/Bh8xFgeHDJaRUG4OB3Aknr5dACkbXPmqO3Abysq4=" Feb 26 13:27:54 volumio go-librespot[3342]: time="2026-02-26T13:27:54-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 26 13:27:54 volumio go-librespot[3342]: time="2026-02-26T13:27:54-06:00" level=debug msg="completed keyexchange" Feb 26 13:27:54 volumio go-librespot[3342]: time="2026-02-26T13:27:54-06:00" level=debug msg="completed challenge" Feb 26 13:27:54 volumio go-librespot[3342]: time="2026-02-26T13:27: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 " Feb 26 13:27:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 13:27:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 13:27:54 volumio volumio[2825]: info: Initializing connection to go-librespot Websocket Feb 26 13:27:54 volumio volumio[2825]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 13:27:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Feb 26 13:27:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:27:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:27:57 volumio go-librespot[3364]: go-librespot daemon starting... Feb 26 13:27:57 volumio go-librespot[3365]: time="2026-02-26T13:27:57-06:00" level=info msg="running go-librespot 0.4.0" Feb 26 13:27:57 volumio go-librespot[3365]: time="2026-02-26T13:27:57-06:00" level=debug msg="app state loaded" Feb 26 13:27:57 volumio go-librespot[3365]: time="2026-02-26T13:27:57-06:00" level=debug msg="stored credentials not found" Feb 26 13:27:57 volumio go-librespot[3365]: time="2026-02-26T13:27:57-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 13:27:57 volumio go-librespot[3365]: time="2026-02-26T13:27: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-gew4.spotify.com:80]" Feb 26 13:27:57 volumio go-librespot[3365]: time="2026-02-26T13:27:57-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]" Feb 26 13:27:57 volumio go-librespot[3365]: time="2026-02-26T13:27:57-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]" Feb 26 13:27:57 volumio go-librespot[3365]: time="2026-02-26T13:27:57-06:00" level=info msg="zeroconf server listening on port 42133" Feb 26 13:27:57 volumio volumio[2825]: info: Initializing connection to go-librespot Websocket Feb 26 13:27:57 volumio go-librespot[3365]: time="2026-02-26T13:27:57-06:00" level=debug msg="new websocket client" Feb 26 13:27:57 volumio volumio[2825]: info: Connection to go-librespot Websocket established Feb 26 13:27:57 volumio go-librespot[3365]: time="2026-02-26T13:27:57-06:00" level=debug msg="obtained new client token: AABdVCpWxUKMtGVbgII5gRJXhZYh932RjJlN3Towvd3FsOSgsfIN0aG9BHHoESZ29qEpSqdMLdbp6LVlpA4kbczBrENm4WuXOxsYR0rRko5rg1uaAGC/4NwmFZMmRHEFIRSVcwItkCsiiQRkMCUEaB8DlaTeazdZXrMuDzZMu0zhWIPrCXs/FodJ9qG1P32YlUunnR/nf8BjGJ+ElWaWsvWtE7A6oFa/WkWc4ASoBlZBkIfPyz5UmXQkgw==" Feb 26 13:27:57 volumio go-librespot[3365]: time="2026-02-26T13:27:57-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 26 13:27:57 volumio go-librespot[3365]: time="2026-02-26T13:27:57-06:00" level=debug msg="completed keyexchange" Feb 26 13:27:57 volumio go-librespot[3365]: time="2026-02-26T13:27:57-06:00" level=debug msg="completed challenge" Feb 26 13:27:57 volumio go-librespot[3365]: time="2026-02-26T13:27:57-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 " Feb 26 13:27:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 13:27:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 13:27:57 volumio volumio[2825]: info: Connection to go-librespot Websocket closed Feb 26 13:28:00 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 26 13:28:00 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 13:28:00 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 26 13:28:00 volumio volumio-remote-updater[13697]: Test mode disabled Feb 26 13:28:00 volumio volumio-remote-updater[13697]: Alpha mode disabled Feb 26 13:28:00 volumio volumio-remote-updater[13697]: Alpha legacy test mode disabled Feb 26 13:28:00 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Feb 26 13:28:00 volumio volumio[2825]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

FIXES

\n
    \n
  • Fix for CPU utilization spike
    • \n
  • Fix for triggerhappy input permission
    • \n
\n

NEW ADDITIONS

\n
    \n
  • Add BLE onboarding plugin
    • \n
  • Enable vc4-kms-v3d for all compatible RPi models
    • \n
  • Update Tidal SDK
    • \n
\n","title":"Update v4.096","updateavailable":true} Feb 26 13:28:00 volumio volumio[2825]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 26 13:28:00 volumio volumio[2825]: info: Getting Spotify volume Feb 26 13:28:00 volumio volumio[2825]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 26 13:28:00 volumio volumio[2825]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 13:28:00 volumio volumio[2825]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 26 13:28:00 volumio volumio[2825]: errno: -111, Feb 26 13:28:00 volumio volumio[2825]: code: 'ECONNREFUSED', Feb 26 13:28:00 volumio volumio[2825]: syscall: 'connect', Feb 26 13:28:00 volumio volumio[2825]: address: '127.0.0.1', Feb 26 13:28:00 volumio volumio[2825]: port: 9879, Feb 26 13:28:00 volumio volumio[2825]: response: undefined Feb 26 13:28:00 volumio volumio[2825]: } Feb 26 13:28:00 volumio volumio[2825]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 26 13:28:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33. Feb 26 13:28:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:28:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:28:01 volumio go-librespot[3391]: go-librespot daemon starting... Feb 26 13:28:01 volumio go-librespot[3392]: time="2026-02-26T13:28:01-06:00" level=info msg="running go-librespot 0.4.0" Feb 26 13:28:01 volumio go-librespot[3392]: time="2026-02-26T13:28:01-06:00" level=debug msg="app state loaded" Feb 26 13:28:01 volumio go-librespot[3392]: time="2026-02-26T13:28:01-06:00" level=debug msg="stored credentials not found" Feb 26 13:28:01 volumio go-librespot[3392]: time="2026-02-26T13:28:01-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 13:28:01 volumio go-librespot[3392]: time="2026-02-26T13:28: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]" Feb 26 13:28:01 volumio go-librespot[3392]: time="2026-02-26T13:28: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]" Feb 26 13:28:01 volumio go-librespot[3392]: time="2026-02-26T13:28: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]" Feb 26 13:28:01 volumio go-librespot[3392]: time="2026-02-26T13:28:01-06:00" level=info msg="zeroconf server listening on port 36653" Feb 26 13:28:01 volumio go-librespot[3392]: time="2026-02-26T13:28:01-06:00" level=debug msg="obtained new client token: AAASR2nQzEQcYVCpfgZLeGvL1nvrfeS9kDZM0vm2PdsqkF4vxtWXTvldmO8uOItQsYJYAl72nq/JVZxVgAxnGrtQM8Giq173H8fTdZTgZ6AMXIi34TTZwzU+H3nTvPvziFxH14sberyT4scHMFKmojBzEPkimHZwxoQXUKIJg5oAOvxROHh8PcKY6+VE3pUo7LrPjn5qQysGZZwD6GONgseYV/sGqUBcQyGcmUketZe53eKkvOZAQ1cEJg==" Feb 26 13:28:01 volumio sudo[3401]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-26 13:27' Feb 26 13:28:01 volumio sudo[3401]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:01 volumio go-librespot[3392]: time="2026-02-26T13:28:01-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 26 13:28:01 volumio go-librespot[3392]: time="2026-02-26T13:28:01-06:00" level=debug msg="completed keyexchange" Feb 26 13:28:01 volumio go-librespot[3392]: time="2026-02-26T13:28:01-06:00" level=debug msg="completed challenge" Feb 26 13:28:01 volumio go-librespot[3392]: time="2026-02-26T13:28:01-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 " Feb 26 13:28:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 13:28:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 13:28:01 volumio sudo[3401]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:01 volumio volumio-remote-updater[13697]: [2026-02-26 13:28:01] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 26 13:28:01 volumio volumio-remote-updater[13697]: [2026-02-26 13:28:01] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 26 13:28:01 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 26 13:28:01 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 26 13:28:01 volumio systemd[1]: volumio.service: Consumed 47.249s CPU time. Feb 26 13:28:01 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 26 13:28:01 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 26 13:28:02 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 6504. Feb 26 13:28:02 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 26 13:28:02 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 26 13:28:02 volumio systemd[1]: volumio.service: Consumed 47.249s CPU time. Feb 26 13:28:02 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 26 13:28:02 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 26 13:28:04 volumio volumio[3413]: info: ------------------------------------------- Feb 26 13:28:04 volumio volumio[3413]: info: ----- Volumio3 ---- Feb 26 13:28:04 volumio volumio[3413]: info: ------------------------------------------- Feb 26 13:28:04 volumio volumio[3413]: info: ----- System startup ---- Feb 26 13:28:04 volumio volumio[3413]: info: ------------------------------------------- Feb 26 13:28:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34. Feb 26 13:28:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:28:04 volumio volumio[3413]: info: MYVOLUMIO Environment detected Feb 26 13:28:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:28:04 volumio go-librespot[3434]: go-librespot daemon starting... Feb 26 13:28:05 volumio go-librespot[3438]: time="2026-02-26T13:28:05-06:00" level=info msg="running go-librespot 0.4.0" Feb 26 13:28:05 volumio go-librespot[3438]: time="2026-02-26T13:28:05-06:00" level=debug msg="app state loaded" Feb 26 13:28:05 volumio go-librespot[3438]: time="2026-02-26T13:28:05-06:00" level=debug msg="stored credentials not found" Feb 26 13:28:05 volumio go-librespot[3438]: time="2026-02-26T13:28:05-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 13:28:05 volumio volumio[3413]: info: Plugin folders cleanup Feb 26 13:28:05 volumio volumio[3413]: info: Scanning into folder /volumio/app/plugins/ Feb 26 13:28:05 volumio volumio[3413]: info: Scanning category audio_interface Feb 26 13:28:05 volumio volumio[3413]: info: Scanning category miscellanea Feb 26 13:28:05 volumio volumio[3413]: info: Scanning category music_service Feb 26 13:28:05 volumio volumio[3413]: info: Scanning category plugins.json Feb 26 13:28:05 volumio volumio[3413]: info: Scanning category system_controller Feb 26 13:28:05 volumio volumio[3413]: info: Scanning category user_interface Feb 26 13:28:05 volumio volumio[3413]: info: Scanning into folder /data/plugins/ Feb 26 13:28:05 volumio volumio[3413]: info: Scanning category audio_interface Feb 26 13:28:05 volumio volumio[3413]: info: Scanning category music_service Feb 26 13:28:05 volumio volumio[3413]: info: Scanning category system_controller Feb 26 13:28:05 volumio volumio[3413]: info: Scanning category system_hardware Feb 26 13:28:05 volumio volumio[3413]: info: Scanning category user_interface Feb 26 13:28:05 volumio volumio[3413]: info: Plugin folders cleanup completed Feb 26 13:28:05 volumio volumio[3413]: info: ------------------------------------------- Feb 26 13:28:05 volumio volumio[3413]: info: ----- Core plugins startup ---- Feb 26 13:28:05 volumio volumio[3413]: info: ------------------------------------------- Feb 26 13:28:05 volumio volumio[3413]: info: Loading plugins from folder /volumio/app/plugins/ Feb 26 13:28:05 volumio volumio[3413]: info: Adding plugin upnp to MyMusic Plugins Feb 26 13:28:05 volumio volumio[3413]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 26 13:28:05 volumio volumio[3413]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 26 13:28:05 volumio volumio[3413]: info: Loading plugins from folder /data/plugins/ Feb 26 13:28:05 volumio volumio[3413]: info: Loading plugin "system"... Feb 26 13:28:05 volumio volumio[3413]: info: Loading plugin "appearance"... Feb 26 13:28:05 volumio go-librespot[3438]: time="2026-02-26T13:28:05-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]" Feb 26 13:28:05 volumio go-librespot[3438]: time="2026-02-26T13:28:05-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]" Feb 26 13:28:05 volumio go-librespot[3438]: time="2026-02-26T13:28:05-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]" Feb 26 13:28:05 volumio go-librespot[3438]: time="2026-02-26T13:28:05-06:00" level=info msg="zeroconf server listening on port 38007" Feb 26 13:28:05 volumio go-librespot[3438]: time="2026-02-26T13:28:05-06:00" level=debug msg="obtained new client token: AADrAFQNgQwDW0yCb+Nz/THCdHzI8FifkY9Zoq1xtxO1HabqmVOOoZw54cYps/ziRCnS9N9CCp5OfImURf05eKnfgG7wM15sCYO5CVD6ofV5cJ74eYRHWdHLVjBsI5DJiP2D9OUh5faADvJfRUJ/xobcIwzR2pfwYbIhOhJpTPW1IDNnM80It7BdCH6uJ6oMqpUdW6/dESrZKF/bqBBT3UTemivPdFSrbpPll3HjFNYtMjK4cdHbBpQUqA==" Feb 26 13:28:05 volumio go-librespot[3438]: time="2026-02-26T13:28:05-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 26 13:28:05 volumio go-librespot[3438]: time="2026-02-26T13:28:05-06:00" level=debug msg="completed keyexchange" Feb 26 13:28:05 volumio go-librespot[3438]: time="2026-02-26T13:28:05-06:00" level=debug msg="completed challenge" Feb 26 13:28:05 volumio go-librespot[3438]: time="2026-02-26T13:28: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 " Feb 26 13:28:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 13:28:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 13:28:06 volumio volumio[3413]: info: Loading plugin "network"... Feb 26 13:28:06 volumio volumio[3413]: info: Refreshing Cached IP Addresses Feb 26 13:28:06 volumio sudo[3450]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 26 13:28:06 volumio sudo[3450]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:06 volumio sudo[3452]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 26 13:28:06 volumio sudo[3452]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:06 volumio sudo[3450]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:06 volumio sudo[3452]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:06 volumio volumio[3413]: info: Loading plugin "services"... Feb 26 13:28:06 volumio volumio[3413]: info: Loading plugin "alsa_controller"... Feb 26 13:28:06 volumio sudo[3460]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 26 13:28:06 volumio sudo[3460]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:06 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 26 13:28:06 volumio volumio[3413]: info: Loading plugin "wizard"... Feb 26 13:28:06 volumio volumio[3413]: info: Loading plugin "networkfs"... Feb 26 13:28:06 volumio volumio[3413]: info: Starting Udev Watcher for removable devices Feb 26 13:28:06 volumio volumio[3413]: info: Ignoring mount for partition: boot Feb 26 13:28:06 volumio volumio[3413]: info: Ignoring mount for partition: volumio Feb 26 13:28:06 volumio volumio[3413]: info: Ignoring mount for partition: volumio_data Feb 26 13:28:06 volumio volumio[3413]: info: Mounting Device Wikipedia Feb 26 13:28:06 volumio sudo[3489]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Feb 26 13:28:06 volumio sudo[3489]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:06 volumio sudo[3489]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:06 volumio volumio[3413]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Feb 26 13:28:06 volumio volumio[3413]: dmesg(1) may have more information after failed mount system call. Feb 26 13:28:06 volumio volumio[3413]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Feb 26 13:28:06 volumio volumio[3413]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Feb 26 13:28:06 volumio volumio[3413]: dmesg(1) may have more information after failed mount system call. Feb 26 13:28:06 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 26 13:28:06 volumio volumio[3413]: info: Loading plugin "volumio_command_line_client"... Feb 26 13:28:06 volumio volumio[3413]: info: Loading plugin "upnp"... Feb 26 13:28:06 volumio volumio[3413]: info: [1772134086647] Starting Upmpd Daemon Feb 26 13:28:06 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 26 13:28:06 volumio volumio[3413]: info: Loading plugin "my_music"... Feb 26 13:28:06 volumio volumio[3413]: info: Loading plugin "mpd"... Feb 26 13:28:06 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 26 13:28:06 volumio volumio-remote-updater[13697]: [2026-02-26 13:28:06] [connect] Successful connection Feb 26 13:28:06 volumio sudo[3460]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:07 volumio volumio[3413]: info: Loading plugin "upnp_browser"... Feb 26 13:28:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35. Feb 26 13:28:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:28:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:28:08 volumio go-librespot[3492]: go-librespot daemon starting... Feb 26 13:28:09 volumio go-librespot[3493]: time="2026-02-26T13:28:09-06:00" level=info msg="running go-librespot 0.4.0" Feb 26 13:28:09 volumio go-librespot[3493]: time="2026-02-26T13:28:09-06:00" level=debug msg="app state loaded" Feb 26 13:28:09 volumio go-librespot[3493]: time="2026-02-26T13:28:09-06:00" level=debug msg="stored credentials not found" Feb 26 13:28:09 volumio go-librespot[3493]: time="2026-02-26T13:28:09-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 13:28:09 volumio go-librespot[3493]: time="2026-02-26T13:28:09-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]" Feb 26 13:28:09 volumio go-librespot[3493]: time="2026-02-26T13:28:09-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]" Feb 26 13:28:09 volumio go-librespot[3493]: time="2026-02-26T13:28:09-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]" Feb 26 13:28:09 volumio go-librespot[3493]: time="2026-02-26T13:28:09-06:00" level=info msg="zeroconf server listening on port 35431" Feb 26 13:28:09 volumio go-librespot[3493]: time="2026-02-26T13:28:09-06:00" level=debug msg="obtained new client token: AABkyBWy7fLSDL3a3xf0Cqp0aZ+mMDDS7o80naARD0w4qSCET4/QzStg+UJ+rwWVYrP1Hu2r8ILWP6WXaT9sxuX7jiK4KnOp9ZnM9Vuwk2L5pjMd6KZ+hK9OSIG60//zhqYV2jK5NJ+ONP3xZxTtCfmxqdjoUPh5x/cz72eo6aypLTIDjjcejIlcdKdrFOMvePYZsWmk0s1toPg5QX/26CbVQfG9td3GDRQcAtedK6sNqQFwlO6BkW8sAw==" Feb 26 13:28:09 volumio go-librespot[3493]: time="2026-02-26T13:28:09-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 26 13:28:09 volumio go-librespot[3493]: time="2026-02-26T13:28:09-06:00" level=debug msg="completed keyexchange" Feb 26 13:28:09 volumio go-librespot[3493]: time="2026-02-26T13:28:09-06:00" level=debug msg="completed challenge" Feb 26 13:28:09 volumio go-librespot[3493]: time="2026-02-26T13:28: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 " Feb 26 13:28:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 13:28:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 13:28:09 volumio volumio[3413]: info: Loading plugin "alarm-clock"... Feb 26 13:28:10 volumio volumio[3413]: info: Loading plugin "airplay_emulation"... Feb 26 13:28:10 volumio volumio[3413]: info: Starting Shairport Sync Feb 26 13:28:10 volumio volumio[3413]: info: Loading plugin "last_100"... Feb 26 13:28:10 volumio volumio[3413]: info: Loading plugin "webradio"... Feb 26 13:28:10 volumio volumio[3413]: info: Loading plugin "i2s_dacs"... Feb 26 13:28:10 volumio volumio[3413]: info: I2S DAC not set, start Auto-detection Feb 26 13:28:10 volumio volumio[3413]: info: Loading plugin "volumiodiscovery"... Feb 26 13:28:10 volumio volumio[3413]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 26 13:28:10 volumio volumio[3413]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 26 13:28:10 volumio volumio[3413]: *** WARNING *** For more information see Feb 26 13:28:10 volumio volumio[3413]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 26 13:28:10 volumio volumio[3413]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 26 13:28:10 volumio volumio[3413]: *** WARNING *** For more information see Feb 26 13:28:10 volumio node[3413]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 26 13:28:10 volumio node[3413]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 26 13:28:10 volumio node[3413]: *** WARNING *** For more information see Feb 26 13:28:10 volumio node[3413]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 26 13:28:10 volumio node[3413]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 26 13:28:10 volumio node[3413]: *** WARNING *** For more information see Feb 26 13:28:10 volumio volumio[3413]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 26 13:28:10 volumio volumio[3413]: info: Discovery: Started advertising with name: Volumio Feb 26 13:28:10 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 26 13:28:10 volumio volumio[3413]: info: Loading plugin "bandcamp"... Feb 26 13:28:11 volumio volumio[3413]: info: Plugin calmradio is not enabled Feb 26 13:28:11 volumio volumio[3413]: info: Loading plugin "soundcloud"... Feb 26 13:28:11 volumio volumio[3413]: info: Loading plugin "spop"... Feb 26 13:28:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 36. Feb 26 13:28:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:28:12 volumio volumio[3413]: info: Loading plugin "squeezelite_mc"... Feb 26 13:28:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:28:12 volumio go-librespot[3502]: go-librespot daemon starting... Feb 26 13:28:12 volumio go-librespot[3503]: time="2026-02-26T13:28:12-06:00" level=info msg="running go-librespot 0.4.0" Feb 26 13:28:12 volumio go-librespot[3503]: time="2026-02-26T13:28:12-06:00" level=debug msg="app state loaded" Feb 26 13:28:12 volumio go-librespot[3503]: time="2026-02-26T13:28:12-06:00" level=debug msg="stored credentials not found" Feb 26 13:28:12 volumio go-librespot[3503]: time="2026-02-26T13:28:12-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 13:28:13 volumio kernel: hwmon hwmon1: Voltage normalised Feb 26 13:28:13 volumio go-librespot[3503]: time="2026-02-26T13:28:13-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]" Feb 26 13:28:13 volumio go-librespot[3503]: time="2026-02-26T13:28:13-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]" Feb 26 13:28:13 volumio go-librespot[3503]: time="2026-02-26T13:28:13-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]" Feb 26 13:28:13 volumio go-librespot[3503]: time="2026-02-26T13:28:13-06:00" level=info msg="zeroconf server listening on port 41807" Feb 26 13:28:13 volumio go-librespot[3503]: time="2026-02-26T13:28:13-06:00" level=debug msg="obtained new client token: AAD6YvO8UPolAbwKihuYZuet4mDKs8rgNGiQ5lJ2nW/hNjnQpE1mmr+OWoC4MrFZcfvgoT0aEDCvWxBegfEJsY/TdmefC5f0cvA8ehuPv08VGKK/K3ak6WTYCtnEr4UR2LQblJMusPcgoulQZg3VggLh55zNBymoC7FnlQ7UnCTknQpuNjTFUSgCLuSfBTx2QCZRYc8ti0YuuhkslJgcpiNOO7iuEGH1KNnzbafScjBZ4M9FxZeNy+aEag==" Feb 26 13:28:13 volumio go-librespot[3503]: time="2026-02-26T13:28:13-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 26 13:28:13 volumio go-librespot[3503]: time="2026-02-26T13:28:13-06:00" level=debug msg="completed keyexchange" Feb 26 13:28:13 volumio go-librespot[3503]: time="2026-02-26T13:28:13-06:00" level=debug msg="completed challenge" Feb 26 13:28:13 volumio go-librespot[3503]: time="2026-02-26T13:28: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 " Feb 26 13:28:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 13:28:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 13:28:13 volumio volumio[3413]: info: Loading plugin "youtube2"... Feb 26 13:28:14 volumio volumio[3413]: info: Loading plugin "ytcr"... Feb 26 13:28:15 volumio volumio[3413]: info: Loading plugin "ytmusic"... Feb 26 13:28:16 volumio volumio[3413]: info: Plugin now_playing is not enabled Feb 26 13:28:16 volumio volumio[3413]: info: Loading plugin "outputs"... Feb 26 13:28:16 volumio volumio[3413]: info: Loading plugin "albumart"... Feb 26 13:28:16 volumio volumio[3413]: info: Plugin example_plugin is not enabled Feb 26 13:28:16 volumio volumio[3413]: info: Loading plugin "inputs"... Feb 26 13:28:16 volumio volumio[3413]: info: Loading plugin "updater_comm"... Feb 26 13:28:16 volumio volumio[3413]: info: Plugin mpdemulation is not enabled Feb 26 13:28:16 volumio volumio[3413]: info: Loading plugin "rest_api"... Feb 26 13:28:16 volumio volumio[3413]: info: Loading plugin "websocket"... Feb 26 13:28:16 volumio volumio[3413]: info: Starting Socket.io Server version 1.7.4 Feb 26 13:28:16 volumio volumio[3413]: info: Plugin fusiondsp is not enabled Feb 26 13:28:16 volumio volumio[3413]: info: Plugin mpdoutput is not enabled Feb 26 13:28:16 volumio volumio[3413]: info: Plugin RoonBridge is not enabled Feb 26 13:28:16 volumio volumio[3413]: info: Loading plugin "podcast"... Feb 26 13:28:16 volumio volumio[3413]: info: ControllerPodcast::constructor Feb 26 13:28:16 volumio volumio[3413]: info: Loading plugin "volusonic"... Feb 26 13:28:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 37. Feb 26 13:28:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:28:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:28:16 volumio volumio[3511]: Forking 3 albumart workers Feb 26 13:28:16 volumio go-librespot[3536]: go-librespot daemon starting... Feb 26 13:28:16 volumio go-librespot[3537]: time="2026-02-26T13:28:16-06:00" level=info msg="running go-librespot 0.4.0" Feb 26 13:28:16 volumio go-librespot[3537]: time="2026-02-26T13:28:16-06:00" level=debug msg="app state loaded" Feb 26 13:28:16 volumio go-librespot[3537]: time="2026-02-26T13:28:16-06:00" level=debug msg="stored credentials not found" Feb 26 13:28:16 volumio go-librespot[3537]: time="2026-02-26T13:28:16-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 13:28:17 volumio go-librespot[3537]: time="2026-02-26T13:28:17-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 26 13:28:17 volumio go-librespot[3537]: time="2026-02-26T13:28:17-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 26 13:28:17 volumio go-librespot[3537]: time="2026-02-26T13:28:17-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 26 13:28:17 volumio go-librespot[3537]: time="2026-02-26T13:28:17-06:00" level=info msg="zeroconf server listening on port 41659" Feb 26 13:28:17 volumio go-librespot[3537]: time="2026-02-26T13:28:17-06:00" level=debug msg="obtained new client token: AADVNYwDgGTRKIoLeU82SwVfeE+zcUBztfQBNJMWPNpLMO8RK7zir2LK/i4fFFrotPXvfZnrys5XFLWs/pUdFvrXCoBpRlrkvFXyhPSN86+k9W/7Z2WhBucg3DG+PGGUkVtGVEQPyQkqSFDU17lTjwAHhFTS9/PE7xuyRptEZR7qfyGnDK6vS3Wn010wci/+5HBdp7gKNr2RSwQk86VGnOTF77qd0jvPZN7MX5ug8bKYKzW6rwLFXE8=" Feb 26 13:28:17 volumio go-librespot[3537]: time="2026-02-26T13:28:17-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 26 13:28:17 volumio go-librespot[3537]: time="2026-02-26T13:28:17-06:00" level=debug msg="completed keyexchange" Feb 26 13:28:17 volumio go-librespot[3537]: time="2026-02-26T13:28:17-06:00" level=debug msg="completed challenge" Feb 26 13:28:17 volumio go-librespot[3537]: time="2026-02-26T13:28: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 " Feb 26 13:28:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 13:28:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 13:28:18 volumio volumio[3413]: info: Applying required configuration parameters for plugin volusonic Feb 26 13:28:18 volumio volumio[3413]: info: Loading plugin "backup_restore"... Feb 26 13:28:18 volumio volumio[3546]: Starting albumart workers Feb 26 13:28:18 volumio volumio[3545]: Starting albumart workers Feb 26 13:28:18 volumio volumio[3544]: Starting albumart workers Feb 26 13:28:18 volumio volumio[3413]: info: Applying required configuration parameters for plugin backup_restore Feb 26 13:28:18 volumio volumio[3413]: info: Plugin rpi_eeprom_config is not enabled Feb 26 13:28:18 volumio volumio[3413]: info: Plugin rpi_eeprom_updater is not enabled Feb 26 13:28:18 volumio volumio[3413]: info: Loading plugin "scheduledrestart"... Feb 26 13:28:18 volumio volumio[3413]: info: Applying required configuration parameters for plugin scheduledrestart Feb 26 13:28:18 volumio volumio[3413]: info: Plugin Bluetoothremote is not enabled Feb 26 13:28:18 volumio volumio[3413]: info: Plugin music_services_shield is not enabled Feb 26 13:28:18 volumio volumio[3413]: info: Loading plugin "Systeminfo"... Feb 26 13:28:19 volumio volumio-remote-updater[13697]: [2026-02-26 13:28:19] [connect] Successful connection Feb 26 13:28:19 volumio volumio[3413]: info: Plugin peppymeterbasic is not enabled Feb 26 13:28:19 volumio volumio[3413]: info: Loading plugin "peppyspectrum"... Feb 26 13:28:19 volumio volumio[3413]: info: Loading i18n strings for locale en Feb 26 13:28:19 volumio volumio[3413]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Feb 26 13:28:19 volumio volumio[3413]: Updating browse sources language Feb 26 13:28:19 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 13:28:19 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 13:28:19 volumio volumio[3413]: info: CoreCommandRouter::initPlayerControls Feb 26 13:28:19 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:19 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:19 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:19 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:19 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:19 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:19 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:19 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:19 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 13:28:19 volumio volumio[3413]: Express server listening on port 3000 Feb 26 13:28:19 volumio volumio[3413]: [Metrics] WebUI: 16s 214.18ms Feb 26 13:28:19 volumio volumio[3413]: info: CoreStateMachine::resetVolumioState Feb 26 13:28:19 volumio volumio[3413]: info: CoreStateMachine::getcurrentVolume Feb 26 13:28:19 volumio volumio[3413]: info: CoreCommandRouter::volumioRetrievevolume Feb 26 13:28:19 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 13:28:19 volumio sudo[3600]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 26 13:28:19 volumio sudo[3600]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:19 volumio sudo[3600]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:19 volumio sudo[3602]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 26 13:28:19 volumio sudo[3602]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:19 volumio sudo[3602]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:20 volumio volumio[3413]: info: Volumio Network Manager: Network status updated: 1 Feb 26 13:28:20 volumio volumio[3413]: info: VolumeController:: Volume=100 Mute =false Feb 26 13:28:20 volumio volumio[3413]: info: CoreStateMachine::pushState Feb 26 13:28:20 volumio volumio[3413]: info: CorePlayQueue::getTrack 0 Feb 26 13:28:20 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 13:28:20 volumio volumio[3413]: info: CoreCommandRouter::volumioPushState Feb 26 13:28:20 volumio volumio[3413]: info: CoreStateMachine::updateTrackBlock Feb 26 13:28:20 volumio volumio[3413]: info: CorePlayQueue::getTrackBlock Feb 26 13:28:20 volumio volumio[3413]: info: CoreCommandRouter::volumioRetrievevolume Feb 26 13:28:20 volumio volumio-remote-updater[13697]: [2026-02-26 13:28:20] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1772134099 101 Feb 26 13:28:20 volumio volumio[3413]: 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 Feb 26 13:28:20 volumio volumio[3413]: info: Reloading queue from file Feb 26 13:28:20 volumio volumio[3413]: info: CoreStateMachine::setRepeat null single undefined Feb 26 13:28:20 volumio volumio[3413]: info: CoreStateMachine::pushState Feb 26 13:28:20 volumio volumio[3413]: info: CorePlayQueue::getTrack 0 Feb 26 13:28:20 volumio volumio[3413]: info: CoreCommandRouter::volumioPushState Feb 26 13:28:20 volumio volumio[3413]: info: CoreStateMachine::setRandom null Feb 26 13:28:20 volumio volumio[3413]: info: CoreStateMachine::pushState Feb 26 13:28:20 volumio volumio[3413]: info: CorePlayQueue::getTrack 0 Feb 26 13:28:20 volumio volumio[3413]: info: CoreCommandRouter::volumioPushState Feb 26 13:28:20 volumio volumio[3413]: info: Setting Device type: Raspberry PI Feb 26 13:28:20 volumio volumio[3413]: info: VolumeController:: Volume=100 Mute =false Feb 26 13:28:20 volumio volumio[3413]: info: CoreStateMachine::pushState Feb 26 13:28:20 volumio volumio[3413]: info: CorePlayQueue::getTrack 0 Feb 26 13:28:20 volumio volumio[3413]: info: CoreCommandRouter::volumioPushState Feb 26 13:28:20 volumio volumio[3413]: info: Completed loading Core Plugins Feb 26 13:28:20 volumio volumio[3413]: info: Preparing to generate the ALSA configuration file Feb 26 13:28:20 volumio sudo[3616]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 26 13:28:20 volumio sudo[3616]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:20 volumio volumio[3413]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Feb 26 13:28:20 volumio volumio[3413]: info: Discovery: Found device Volumio Feb 26 13:28:20 volumio volumio[3413]: info: CoreCommandRouter::volumioGetState Feb 26 13:28:20 volumio volumio[3413]: info: CorePlayQueue::getTrack 0 Feb 26 13:28:20 volumio volumio[3413]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Feb 26 13:28:20 volumio volumio[3413]: info: Discovery: Found device Volumio Feb 26 13:28:20 volumio volumio[3413]: info: CoreCommandRouter::volumioGetState Feb 26 13:28:20 volumio volumio[3413]: info: CorePlayQueue::getTrack 0 Feb 26 13:28:20 volumio sudo[3616]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:20 volumio volumio[3413]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Feb 26 13:28:20 volumio volumio[3413]: info: Reading ALSA contributions from plugins. Feb 26 13:28:20 volumio volumio[3413]: info: Upmpdcli Daemon Started Feb 26 13:28:20 volumio volumio[3413]: info: Asound.conf file unchanged, so no further update is needed Feb 26 13:28:20 volumio volumio[3413]: info: Output device has changed, restarting MPD Feb 26 13:28:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38. Feb 26 13:28:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:28:20 volumio volumio[3413]: info: Output device has changed, restarting Shairport Sync Feb 26 13:28:20 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:20 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 13:28:20 volumio sudo[3619]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 26 13:28:20 volumio sudo[3619]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:20 volumio sudo[3622]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 26 13:28:20 volumio sudo[3622]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:20 volumio sudo[3619]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:20 volumio volumio[3413]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 26 13:28:20 volumio volumio[3413]: info: ___________ START PLUGINS ___________ Feb 26 13:28:20 volumio volumio[3413]: info: ControllerMpd::onStart: Initializing MPD Feb 26 13:28:20 volumio volumio[3413]: info: Creating MPD Configuration file Feb 26 13:28:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:28:20 volumio go-librespot[3621]: go-librespot daemon starting... Feb 26 13:28:20 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 13:28:20 volumio volumio[3413]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 26 13:28:20 volumio volumio[3413]: info: [1772134100506] CoreMusicLibrary::Adding element Media Servers Feb 26 13:28:20 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 13:28:20 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 26 13:28:20 volumio sudo[3630]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 26 13:28:20 volumio go-librespot[3632]: time="2026-02-26T13:28:20-06:00" level=info msg="running go-librespot 0.4.0" Feb 26 13:28:20 volumio go-librespot[3632]: time="2026-02-26T13:28:20-06:00" level=debug msg="app state loaded" Feb 26 13:28:20 volumio go-librespot[3632]: time="2026-02-26T13:28:20-06:00" level=debug msg="stored credentials not found" Feb 26 13:28:20 volumio sudo[3630]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:20 volumio sudo[3633]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 26 13:28:20 volumio sudo[3633]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:20 volumio sudo[3630]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:20 volumio go-librespot[3632]: time="2026-02-26T13:28:20-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 13:28:20 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:20 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 13:28:20 volumio volumio[3413]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 26 13:28:20 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:20 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 13:28:20 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 26 13:28:20 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 26 13:28:20 volumio systemd[1]: mpd.service: Consumed 4.399s CPU time. Feb 26 13:28:20 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 26 13:28:20 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 26 13:28:20 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 26 13:28:20 volumio volumio[3413]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 26 13:28:20 volumio volumio[3413]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 26 13:28:20 volumio volumio[3413]: info: [1772134100643] CoreMusicLibrary::Adding element Last_100 Feb 26 13:28:20 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 13:28:20 volumio volumio[3413]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 26 13:28:20 volumio volumio[3413]: info: [1772134100648] CoreMusicLibrary::Adding element Webradio Feb 26 13:28:20 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 13:28:20 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 26 13:28:20 volumio volumio[3413]: info: Initializing BBC Radios Feb 26 13:28:20 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 26 13:28:20 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 26 13:28:20 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 26 13:28:20 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 13:28:20 volumio volumio[3413]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 26 13:28:20 volumio volumio[3413]: info: [1772134100769] CoreMusicLibrary::Adding element Bandcamp Discover Feb 26 13:28:20 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 13:28:20 volumio volumio[3413]: Cannot find translation for source Bandcamp Discover Feb 26 13:28:20 volumio volumio[3413]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 26 13:28:20 volumio volumio[3413]: info: [1772134100781] CoreMusicLibrary::Adding element SoundCloud Feb 26 13:28:20 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 13:28:20 volumio volumio[3413]: Cannot find translation for source Bandcamp Discover Feb 26 13:28:20 volumio volumio[3413]: Cannot find translation for source SoundCloud Feb 26 13:28:20 volumio volumio[3413]: info: Creating Spotify config file Feb 26 13:28:20 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:20 volumio go-librespot[3632]: time="2026-02-26T13:28: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]" Feb 26 13:28:20 volumio go-librespot[3632]: time="2026-02-26T13:28: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]" Feb 26 13:28:20 volumio go-librespot[3632]: time="2026-02-26T13:28: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]" Feb 26 13:28:20 volumio go-librespot[3632]: time="2026-02-26T13:28:20-06:00" level=info msg="zeroconf server listening on port 32801" Feb 26 13:28:20 volumio go-librespot[3632]: time="2026-02-26T13:28:20-06:00" level=debug msg="obtained new client token: AABQdjshTZ+JcmN8B5mFfLxeZlSld8aZ7dDXJgvqQTTv44hWBNcdYvy1AkfokAlXPLJnJV6hNmNg/UdK9TWNmrtas+DhdCdoTz8g8XZWRXgrbzNQWmK+e3+iOHowuccqaFEIQEGE0DITgms/3SriTt1QxV+rfAqGkSPSRaAv2f9VH2HThG6rAdxSRtAgEnBpl/wwEVFu1RNNBvCdROl1F98VY3V8CQ1AhiQ8hQbElhO7aeSo8P28KynOHg==" Feb 26 13:28:20 volumio sudo[3658]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 26 13:28:20 volumio sudo[3658]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 26 13:28:20 volumio sudo[3658]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:21 volumio go-librespot[3632]: time="2026-02-26T13:28:21-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 26 13:28:21 volumio go-librespot[3632]: time="2026-02-26T13:28:21-06:00" level=debug msg="completed keyexchange" Feb 26 13:28:21 volumio go-librespot[3632]: time="2026-02-26T13:28:21-06:00" level=debug msg="completed challenge" Feb 26 13:28:21 volumio go-librespot[3632]: time="2026-02-26T13:28: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 " Feb 26 13:28:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 13:28:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 13:28:21 volumio volumio[3413]: info: [squeezelite_mc] Starting proxy server... Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 26 13:28:21 volumio volumio[3413]: info: [1772134101163] CoreMusicLibrary::Adding element YouTube2 Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 13:28:21 volumio volumio[3413]: Cannot find translation for source Bandcamp Discover Feb 26 13:28:21 volumio volumio[3413]: Cannot find translation for source SoundCloud Feb 26 13:28:21 volumio volumio[3413]: Cannot find translation for source YouTube2 Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 26 13:28:21 volumio volumio[3413]: info: [1772134101182] CoreMusicLibrary::Adding element YouTube Music Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 13:28:21 volumio volumio[3413]: Cannot find translation for source Bandcamp Discover Feb 26 13:28:21 volumio volumio[3413]: Cannot find translation for source SoundCloud Feb 26 13:28:21 volumio volumio[3413]: Cannot find translation for source YouTube2 Feb 26 13:28:21 volumio volumio[3413]: Cannot find translation for source YouTube Music Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 26 13:28:21 volumio volumio[3413]: info: [1772134101194] CoreMusicLibrary::Adding element Podcast Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 13:28:21 volumio volumio[3413]: Cannot find translation for source Bandcamp Discover Feb 26 13:28:21 volumio volumio[3413]: Cannot find translation for source SoundCloud Feb 26 13:28:21 volumio volumio[3413]: Cannot find translation for source YouTube2 Feb 26 13:28:21 volumio volumio[3413]: Cannot find translation for source YouTube Music Feb 26 13:28:21 volumio volumio[3413]: Cannot find translation for source Podcast Feb 26 13:28:21 volumio volumio[3413]: info: Loading i18n strings for locale en Feb 26 13:28:21 volumio volumio[3413]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Feb 26 13:28:21 volumio volumio[3413]: Updating browse sources language Feb 26 13:28:21 volumio volumio[3413]: Cannot find translation for source Bandcamp Discover Feb 26 13:28:21 volumio volumio[3413]: Cannot find translation for source SoundCloud Feb 26 13:28:21 volumio volumio[3413]: Cannot find translation for source YouTube2 Feb 26 13:28:21 volumio volumio[3413]: Cannot find translation for source YouTube Music Feb 26 13:28:21 volumio volumio[3413]: Cannot find translation for source Podcast Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 13:28:21 volumio volumio[3413]: Cannot find translation for source Bandcamp Discover Feb 26 13:28:21 volumio volumio[3413]: Cannot find translation for source SoundCloud Feb 26 13:28:21 volumio volumio[3413]: Cannot find translation for source YouTube2 Feb 26 13:28:21 volumio volumio[3413]: Cannot find translation for source YouTube Music Feb 26 13:28:21 volumio volumio[3413]: Cannot find translation for source Podcast Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 26 13:28:21 volumio volumio[3413]: info: [1772134101241] CoreMusicLibrary::Adding element Volusonic Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 13:28:21 volumio volumio[3413]: Cannot find translation for source Bandcamp Discover Feb 26 13:28:21 volumio volumio[3413]: Cannot find translation for source SoundCloud Feb 26 13:28:21 volumio volumio[3413]: Cannot find translation for source YouTube2 Feb 26 13:28:21 volumio volumio[3413]: Cannot find translation for source YouTube Music Feb 26 13:28:21 volumio volumio[3413]: Cannot find translation for source Podcast Feb 26 13:28:21 volumio volumio[3413]: Cannot find translation for source Volusonic Feb 26 13:28:21 volumio volumio[3413]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Feb 26 13:28:21 volumio volumio[3413]: info: Volumio Calling Home Feb 26 13:28:21 volumio volumio[3413]: info: [squeezelite_mc] Proxy server started on port 35259 Feb 26 13:28:21 volumio volumio[3413]: info: Preparing to generate the ALSA configuration file Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::volumioRetrievevolume Feb 26 13:28:21 volumio volumio[3413]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Feb 26 13:28:21 volumio volumio[3413]: info: Reading ALSA contributions from plugins. Feb 26 13:28:21 volumio volumio[3413]: info: MPD Permissions set Feb 26 13:28:21 volumio volumio[3413]: info: MPD Permissions set Feb 26 13:28:21 volumio volumio[3413]: info: Spotify config file written Feb 26 13:28:21 volumio sudo[3673]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 26 13:28:21 volumio sudo[3673]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:21 volumio volumio[3413]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 26 13:28:21 volumio volumio[3413]: info: VolumeController:: Volume=100 Mute =false Feb 26 13:28:21 volumio volumio[3413]: info: CoreStateMachine::pushState Feb 26 13:28:21 volumio volumio[3413]: info: CorePlayQueue::getTrack 0 Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::volumioPushState Feb 26 13:28:21 volumio volumio[3413]: info: [squeezelite_mc] Server discovery started Feb 26 13:28:21 volumio volumio[3413]: info: [squeezelite_mc] Player finder started Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 13:28:21 volumio volumio[3413]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Feb 26 13:28:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:21 volumio volumio[3413]: info: No need to fix Spotify hosts Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:28:21 volumio go-librespot[3676]: go-librespot daemon starting... Feb 26 13:28:21 volumio sudo[3673]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 13:28:21 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:21 volumio go-librespot[3685]: time="2026-02-26T13:28:21-06:00" level=info msg="running go-librespot 0.4.0" Feb 26 13:28:21 volumio go-librespot[3685]: time="2026-02-26T13:28:21-06:00" level=debug msg="app state loaded" Feb 26 13:28:21 volumio go-librespot[3685]: time="2026-02-26T13:28:21-06:00" level=debug msg="stored credentials not found" Feb 26 13:28:21 volumio go-librespot[3685]: time="2026-02-26T13:28:21-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 13:28:21 volumio volumio[3413]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 26 13:28:21 volumio volumio[3413]: info: Volumio called home Feb 26 13:28:21 volumio volumio[3413]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Feb 26 13:28:21 volumio volumio[3413]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Feb 26 13:28:21 volumio volumio[3413]: 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 Feb 26 13:28:21 volumio volumio[3413]: info: Starting Shairport Sync Feb 26 13:28:21 volumio volumio[3413]: info: Starting Shairport Sync Feb 26 13:28:22 volumio volumio[3413]: info: Starting Shairport Sync Feb 26 13:28:22 volumio sudo[3700]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 26 13:28:22 volumio sudo[3700]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:22 volumio sudo[3702]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 26 13:28:22 volumio sudo[3702]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:22 volumio sudo[3697]: 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 Feb 26 13:28:22 volumio sudo[3697]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:22 volumio sudo[3697]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:22 volumio sudo[3705]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 26 13:28:22 volumio sudo[3705]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:22 volumio volumio[3413]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Feb 26 13:28:22 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 26 13:28:22 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 26 13:28:22 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 26 13:28:22 volumio systemd[1]: shairport-sync.service: Consumed 2.011s CPU time. Feb 26 13:28:22 volumio volumio[3413]: info: Asound.conf file unchanged, so no further update is needed Feb 26 13:28:22 volumio volumio[3413]: info: Output device has changed, restarting MPD Feb 26 13:28:22 volumio sudo[3711]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Feb 26 13:28:22 volumio sudo[3711]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:22 volumio sudo[3714]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 26 13:28:22 volumio sudo[3714]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:22 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 26 13:28:22 volumio sudo[3711]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:22 volumio sudo[3702]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:22 volumio sudo[3700]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:22 volumio volumio[3413]: info: Output device has changed, restarting Shairport Sync Feb 26 13:28:22 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:22 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 13:28:22 volumio sudo[3705]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:22 volumio sudo[3714]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:22 volumio sudo[3719]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 26 13:28:22 volumio sudo[3719]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:22 volumio volumio[3413]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 26 13:28:22 volumio go-librespot[3685]: time="2026-02-26T13:28:22-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 26 13:28:22 volumio go-librespot[3685]: time="2026-02-26T13:28:22-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]" Feb 26 13:28:22 volumio go-librespot[3685]: time="2026-02-26T13:28:22-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]" Feb 26 13:28:22 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 26 13:28:22 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 26 13:28:22 volumio systemd[1]: mpd.service: Consumed 1.512s CPU time. Feb 26 13:28:22 volumio go-librespot[3685]: time="2026-02-26T13:28:22-06:00" level=info msg="zeroconf server listening on port 46777" Feb 26 13:28:22 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 26 13:28:22 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 26 13:28:22 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 26 13:28:22 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 26 13:28:22 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 26 13:28:22 volumio go-librespot[3685]: time="2026-02-26T13:28:22-06:00" level=debug msg="obtained new client token: AACsGdI2K0TMUEHwiJxSnEDseBhjG/Zd04Qu3pBVldR6m3NRoLimkdz5tKqYS2oGpcX1RqwIMLLsdtZTvsBQOONZ3yF+qVSmh1PqVHSoDdqp0DnO/zga3RBPtCTXcsAZrU7yRG1W6LzAOqJJ1mJf23mEqhBIggP1cP8eF6wKdPKYvHwjod08u1AhdsSxzxBA1+kEU9LiFc/yDHdzxQXYXOKKsIHrC2wii8N3ICU8cTshP5lahtDUGB8kFQ==" Feb 26 13:28:22 volumio volumio[3413]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 26 13:28:22 volumio volumio[3413]: SPOTIFY: BQAYoS6ZAvTXrux4XDOdPe-epY2ogZlD3wUh0lvehw_bBN7EuF6AUa9M1qy8i1sQJF-M_Trk7wiRitZJ8Rl7yvE1uEHp2ooXBOyk30TTA-5pcWCo8Svffjzq6nMpl6kYmLTY1kNA8-D6oHpCA5cCPoqJjVWJQvbAo5OEYVEbStO2yv4AYrn4W18hDcFK5tytn0hHTMI6fX5DHTIdr9hVcF8aWmm5sP-lNjikBCM Feb 26 13:28:22 volumio volumio[3413]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 26 13:28:22 volumio volumio[3413]: info: New Spotify access token = BQAYoS6ZAvTXrux4XDOdPe-epY2ogZlD3wUh0lvehw_bBN7EuF6AUa9M1qy8i1sQJF-M_Trk7wiRitZJ8Rl7yvE1uEHp2ooXBOyk30TTA-5pcWCo8Svffjzq6nMpl6kYmLTY1kNA8-D6oHpCA5cCPoqJjVWJQvbAo5OEYVEbStO2yv4AYrn4W18hDcFK5tytn0hHTMI6fX5DHTIdr9hVcF8aWmm5sP-lNjikBCM Feb 26 13:28:22 volumio volumio[3413]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 26 13:28:22 volumio go-librespot[3685]: time="2026-02-26T13:28:22-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 26 13:28:22 volumio volumio[3413]: info: MPD Permissions set Feb 26 13:28:22 volumio volumio[3413]: info: Shairport-Sync Started Feb 26 13:28:22 volumio volumio[3413]: Error adding Membership: Error: addMembership EINVAL Feb 26 13:28:22 volumio volumio[3413]: info: Shairport-Sync Started Feb 26 13:28:22 volumio volumio[3413]: info: Shairport-Sync Started Feb 26 13:28:22 volumio volumio[3413]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Feb 26 13:28:22 volumio go-librespot[3685]: time="2026-02-26T13:28:22-06:00" level=debug msg="completed keyexchange" Feb 26 13:28:22 volumio go-librespot[3685]: time="2026-02-26T13:28:22-06:00" level=debug msg="completed challenge" Feb 26 13:28:22 volumio go-librespot[3685]: time="2026-02-26T13:28:22-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 13:28:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 13:28:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 13:28:22 volumio sudo[3747]: 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 Feb 26 13:28:22 volumio sudo[3747]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:22 volumio sudo[3747]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:22 volumio sudo[3743]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 26 13:28:22 volumio sudo[3743]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 26 13:28:22 volumio sudo[3743]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:22 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:22 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:22 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:22 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:22 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:22 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:22 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:22 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:22 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 13:28:22 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:22 volumio volumio[3413]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Feb 26 13:28:22 volumio volumio[3413]: info: CoreCommandRouter::volumioGetState Feb 26 13:28:22 volumio volumio[3413]: info: CorePlayQueue::getTrack 0 Feb 26 13:28:22 volumio sudo[3757]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Feb 26 13:28:22 volumio sudo[3757]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:22 volumio volumio[3413]: info: Starting Shairport Sync Feb 26 13:28:22 volumio systemd[1]: Reloading. Feb 26 13:28:22 volumio sudo[3760]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 26 13:28:22 volumio sudo[3760]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:23 volumio volumio[3413]: 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"} Feb 26 13:28:23 volumio volumio[3413]: info: Spotify Successfully logged in Feb 26 13:28:23 volumio volumio[3413]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 26 13:28:23 volumio volumio[3413]: info: [1772134103036] CoreMusicLibrary::Adding element Spotify Feb 26 13:28:23 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 13:28:23 volumio volumio[3413]: Cannot find translation for source Bandcamp Discover Feb 26 13:28:23 volumio volumio[3413]: Cannot find translation for source SoundCloud Feb 26 13:28:23 volumio volumio[3413]: Cannot find translation for source YouTube2 Feb 26 13:28:23 volumio volumio[3413]: Cannot find translation for source YouTube Music Feb 26 13:28:23 volumio volumio[3413]: Cannot find translation for source Podcast Feb 26 13:28:23 volumio volumio[3413]: Cannot find translation for source Volusonic Feb 26 13:28:23 volumio volumio[3413]: Cannot find translation for source Spotify Feb 26 13:28:23 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:23 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:23 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 13:28:23 volumio volumio[3413]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 13:28:24 volumio volumio[3413]: info: go-librespot daemon successfully initialized Feb 26 13:28:25 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 26 13:28:25 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 26 13:28:25 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 26 13:28:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 39. Feb 26 13:28:25 volumio sudo[3757]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:25 volumio volumio[3413]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 26 13:28:26 volumio sudo[3781]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 26 13:28:26 volumio sudo[3781]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:28:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:28:26 volumio go-librespot[3783]: go-librespot daemon starting... Feb 26 13:28:26 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 26 13:28:26 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 26 13:28:26 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 26 13:28:26 volumio systemd[1]: shairport-sync.service: Consumed 1.455s CPU time. Feb 26 13:28:26 volumio go-librespot[3784]: time="2026-02-26T13:28:26-06:00" level=info msg="running go-librespot 0.4.0" Feb 26 13:28:26 volumio go-librespot[3784]: time="2026-02-26T13:28:26-06:00" level=debug msg="app state loaded" Feb 26 13:28:26 volumio go-librespot[3784]: time="2026-02-26T13:28:26-06:00" level=debug msg="stored credentials not found" Feb 26 13:28:26 volumio go-librespot[3784]: time="2026-02-26T13:28:26-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 13:28:26 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 26 13:28:26 volumio sudo[3760]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:26 volumio volumio[3413]: info: Shairport-Sync Started Feb 26 13:28:26 volumio sudo[3781]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:26 volumio volumio[3413]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Feb 26 13:28:26 volumio sudo[3817]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Feb 26 13:28:26 volumio sudo[3817]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:26 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 26 13:28:26 volumio go-librespot[3784]: time="2026-02-26T13:28:26-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]" Feb 26 13:28:26 volumio go-librespot[3784]: time="2026-02-26T13:28:26-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]" Feb 26 13:28:26 volumio go-librespot[3784]: time="2026-02-26T13:28:26-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]" Feb 26 13:28:26 volumio systemd[1]: squeezelite.service: Deactivated successfully. Feb 26 13:28:26 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 26 13:28:26 volumio go-librespot[3784]: time="2026-02-26T13:28:26-06:00" level=info msg="zeroconf server listening on port 39357" Feb 26 13:28:26 volumio sudo[3817]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:26 volumio go-librespot[3784]: time="2026-02-26T13:28:26-06:00" level=debug msg="obtained new client token: AACus9ACyuzptdKc6TFBI9G9bNseYeRb+1okAccTt/zcPbC/2IdFZR04AhOJQJ4pkWfLv3hW1q66ZDrUlnaNkpYRhEqSYG69Cnvrq9aW55JFlpodmQLuyR2cLOtpBybPe2fpu0j0G8WWAf341eP9Hcle2zxFjKby8RmPsj+OQnbHl2TNL6bMWo4tDUni9Z80yp84MzUe9+5xTwusj35D4Jvjc2b3lZdSlkxYjcShKHKN1SqdxWNhsXgLbQ==" Feb 26 13:28:27 volumio go-librespot[3784]: time="2026-02-26T13:28:27-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 26 13:28:27 volumio go-librespot[3784]: time="2026-02-26T13:28:27-06:00" level=debug msg="completed keyexchange" Feb 26 13:28:27 volumio go-librespot[3784]: time="2026-02-26T13:28:27-06:00" level=debug msg="completed challenge" Feb 26 13:28:27 volumio volumio[3413]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 26 13:28:27 volumio sudo[3826]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 26 13:28:27 volumio sudo[3826]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:27 volumio go-librespot[3784]: time="2026-02-26T13:28:27-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 " Feb 26 13:28:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 13:28:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 13:28:27 volumio sudo[3826]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:27 volumio volumio[3413]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Feb 26 13:28:27 volumio sudo[3830]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Feb 26 13:28:27 volumio sudo[3830]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:27 volumio sudo[3830]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:27 volumio volumio[3413]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Feb 26 13:28:27 volumio sudo[3833]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Feb 26 13:28:27 volumio sudo[3833]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:27 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 26 13:28:27 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 26 13:28:27 volumio sudo[3833]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:27 volumio volumio[3413]: info: Initializing connection to go-librespot Websocket Feb 26 13:28:27 volumio mpd[3750]: 2026-02-26T13:28:27 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 26 13:28:27 volumio volumio[3413]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 13:28:28 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 26 13:28:28 volumio sudo[3719]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:28 volumio sudo[3633]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:28 volumio sudo[3622]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:28 volumio volumio[3413]: error: MPD error: The expression evaluated to a falsy value: Feb 26 13:28:28 volumio volumio[3413]: assert.ok(self.idling) Feb 26 13:28:28 volumio volumio[3413]: error: The expression evaluated to a falsy value: Feb 26 13:28:28 volumio volumio[3413]: assert.ok(self.idling) Feb 26 13:28:28 volumio volumio[3413]: error: MPD error: The expression evaluated to a falsy value: Feb 26 13:28:28 volumio volumio[3413]: assert.ok(self.idling) Feb 26 13:28:28 volumio volumio[3413]: error: The expression evaluated to a falsy value: Feb 26 13:28:28 volumio volumio[3413]: assert.ok(self.idling) Feb 26 13:28:28 volumio volumio[3413]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 26 13:28:28 volumio volumio[3413]: info: MPD running with PID3750 Feb 26 13:28:28 volumio volumio[3413]: ,establishing connection Feb 26 13:28:28 volumio volumio[3413]: error: updateQueue error: null Feb 26 13:28:28 volumio volumio[3413]: error: updateQueue error: null Feb 26 13:28:28 volumio sudo[3844]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 26 13:28:28 volumio sudo[3844]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:28 volumio sudo[3844]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:28 volumio volumio[3413]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 26 13:28:28 volumio sudo[3847]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 26 13:28:28 volumio sudo[3847]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:28 volumio sudo[3847]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:29 volumio volumio[3413]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 26 13:28:29 volumio sudo[3850]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 26 13:28:29 volumio sudo[3850]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:29 volumio sudo[3850]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:29 volumio kernel: hwmon hwmon1: Voltage normalised Feb 26 13:28:30 volumio volumio[3413]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 26 13:28:30 volumio sudo[3854]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 26 13:28:30 volumio sudo[3854]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:30 volumio sudo[3854]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 40. Feb 26 13:28:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:28:30 volumio volumio[3413]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 26 13:28:30 volumio sudo[3858]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 26 13:28:30 volumio sudo[3858]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:28:30 volumio go-librespot[3856]: go-librespot daemon starting... Feb 26 13:28:30 volumio go-librespot[3860]: time="2026-02-26T13:28:30-06:00" level=info msg="running go-librespot 0.4.0" Feb 26 13:28:30 volumio go-librespot[3860]: time="2026-02-26T13:28:30-06:00" level=debug msg="app state loaded" Feb 26 13:28:30 volumio go-librespot[3860]: time="2026-02-26T13:28:30-06:00" level=debug msg="stored credentials not found" Feb 26 13:28:30 volumio go-librespot[3860]: time="2026-02-26T13:28:30-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 13:28:30 volumio sudo[3858]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:30 volumio volumio[3413]: info: Completed starting Core Plugins Feb 26 13:28:30 volumio volumio[3413]: info: ------------------------------------------- Feb 26 13:28:30 volumio volumio[3413]: info: ----- MyVolumio plugins startup ---- Feb 26 13:28:30 volumio volumio[3413]: info: ------------------------------------------- Feb 26 13:28:30 volumio volumio[3413]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 26 13:28:30 volumio volumio[3413]: info: Initializing connection to go-librespot Websocket Feb 26 13:28:30 volumio go-librespot[3860]: time="2026-02-26T13:28:30-06:00" level=debug msg="new websocket client" Feb 26 13:28:30 volumio go-librespot[3860]: time="2026-02-26T13:28:30-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]" Feb 26 13:28:30 volumio go-librespot[3860]: time="2026-02-26T13:28:30-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]" Feb 26 13:28:30 volumio go-librespot[3860]: time="2026-02-26T13:28:30-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]" Feb 26 13:28:30 volumio volumio[3413]: info: Connection to go-librespot Websocket established Feb 26 13:28:30 volumio go-librespot[3860]: time="2026-02-26T13:28:30-06:00" level=info msg="zeroconf server listening on port 44439" Feb 26 13:28:31 volumio go-librespot[3860]: time="2026-02-26T13:28:31-06:00" level=debug msg="obtained new client token: AABEU0vAF0A+rYy2WAmXPsSVwDEU6k38INKyQ7zRdSTwW0z0gABeBSF0MrD4Mfoge6MZD94n4kusUoA+8Viv9BS6lGuuoeV6lTCP7Yt//BNFuzeEDoCuG4uY6H5D9Kda5n01dDm6P9PueJZWsgkOGhZ7/CbiDuF3JnENWJN+AD5bjGNE3PufN4MITDzX986VPoC8BjTStOguKJZCPMy5JnA/gjb/xKa8apM/qnMagTZ/NchyE55yf0E=" Feb 26 13:28:31 volumio go-librespot[3860]: time="2026-02-26T13:28:31-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 26 13:28:31 volumio go-librespot[3860]: time="2026-02-26T13:28:31-06:00" level=debug msg="completed keyexchange" Feb 26 13:28:31 volumio go-librespot[3860]: time="2026-02-26T13:28:31-06:00" level=debug msg="completed challenge" Feb 26 13:28:31 volumio sudo[3869]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 26 13:28:31 volumio sudo[3869]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:31 volumio sudo[3871]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 26 13:28:31 volumio sudo[3871]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:31 volumio sudo[3874]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 26 13:28:31 volumio sudo[3874]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 13:28:31 volumio go-librespot[3860]: time="2026-02-26T13:28: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 " Feb 26 13:28:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 13:28:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 13:28:31 volumio volumio[3413]: info: Connection to go-librespot Websocket closed Feb 26 13:28:31 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 26 13:28:31 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 26 13:28:31 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 26 13:28:31 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 26 13:28:31 volumio sudo[3874]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:31 volumio sudo[3871]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:31 volumio sudo[3869]: pam_unix(sudo:session): session closed for user root Feb 26 13:28:31 volumio mpd_monitor.sh[3877]: MPD Monitor Service: Starting MPD Monitor Service Feb 26 13:28:31 volumio volumio[3413]: info: Successfully started MPD Monitor Feb 26 13:28:31 volumio volumio[3413]: info: Successfully started MPD Monitor Feb 26 13:28:31 volumio volumio[3413]: info: Successfully started MPD Monitor Feb 26 13:28:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 41. Feb 26 13:28:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:28:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 13:28:34 volumio go-librespot[3882]: go-librespot daemon starting... Feb 26 13:28:34 volumio go-librespot[3883]: time="2026-02-26T13:28:34-06:00" level=info msg="running go-librespot 0.4.0" Feb 26 13:28:34 volumio go-librespot[3883]: time="2026-02-26T13:28:34-06:00" level=debug msg="app state loaded" Feb 26 13:28:34 volumio go-librespot[3883]: time="2026-02-26T13:28:34-06:00" level=debug msg="stored credentials not found" Feb 26 13:28:34 volumio go-librespot[3883]: time="2026-02-26T13:28:34-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 13:28:34 volumio volumio[3413]: info: Getting Spotify volume Feb 26 13:28:34 volumio volumio[3413]: info: Initializing connection to go-librespot Websocket Feb 26 13:28:34 volumio go-librespot[3883]: time="2026-02-26T13:28:34-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]" Feb 26 13:28:34 volumio go-librespot[3883]: time="2026-02-26T13:28:34-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]" Feb 26 13:28:34 volumio go-librespot[3883]: time="2026-02-26T13:28:34-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]" Feb 26 13:28:34 volumio go-librespot[3883]: time="2026-02-26T13:28:34-06:00" level=info msg="zeroconf server listening on port 46693" Feb 26 13:28:34 volumio go-librespot[3883]: time="2026-02-26T13:28:34-06:00" level=debug msg="obtained new client token: AACKEIV3zVLwqu9v4wUzgGjg7wPMLjv9yVaImNxJarO5rQXkfNun0yop2yWZY4A06DeuozxbqW9HCxLxDkkQI3q89cLRe/o0coX+IP4Lf9NPhPBiK7XEobpe1EAROLu1TCOemV0PtfhOcCAk359KGWohp91VDAkzsKFUEm42sCqLdWh9ZidKGVVSfedFsDgjOm62Zw64BGWQiubsw9hyCVwzEAJsMskPchMBssZ5+TKvXueySmD7LzGzqQ==" Feb 26 13:28:35 volumio go-librespot[3883]: time="2026-02-26T13:28:35-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 26 13:28:35 volumio go-librespot[3883]: time="2026-02-26T13:28:35-06:00" level=debug msg="completed keyexchange" Feb 26 13:28:35 volumio go-librespot[3883]: time="2026-02-26T13:28:35-06:00" level=debug msg="completed challenge" Feb 26 13:28:35 volumio go-librespot[3883]: time="2026-02-26T13:28: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 " Feb 26 13:28:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 13:28:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 13:28:36 volumio volumio[3413]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 26 13:28:36 volumio volumio[3413]: Error: socket hang up Feb 26 13:28:36 volumio volumio[3413]: at connResetException (node:internal/errors:720:14) Feb 26 13:28:36 volumio volumio[3413]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 26 13:28:36 volumio volumio[3413]: at Socket.emit (node:events:526:35) Feb 26 13:28:36 volumio volumio[3413]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 26 13:28:36 volumio volumio[3413]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 26 13:28:36 volumio volumio[3413]: code: 'ECONNRESET', Feb 26 13:28:36 volumio volumio[3413]: response: undefined Feb 26 13:28:36 volumio volumio[3413]: } Feb 26 13:28:36 volumio volumio[3413]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 26 13:28:36 volumio sudo[3918]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-26 13:27' Feb 26 13:28:36 volumio sudo[3918]: 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"