Feb 12 13:43:00 volumio sudo[13600]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Feb 12 13:43:00 volumio sudo[13600]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:00 volumio go-librespot[13584]: time="2026-02-12T13:43:00-06:00" level=debug msg="obtained new client token: AAA4jwoRLvANA/7NiY7+e0u5rfg3E8sfMgjv81gsBamyPgUryhmtMcggCSVhZMIHOVeryzz2edst/KJheQjW4TV0NwgJpmLyvhs0Kz85dX/uR52b0fD7rRZvakf0JfTde7Q1Y8rZAK2NENZLSqE/YNW5FCuAffrE/keC8jInSz1ZYcPS2EKqqeymL8WK4s7JB3QX3bPEmxCBjBZcmGdCjTq8gwxtGiUTk4vOh+xieKoHtYonpvy3DVU=" Feb 12 13:43:00 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 12 13:43:00 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 12 13:43:00 volumio sudo[13600]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:00 volumio go-librespot[13584]: time="2026-02-12T13:43:00-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 13:43:00 volumio go-librespot[13584]: time="2026-02-12T13:43:00-06:00" level=debug msg="completed keyexchange" Feb 12 13:43:00 volumio go-librespot[13584]: time="2026-02-12T13:43:00-06:00" level=debug msg="completed challenge" Feb 12 13:43:00 volumio go-librespot[13584]: time="2026-02-12T13:43:00-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 13:43:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:43:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:43:00 volumio volumio[13175]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 13:43:00 volumio sudo[13607]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 13:43:00 volumio sudo[13607]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:00 volumio sudo[13607]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:01 volumio volumio[13175]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 13:43:01 volumio sudo[13610]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 13:43:01 volumio sudo[13610]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:01 volumio sudo[13610]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:01 volumio volumio[13175]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 13:43:01 volumio sudo[13613]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 13:43:01 volumio sudo[13613]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:01 volumio sudo[13613]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:02 volumio mpd[13546]: 2026-02-12T13:43:01 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 12 13:43:02 volumio volumio[13175]: info: Initializing connection to go-librespot Websocket Feb 12 13:43:02 volumio volumio[13175]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 13:43:02 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 12 13:43:02 volumio sudo[13483]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:02 volumio sudo[13393]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:02 volumio sudo[13403]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:02 volumio volumio[13175]: error: MPD error: The expression evaluated to a falsy value: Feb 12 13:43:02 volumio volumio[13175]: assert.ok(self.idling) Feb 12 13:43:02 volumio volumio[13175]: error: The expression evaluated to a falsy value: Feb 12 13:43:02 volumio volumio[13175]: assert.ok(self.idling) Feb 12 13:43:02 volumio volumio[13175]: error: MPD error: The expression evaluated to a falsy value: Feb 12 13:43:02 volumio volumio[13175]: assert.ok(self.idling) Feb 12 13:43:02 volumio volumio[13175]: error: The expression evaluated to a falsy value: Feb 12 13:43:02 volumio volumio[13175]: assert.ok(self.idling) Feb 12 13:43:02 volumio volumio[13175]: info: MPD running with PID13546 Feb 12 13:43:02 volumio volumio[13175]: ,establishing connection Feb 12 13:43:02 volumio volumio[13175]: error: updateQueue error: null Feb 12 13:43:02 volumio volumio[13175]: error: updateQueue error: null Feb 12 13:43:02 volumio volumio[13175]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 13:43:02 volumio sudo[13620]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 13:43:02 volumio sudo[13620]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:02 volumio sudo[13620]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:03 volumio volumio[13175]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 13:43:03 volumio sudo[13623]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 13:43:03 volumio sudo[13623]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:03 volumio sudo[13623]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:03 volumio volumio[13175]: info: Completed starting Core Plugins Feb 12 13:43:03 volumio volumio[13175]: info: ------------------------------------------- Feb 12 13:43:03 volumio volumio[13175]: info: ----- MyVolumio plugins startup ---- Feb 12 13:43:03 volumio volumio[13175]: info: ------------------------------------------- Feb 12 13:43:03 volumio volumio[13175]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 12 13:43:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 62. Feb 12 13:43:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:43:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:43:03 volumio go-librespot[13625]: go-librespot daemon starting... Feb 12 13:43:03 volumio go-librespot[13626]: time="2026-02-12T13:43:03-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:43:03 volumio go-librespot[13626]: time="2026-02-12T13:43:03-06:00" level=debug msg="app state loaded" Feb 12 13:43:03 volumio go-librespot[13626]: time="2026-02-12T13:43:03-06:00" level=debug msg="stored credentials not found" Feb 12 13:43:03 volumio go-librespot[13626]: time="2026-02-12T13:43:03-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:43:03 volumio go-librespot[13626]: time="2026-02-12T13:43:03-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:43:03 volumio go-librespot[13626]: time="2026-02-12T13:43:03-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 12 13:43:03 volumio go-librespot[13626]: time="2026-02-12T13:43:03-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 12 13:43:03 volumio go-librespot[13626]: time="2026-02-12T13:43:03-06:00" level=info msg="zeroconf server listening on port 45699" Feb 12 13:43:03 volumio go-librespot[13626]: time="2026-02-12T13:43:03-06:00" level=debug msg="obtained new client token: AABAGlhNK4OnbPqMfkEjMxotEiyXNFUF9ddM34L5Tg8LNVhFnYZorL9qis+MAt/PBCwSqZTcJ/FZ/AY00IxeRxK/WAF3N5/MrKTLQtZGaGPSZU5vKJXlJOqRZvz3LPo1goDgM2QX6+/q55K1RhbG4SmofkZDItfBrWFqwkdNz5rdoVVMBUQI1mmIcQ7zMnUIu4WDb89rwE0c+5N0E8sojE6PTuvJwuaZc/2ygtLmvTf+D73opHfRS0STUw==" Feb 12 13:43:03 volumio go-librespot[13626]: time="2026-02-12T13:43:03-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 13:43:04 volumio go-librespot[13626]: time="2026-02-12T13:43:04-06:00" level=debug msg="completed keyexchange" Feb 12 13:43:04 volumio go-librespot[13626]: time="2026-02-12T13:43:04-06:00" level=debug msg="completed challenge" Feb 12 13:43:04 volumio go-librespot[13626]: time="2026-02-12T13:43:04-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 13:43:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:43:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:43:05 volumio volumio[13175]: info: Initializing connection to go-librespot Websocket Feb 12 13:43:05 volumio volumio[13175]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 13:43:05 volumio sudo[13634]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 12 13:43:05 volumio sudo[13634]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:05 volumio sudo[13636]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 12 13:43:05 volumio sudo[13636]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:05 volumio sudo[13638]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 12 13:43:05 volumio sudo[13638]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:05 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 12 13:43:05 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 12 13:43:05 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 12 13:43:05 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 12 13:43:05 volumio sudo[13638]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:05 volumio sudo[13634]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:05 volumio sudo[13636]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:05 volumio mpd_monitor.sh[13642]: MPD Monitor Service: Starting MPD Monitor Service Feb 12 13:43:05 volumio volumio[13175]: info: Successfully started MPD Monitor Feb 12 13:43:05 volumio volumio[13175]: info: Successfully started MPD Monitor Feb 12 13:43:05 volumio volumio[13175]: info: Successfully started MPD Monitor Feb 12 13:43:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 63. Feb 12 13:43:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:43:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:43:07 volumio go-librespot[13646]: go-librespot daemon starting... Feb 12 13:43:07 volumio go-librespot[13647]: time="2026-02-12T13:43:07-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:43:07 volumio go-librespot[13647]: time="2026-02-12T13:43:07-06:00" level=debug msg="app state loaded" Feb 12 13:43:07 volumio go-librespot[13647]: time="2026-02-12T13:43:07-06:00" level=debug msg="stored credentials not found" Feb 12 13:43:07 volumio go-librespot[13647]: time="2026-02-12T13:43:07-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:43:07 volumio go-librespot[13647]: time="2026-02-12T13:43:07-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 12 13:43:07 volumio go-librespot[13647]: time="2026-02-12T13:43:07-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 12 13:43:07 volumio go-librespot[13647]: time="2026-02-12T13:43:07-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 12 13:43:07 volumio go-librespot[13647]: time="2026-02-12T13:43:07-06:00" level=info msg="zeroconf server listening on port 36219" Feb 12 13:43:07 volumio go-librespot[13647]: time="2026-02-12T13:43:07-06:00" level=debug msg="obtained new client token: AAD7mVc9SaexxW6B+JbjxmZP9P49p6tl3LATy/A2Wy1KLoBPJet8MuUWQtWYksuo4INeZ3KMeMtA6r9uVPkXRC55KCrtNV1TN+C5XIqFRvYG5bYoicPAvg5JLPFZQOMotO+yYk2y8Mx2Xo0ts3GsetCdOuLlNY726k3LHeiB5q1ZBDSWR1Y0Sny/e7MHRqB9QNugsOTTH6Rd7WR94pVNrnOPyh5I996izBFpeBoxJ0MHrxyEthlF17t0pQ==" Feb 12 13:43:07 volumio go-librespot[13647]: time="2026-02-12T13:43:07-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 13:43:07 volumio go-librespot[13647]: time="2026-02-12T13:43:07-06:00" level=debug msg="completed keyexchange" Feb 12 13:43:07 volumio go-librespot[13647]: time="2026-02-12T13:43:07-06:00" level=debug msg="completed challenge" Feb 12 13:43:07 volumio go-librespot[13647]: time="2026-02-12T13:43:07-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 13:43:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:43:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:43:08 volumio volumio[13175]: info: Initializing connection to go-librespot Websocket Feb 12 13:43:08 volumio volumio[13175]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 13:43:09 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 12 13:43:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 64. Feb 12 13:43:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:43:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:43:11 volumio go-librespot[13670]: go-librespot daemon starting... Feb 12 13:43:11 volumio go-librespot[13671]: time="2026-02-12T13:43:11-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:43:11 volumio go-librespot[13671]: time="2026-02-12T13:43:11-06:00" level=debug msg="app state loaded" Feb 12 13:43:11 volumio go-librespot[13671]: time="2026-02-12T13:43:11-06:00" level=debug msg="stored credentials not found" Feb 12 13:43:11 volumio go-librespot[13671]: time="2026-02-12T13:43:11-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:43:11 volumio go-librespot[13671]: time="2026-02-12T13:43:11-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 12 13:43:11 volumio go-librespot[13671]: time="2026-02-12T13:43:11-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 12 13:43:11 volumio go-librespot[13671]: time="2026-02-12T13:43:11-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 12 13:43:11 volumio go-librespot[13671]: time="2026-02-12T13:43:11-06:00" level=info msg="zeroconf server listening on port 44569" Feb 12 13:43:11 volumio go-librespot[13671]: time="2026-02-12T13:43:11-06:00" level=debug msg="obtained new client token: AAD+geQdeqsOCgU3mB1YPJfNnh3Xpa6KJR52iqdGbbxz6HefVnWXqo5XeKCfHwCfsTubT+OIHX76OzdpS1j8ZXSeSC4c64HGqw8P4oiWI0yGS88Yms3dQlwaiMrxzgsudiuP5lbJlhmtFhsFOd1G8POywyo7zRr/YAt4IIc6OAvtNuqlBLwk7se2uhlw3YyZmUYAqJBL6ljyGSoQloN2grO60SorKOACuQtjqnm//sFDokTvC5K0TITtDA==" Feb 12 13:43:11 volumio volumio[13175]: info: Initializing connection to go-librespot Websocket Feb 12 13:43:11 volumio go-librespot[13671]: time="2026-02-12T13:43:11-06:00" level=debug msg="new websocket client" Feb 12 13:43:11 volumio volumio[13175]: info: Connection to go-librespot Websocket established Feb 12 13:43:11 volumio go-librespot[13671]: time="2026-02-12T13:43:11-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 13:43:11 volumio go-librespot[13671]: time="2026-02-12T13:43:11-06:00" level=debug msg="completed keyexchange" Feb 12 13:43:11 volumio go-librespot[13671]: time="2026-02-12T13:43:11-06:00" level=debug msg="completed challenge" Feb 12 13:43:11 volumio go-librespot[13671]: time="2026-02-12T13:43:11-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 13:43:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:43:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:43:11 volumio volumio[13175]: info: Connection to go-librespot Websocket closed Feb 12 13:43:11 volumio volumio[13175]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 12 13:43:11 volumio volumio[13175]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 12 13:43:11 volumio volumio[13175]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 12 13:43:11 volumio volumio[13175]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 12 13:43:11 volumio volumio[13175]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 12 13:43:11 volumio volumio[13175]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 12 13:43:11 volumio volumio[13175]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 12 13:43:11 volumio volumio[13175]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 12 13:43:11 volumio volumio[13175]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 12 13:43:11 volumio volumio[13175]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 12 13:43:11 volumio volumio[13175]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 12 13:43:11 volumio volumio[13175]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 12 13:43:11 volumio volumio[13175]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 12 13:43:11 volumio volumio[13175]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 12 13:43:11 volumio volumio[13175]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 12 13:43:11 volumio volumio[13175]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 12 13:43:11 volumio volumio[13175]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 12 13:43:11 volumio volumio[13175]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 12 13:43:11 volumio volumio[13175]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 12 13:43:11 volumio volumio[13175]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 12 13:43:11 volumio volumio[13175]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 12 13:43:11 volumio volumio[13175]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 12 13:43:11 volumio volumio[13175]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 12 13:43:11 volumio volumio[13175]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 12 13:43:11 volumio volumio[13175]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 12 13:43:11 volumio volumio[13175]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 12 13:43:11 volumio volumio[13175]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 12 13:43:11 volumio volumio[13175]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 12 13:43:11 volumio volumio[13175]: info: Adding plugin bluetooth to MyMusic Plugins Feb 12 13:43:11 volumio volumio[13175]: info: Adding plugin multiroom to MyMusic Plugins Feb 12 13:43:11 volumio volumio[13175]: info: Adding plugin metavolumio to MyMusic Plugins Feb 12 13:43:11 volumio volumio[13175]: info: Adding plugin cd_controller to MyMusic Plugins Feb 12 13:43:11 volumio volumio[13175]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 12 13:43:11 volumio volumio[13175]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 12 13:43:11 volumio volumio[13175]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 12 13:43:11 volumio volumio[13175]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 12 13:43:12 volumio volumio[13175]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 12 13:43:12 volumio volumio[13175]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 12 13:43:12 volumio volumio[13175]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:43:12 volumio volumio[13175]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:43:12 volumio volumio[13175]: info: Starting MyVolumio Remote Streaming Endpoints Feb 12 13:43:12 volumio volumio[13175]: info: MyVolumio login type: Token Feb 12 13:43:12 volumio volumio[13175]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 12 13:43:12 volumio volumio[13175]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 12 13:43:13 volumio volumio[13175]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 12 13:43:13 volumio volumio[13175]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 12 13:43:13 volumio volumio[13175]: info: Streaming services startup Feb 12 13:43:13 volumio volumio[13175]: info: Starting Streaming Daemon Feb 12 13:43:13 volumio sudo[13679]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 12 13:43:13 volumio sudo[13679]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:13 volumio volumio[13175]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 12 13:43:13 volumio sudo[13679]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:13 volumio volumio[13175]: error: Cannot start Volumio Streaming Daemon Feb 12 13:43:13 volumio volumio[13175]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 12 13:43:13 volumio volumio[13175]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 12 13:43:14 volumio volumio[13175]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 12 13:43:14 volumio volumio[13175]: info: MyVolumio token set successfully Feb 12 13:43:14 volumio volumio[13175]: info: MYVOLUMIO: Adding device Feb 12 13:43:14 volumio volumio[13175]: info: MYVOLUMIO: Evaluating Server Feb 12 13:43:14 volumio volumio[13175]: info: Getting Spotify volume Feb 12 13:43:14 volumio volumio[13175]: info: MyVolumio status changed Feb 12 13:43:14 volumio volumio[13175]: info: Streaming services startup Feb 12 13:43:14 volumio volumio[13175]: info: Starting Streaming Daemon Feb 12 13:43:14 volumio volumio[13175]: info: Removing browser output: myVolumio user plan is not superstar Feb 12 13:43:14 volumio volumio[13175]: info: Removing audio output: Feb 12 13:43:14 volumio volumio[13175]: info: Stoppping Tunnel 1 Feb 12 13:43:14 volumio sudo[13707]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 12 13:43:14 volumio sudo[13707]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:14 volumio sudo[13709]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 12 13:43:14 volumio sudo[13709]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:14 volumio volumio[13175]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 13:43:14 volumio volumio[13175]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 13:43:14 volumio volumio[13175]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 12 13:43:14 volumio volumio[13175]: errno: -111, Feb 12 13:43:14 volumio volumio[13175]: code: 'ECONNREFUSED', Feb 12 13:43:14 volumio volumio[13175]: syscall: 'connect', Feb 12 13:43:14 volumio volumio[13175]: address: '127.0.0.1', Feb 12 13:43:14 volumio volumio[13175]: port: 9879, Feb 12 13:43:14 volumio volumio[13175]: response: undefined Feb 12 13:43:14 volumio volumio[13175]: } Feb 12 13:43:14 volumio volumio[13175]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 13:43:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 65. Feb 12 13:43:14 volumio sudo[13707]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:14 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 12 13:43:14 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 12 13:43:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:43:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:43:15 volumio go-librespot[13723]: go-librespot daemon starting... Feb 12 13:43:15 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 12 13:43:15 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 12 13:43:15 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 12 13:43:15 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 12 13:43:15 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 12 13:43:15 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 12 13:43:15 volumio go-librespot[13725]: time="2026-02-12T13:43:15-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:43:15 volumio go-librespot[13725]: time="2026-02-12T13:43:15-06:00" level=debug msg="app state loaded" Feb 12 13:43:15 volumio go-librespot[13725]: time="2026-02-12T13:43:15-06:00" level=debug msg="stored credentials not found" Feb 12 13:43:15 volumio sudo[13709]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:15 volumio go-librespot[13725]: time="2026-02-12T13:43:15-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:43:15 volumio go-librespot[13725]: time="2026-02-12T13:43:15-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 12 13:43:15 volumio go-librespot[13725]: time="2026-02-12T13:43:15-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 12 13:43:15 volumio go-librespot[13725]: time="2026-02-12T13:43:15-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 12 13:43:15 volumio go-librespot[13725]: time="2026-02-12T13:43:15-06:00" level=info msg="zeroconf server listening on port 44683" Feb 12 13:43:15 volumio kernel: hwmon hwmon1: Voltage normalised Feb 12 13:43:15 volumio go-librespot[13725]: time="2026-02-12T13:43:15-06:00" level=debug msg="obtained new client token: AAB1/yAFaLT4TasyuGuJMRmMRGa/QFCJlm+0Iz/iJK4BMqz5novram0pKIRNimKdZ0eY6tDk1AmNNZ0djtXbkhhlFpo4YhJcFrdr1wt1sckAAEBJtO3jeg+LUTWgN1X/J70b5VoA1N3gI6hMQbg1E0iRXXBtxATZazU7EaLRnlebIgxtLUlXK8fdasv5LvzJ+8kEErC/drw5F8HKZjZcxZgzEzHSMCWcSiJZG2/vXbw0BaAkHJr/4OTFDg==" Feb 12 13:43:15 volumio go-librespot[13725]: time="2026-02-12T13:43:15-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 13:43:15 volumio go-librespot[13725]: time="2026-02-12T13:43:15-06:00" level=debug msg="completed keyexchange" Feb 12 13:43:15 volumio go-librespot[13725]: time="2026-02-12T13:43:15-06:00" level=debug msg="completed challenge" Feb 12 13:43:15 volumio go-librespot[13725]: time="2026-02-12T13:43:15-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 12 13:43:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:43:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:43:15 volumio sudo[13735]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 13:42' Feb 12 13:43:15 volumio sudo[13735]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:15 volumio sudo[13735]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:15 volumio volumio-remote-updater[2265]: [2026-02-12 13:43:15] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 12 13:43:15 volumio volumio-remote-updater[2265]: [2026-02-12 13:43:15] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 12 13:43:15 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:43:15 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 12 13:43:15 volumio systemd[1]: volumio.service: Consumed 51.172s CPU time. Feb 12 13:43:16 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 12 13:43:16 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 12 13:43:16 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 6575. Feb 12 13:43:16 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 12 13:43:16 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 12 13:43:16 volumio systemd[1]: volumio.service: Consumed 51.172s CPU time. Feb 12 13:43:16 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 12 13:43:16 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 12 13:43:18 volumio volumio[13756]: info: ------------------------------------------- Feb 12 13:43:18 volumio volumio[13756]: info: ----- Volumio3 ---- Feb 12 13:43:18 volumio volumio[13756]: info: ------------------------------------------- Feb 12 13:43:18 volumio volumio[13756]: info: ----- System startup ---- Feb 12 13:43:18 volumio volumio[13756]: info: ------------------------------------------- Feb 12 13:43:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 66. Feb 12 13:43:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:43:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:43:18 volumio go-librespot[13777]: go-librespot daemon starting... Feb 12 13:43:18 volumio go-librespot[13778]: time="2026-02-12T13:43:18-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:43:18 volumio go-librespot[13778]: time="2026-02-12T13:43:18-06:00" level=debug msg="app state loaded" Feb 12 13:43:18 volumio go-librespot[13778]: time="2026-02-12T13:43:18-06:00" level=debug msg="stored credentials not found" Feb 12 13:43:18 volumio go-librespot[13778]: time="2026-02-12T13:43:18-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:43:19 volumio volumio[13756]: info: MYVOLUMIO Environment detected Feb 12 13:43:19 volumio go-librespot[13778]: time="2026-02-12T13:43:19-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 12 13:43:19 volumio go-librespot[13778]: time="2026-02-12T13:43:19-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 12 13:43:19 volumio go-librespot[13778]: time="2026-02-12T13:43:19-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 12 13:43:19 volumio go-librespot[13778]: time="2026-02-12T13:43:19-06:00" level=info msg="zeroconf server listening on port 41177" Feb 12 13:43:19 volumio volumio[13756]: info: Plugin folders cleanup Feb 12 13:43:19 volumio volumio[13756]: info: Scanning into folder /volumio/app/plugins/ Feb 12 13:43:19 volumio volumio[13756]: info: Scanning category audio_interface Feb 12 13:43:19 volumio volumio[13756]: info: Scanning category miscellanea Feb 12 13:43:19 volumio volumio[13756]: info: Scanning category music_service Feb 12 13:43:19 volumio volumio[13756]: info: Scanning category plugins.json Feb 12 13:43:19 volumio volumio[13756]: info: Scanning category system_controller Feb 12 13:43:19 volumio volumio[13756]: info: Scanning category user_interface Feb 12 13:43:19 volumio volumio[13756]: info: Scanning into folder /data/plugins/ Feb 12 13:43:19 volumio volumio[13756]: info: Scanning category audio_interface Feb 12 13:43:19 volumio volumio[13756]: info: Scanning category music_service Feb 12 13:43:19 volumio volumio[13756]: info: Scanning category system_controller Feb 12 13:43:19 volumio volumio[13756]: info: Scanning category system_hardware Feb 12 13:43:19 volumio volumio[13756]: info: Scanning category user_interface Feb 12 13:43:19 volumio volumio[13756]: info: Plugin folders cleanup completed Feb 12 13:43:19 volumio volumio[13756]: info: ------------------------------------------- Feb 12 13:43:19 volumio volumio[13756]: info: ----- Core plugins startup ---- Feb 12 13:43:19 volumio volumio[13756]: info: ------------------------------------------- Feb 12 13:43:19 volumio volumio[13756]: info: Loading plugins from folder /volumio/app/plugins/ Feb 12 13:43:19 volumio go-librespot[13778]: time="2026-02-12T13:43:19-06:00" level=debug msg="obtained new client token: AACrcGv/q/TRVmKHPWsJSRI9edYw6etXhS90oqulb7yRcuuJ1vFT0fa6s8fikYOwGnVYwYZkHmt6Vk1oMsX5LhGAvLHNU6xMx0OkPK+XYIPoBiUknoaORb+2DW9fpwQEEEVRc6nZIp6A95HXcMLY1OOMKdbyUAczxYDnrKn8i8QO1/a1o3GMVT1TH4Rd0scVh4O373cwJ3N80dKjbPDHtsmoblXICK564zFS2U7Yj3ovrL3fwmQny90=" Feb 12 13:43:19 volumio volumio[13756]: info: Adding plugin upnp to MyMusic Plugins Feb 12 13:43:19 volumio volumio[13756]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 12 13:43:19 volumio volumio[13756]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 12 13:43:19 volumio volumio[13756]: info: Loading plugins from folder /data/plugins/ Feb 12 13:43:19 volumio volumio[13756]: info: Loading plugin "system"... Feb 12 13:43:19 volumio go-librespot[13778]: time="2026-02-12T13:43:19-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 13:43:19 volumio volumio[13756]: info: Loading plugin "appearance"... Feb 12 13:43:19 volumio go-librespot[13778]: time="2026-02-12T13:43:19-06:00" level=debug msg="completed keyexchange" Feb 12 13:43:19 volumio go-librespot[13778]: time="2026-02-12T13:43:19-06:00" level=debug msg="completed challenge" Feb 12 13:43:19 volumio go-librespot[13778]: time="2026-02-12T13:43:19-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 12 13:43:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:43:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:43:20 volumio volumio[13756]: info: Loading plugin "network"... Feb 12 13:43:20 volumio volumio[13756]: info: Refreshing Cached IP Addresses Feb 12 13:43:20 volumio sudo[13793]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 13:43:20 volumio sudo[13793]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:20 volumio sudo[13795]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 13:43:20 volumio sudo[13793]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:20 volumio sudo[13795]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:20 volumio volumio[13756]: info: Loading plugin "services"... Feb 12 13:43:20 volumio volumio[13756]: info: Loading plugin "alsa_controller"... Feb 12 13:43:20 volumio sudo[13795]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:20 volumio sudo[13803]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 12 13:43:20 volumio sudo[13803]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:20 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 13:43:20 volumio volumio[13756]: info: Loading plugin "wizard"... Feb 12 13:43:20 volumio volumio[13756]: info: Loading plugin "networkfs"... Feb 12 13:43:20 volumio volumio[13756]: info: Starting Udev Watcher for removable devices Feb 12 13:43:20 volumio volumio[13756]: info: Ignoring mount for partition: boot Feb 12 13:43:20 volumio volumio[13756]: info: Ignoring mount for partition: volumio Feb 12 13:43:20 volumio volumio[13756]: info: Ignoring mount for partition: volumio_data Feb 12 13:43:20 volumio volumio[13756]: info: Mounting Device Wikipedia Feb 12 13:43:20 volumio sudo[13832]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Feb 12 13:43:20 volumio sudo[13832]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:20 volumio sudo[13832]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:20 volumio volumio[13756]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Feb 12 13:43:20 volumio volumio[13756]: dmesg(1) may have more information after failed mount system call. Feb 12 13:43:20 volumio volumio[13756]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Feb 12 13:43:20 volumio volumio[13756]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Feb 12 13:43:20 volumio volumio[13756]: dmesg(1) may have more information after failed mount system call. Feb 12 13:43:20 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 13:43:20 volumio volumio[13756]: info: Loading plugin "volumio_command_line_client"... Feb 12 13:43:20 volumio volumio[13756]: info: Loading plugin "upnp"... Feb 12 13:43:20 volumio volumio[13756]: info: [1770925400803] Starting Upmpd Daemon Feb 12 13:43:20 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 13:43:20 volumio volumio[13756]: info: Loading plugin "my_music"... Feb 12 13:43:20 volumio volumio[13756]: info: Loading plugin "mpd"... Feb 12 13:43:20 volumio volumio-remote-updater[2265]: [2026-02-12 13:43:20] [connect] Successful connection Feb 12 13:43:21 volumio sudo[13803]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:21 volumio volumio[13756]: info: Loading plugin "upnp_browser"... Feb 12 13:43:21 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 12 13:43:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 67. Feb 12 13:43:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:43:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:43:22 volumio go-librespot[13835]: go-librespot daemon starting... Feb 12 13:43:22 volumio go-librespot[13836]: time="2026-02-12T13:43:22-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:43:22 volumio go-librespot[13836]: time="2026-02-12T13:43:22-06:00" level=debug msg="app state loaded" Feb 12 13:43:22 volumio go-librespot[13836]: time="2026-02-12T13:43:22-06:00" level=debug msg="stored credentials not found" Feb 12 13:43:22 volumio go-librespot[13836]: time="2026-02-12T13:43:22-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:43:23 volumio go-librespot[13836]: time="2026-02-12T13:43:23-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 12 13:43:23 volumio go-librespot[13836]: time="2026-02-12T13:43:23-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 12 13:43:23 volumio go-librespot[13836]: time="2026-02-12T13:43:23-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 12 13:43:23 volumio go-librespot[13836]: time="2026-02-12T13:43:23-06:00" level=info msg="zeroconf server listening on port 34421" Feb 12 13:43:23 volumio go-librespot[13836]: time="2026-02-12T13:43:23-06:00" level=debug msg="obtained new client token: AABFMgm6tCayN4clo8vutJeDMevsWzRLgWMP5beZq2u6ZYGHt1St0KWZwNvsR+Z29C5MUmao67jE5yH74FbbGVGWm3K/EQqiXxB6j9nm84MGdmKvikwRMfcX19vIpvn5JzQ/zLHQ8Z+bQIX5o0vdENb985HvyTI1pMWg56kF385BJIV9N8+KUjpXIhZ7DfmkZQA+gIVlBSSHlJK77awrWfCYD0SWcNMhwsaTu8irtU18ANrd15RfHNk=" Feb 12 13:43:23 volumio go-librespot[13836]: time="2026-02-12T13:43:23-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Feb 12 13:43:23 volumio go-librespot[13836]: time="2026-02-12T13:43:23-06:00" level=debug msg="connected to ap-guc3.spotify.com:443" Feb 12 13:43:23 volumio go-librespot[13836]: time="2026-02-12T13:43:23-06:00" level=debug msg="completed keyexchange" Feb 12 13:43:23 volumio go-librespot[13836]: time="2026-02-12T13:43:23-06:00" level=debug msg="completed challenge" Feb 12 13:43:23 volumio go-librespot[13836]: time="2026-02-12T13:43:23-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 12 13:43:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:43:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:43:24 volumio volumio[13756]: info: Loading plugin "alarm-clock"... Feb 12 13:43:24 volumio volumio[13756]: info: Loading plugin "airplay_emulation"... Feb 12 13:43:24 volumio volumio[13756]: info: Starting Shairport Sync Feb 12 13:43:24 volumio volumio[13756]: info: Loading plugin "last_100"... Feb 12 13:43:24 volumio volumio[13756]: info: Loading plugin "webradio"... Feb 12 13:43:24 volumio volumio[13756]: info: Loading plugin "i2s_dacs"... Feb 12 13:43:24 volumio volumio[13756]: info: I2S DAC not set, start Auto-detection Feb 12 13:43:24 volumio volumio[13756]: info: Loading plugin "volumiodiscovery"... Feb 12 13:43:24 volumio volumio[13756]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 12 13:43:24 volumio volumio[13756]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 13:43:24 volumio volumio[13756]: *** WARNING *** For more information see Feb 12 13:43:24 volumio volumio[13756]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 12 13:43:24 volumio volumio[13756]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 13:43:24 volumio volumio[13756]: *** WARNING *** For more information see Feb 12 13:43:24 volumio node[13756]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 12 13:43:24 volumio node[13756]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 13:43:24 volumio node[13756]: *** WARNING *** For more information see Feb 12 13:43:24 volumio node[13756]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 12 13:43:24 volumio node[13756]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 13:43:24 volumio node[13756]: *** WARNING *** For more information see Feb 12 13:43:24 volumio volumio[13756]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 12 13:43:24 volumio volumio[13756]: info: Discovery: Started advertising with name: Volumio Feb 12 13:43:24 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 13:43:24 volumio volumio[13756]: info: Loading plugin "bandcamp"... Feb 12 13:43:25 volumio volumio[13756]: info: Plugin calmradio is not enabled Feb 12 13:43:25 volumio volumio[13756]: info: Loading plugin "soundcloud"... Feb 12 13:43:26 volumio volumio[13756]: info: Loading plugin "spop"... Feb 12 13:43:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 68. Feb 12 13:43:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:43:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:43:26 volumio go-librespot[13848]: go-librespot daemon starting... Feb 12 13:43:26 volumio go-librespot[13849]: time="2026-02-12T13:43:26-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:43:26 volumio go-librespot[13849]: time="2026-02-12T13:43:26-06:00" level=debug msg="app state loaded" Feb 12 13:43:26 volumio go-librespot[13849]: time="2026-02-12T13:43:26-06:00" level=debug msg="stored credentials not found" Feb 12 13:43:26 volumio go-librespot[13849]: time="2026-02-12T13:43:26-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:43:26 volumio go-librespot[13849]: time="2026-02-12T13:43: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 12 13:43:26 volumio go-librespot[13849]: time="2026-02-12T13:43: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 12 13:43:26 volumio go-librespot[13849]: time="2026-02-12T13:43: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 12 13:43:26 volumio go-librespot[13849]: time="2026-02-12T13:43:26-06:00" level=info msg="zeroconf server listening on port 33587" Feb 12 13:43:27 volumio go-librespot[13849]: time="2026-02-12T13:43:27-06:00" level=debug msg="obtained new client token: AAAhRJYsL5TfnSFFXpnbU1WQFz+RijomqREm3LVvytFTgqfzjJI0yKuO+8N9fdK4VjivhLkWhbmsHQKJzAd9ibsyhuwPI3pj6V/7knwaD8YpWxkp8RzU/49ghNwLF8PdIjM+SDhjz19FIag0An4r6UQiopl5+zKt8/HjgJddm6gaojrvpbEZALHEZRKmpZINpaacino8MDFgsf5l7bM3+YEYWpzO4ARVoJVSPMSr4aL/fNiWSxTt" Feb 12 13:43:27 volumio go-librespot[13849]: time="2026-02-12T13:43:27-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 13:43:27 volumio go-librespot[13849]: time="2026-02-12T13:43:27-06:00" level=debug msg="completed keyexchange" Feb 12 13:43:27 volumio go-librespot[13849]: time="2026-02-12T13:43:27-06:00" level=debug msg="completed challenge" Feb 12 13:43:27 volumio volumio[13756]: info: Loading plugin "squeezelite_mc"... Feb 12 13:43:27 volumio go-librespot[13849]: time="2026-02-12T13:43: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 12 13:43:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:43:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:43:27 volumio kernel: hwmon hwmon1: Voltage normalised Feb 12 13:43:27 volumio volumio[13756]: info: Loading plugin "youtube2"... Feb 12 13:43:28 volumio volumio[13756]: info: Loading plugin "ytcr"... Feb 12 13:43:29 volumio volumio[13756]: info: Loading plugin "ytmusic"... Feb 12 13:43:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 69. Feb 12 13:43:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:43:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:43:30 volumio go-librespot[13858]: go-librespot daemon starting... Feb 12 13:43:30 volumio volumio[13756]: info: Plugin now_playing is not enabled Feb 12 13:43:30 volumio volumio[13756]: info: Loading plugin "outputs"... Feb 12 13:43:30 volumio volumio[13756]: info: Loading plugin "albumart"... Feb 12 13:43:30 volumio go-librespot[13859]: time="2026-02-12T13:43:30-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:43:30 volumio go-librespot[13859]: time="2026-02-12T13:43:30-06:00" level=debug msg="app state loaded" Feb 12 13:43:30 volumio go-librespot[13859]: time="2026-02-12T13:43:30-06:00" level=debug msg="stored credentials not found" Feb 12 13:43:30 volumio go-librespot[13859]: time="2026-02-12T13:43:30-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:43:30 volumio volumio[13756]: info: Plugin example_plugin is not enabled Feb 12 13:43:30 volumio volumio[13756]: info: Loading plugin "inputs"... Feb 12 13:43:30 volumio volumio[13756]: info: Loading plugin "updater_comm"... Feb 12 13:43:30 volumio volumio[13756]: info: Plugin mpdemulation is not enabled Feb 12 13:43:30 volumio volumio[13756]: info: Loading plugin "rest_api"... Feb 12 13:43:30 volumio volumio[13756]: info: Loading plugin "websocket"... Feb 12 13:43:30 volumio volumio[13756]: info: Starting Socket.io Server version 1.7.4 Feb 12 13:43:30 volumio volumio[13756]: info: Plugin fusiondsp is not enabled Feb 12 13:43:30 volumio volumio[13756]: info: Plugin mpdoutput is not enabled Feb 12 13:43:30 volumio volumio[13756]: info: Plugin RoonBridge is not enabled Feb 12 13:43:30 volumio volumio[13756]: info: Loading plugin "podcast"... Feb 12 13:43:30 volumio go-librespot[13859]: time="2026-02-12T13:43: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:43:30 volumio go-librespot[13859]: time="2026-02-12T13:43:30-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 12 13:43:30 volumio go-librespot[13859]: time="2026-02-12T13:43:30-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 12 13:43:30 volumio go-librespot[13859]: time="2026-02-12T13:43:30-06:00" level=info msg="zeroconf server listening on port 34817" Feb 12 13:43:30 volumio go-librespot[13859]: time="2026-02-12T13:43:30-06:00" level=debug msg="obtained new client token: AACwnx34SBhJ3enHP5X/u8U+fuAbEYyX553AQhAjMZmSWhWP/1CDa1RQeeiEYWMSv2zTMFvMmlO769aZT4SPeoshHZPwN++wJuFYEmp5RZgyISbHYtWzZMt6DJ0uClN81vzSk3CaXz+gWOqVIL8RNhWOmDNNHRAQjM5rEN3cwGM7iPM+pcrmGA62SQF54RxNAmj36fARIxCFZGdJgc7QWGP/p4nFWoL6JFVxyjt0rhoRyYw9ZQstkpyf+Q==" Feb 12 13:43:30 volumio volumio[13756]: info: ControllerPodcast::constructor Feb 12 13:43:30 volumio go-librespot[13859]: time="2026-02-12T13:43:30-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 13:43:30 volumio go-librespot[13859]: time="2026-02-12T13:43:30-06:00" level=debug msg="completed keyexchange" Feb 12 13:43:30 volumio go-librespot[13859]: time="2026-02-12T13:43:30-06:00" level=debug msg="completed challenge" Feb 12 13:43:30 volumio go-librespot[13859]: time="2026-02-12T13:43: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 12 13:43:30 volumio volumio[13756]: info: Loading plugin "volusonic"... Feb 12 13:43:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:43:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:43:30 volumio volumio[13865]: Forking 3 albumart workers Feb 12 13:43:32 volumio volumio[13890]: Starting albumart workers Feb 12 13:43:32 volumio volumio[13756]: info: Applying required configuration parameters for plugin volusonic Feb 12 13:43:32 volumio volumio[13756]: info: Loading plugin "backup_restore"... Feb 12 13:43:32 volumio volumio[13892]: Starting albumart workers Feb 12 13:43:32 volumio volumio[13756]: info: Applying required configuration parameters for plugin backup_restore Feb 12 13:43:32 volumio volumio[13756]: info: Plugin rpi_eeprom_config is not enabled Feb 12 13:43:32 volumio volumio[13756]: info: Plugin rpi_eeprom_updater is not enabled Feb 12 13:43:32 volumio volumio[13756]: info: Loading plugin "scheduledrestart"... Feb 12 13:43:32 volumio volumio[13891]: Starting albumart workers Feb 12 13:43:33 volumio volumio[13756]: info: Applying required configuration parameters for plugin scheduledrestart Feb 12 13:43:33 volumio volumio[13756]: info: Plugin Bluetoothremote is not enabled Feb 12 13:43:33 volumio volumio[13756]: info: Plugin music_services_shield is not enabled Feb 12 13:43:33 volumio volumio[13756]: info: Loading plugin "Systeminfo"... Feb 12 13:43:33 volumio volumio-remote-updater[2265]: [2026-02-12 13:43:33] [connect] Successful connection Feb 12 13:43:33 volumio volumio[13756]: info: Plugin peppymeterbasic is not enabled Feb 12 13:43:33 volumio volumio[13756]: info: Loading plugin "peppyspectrum"... Feb 12 13:43:33 volumio volumio[13756]: info: Loading i18n strings for locale en Feb 12 13:43:33 volumio volumio[13756]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Feb 12 13:43:33 volumio volumio[13756]: Updating browse sources language Feb 12 13:43:33 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:43:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 70. Feb 12 13:43:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::initPlayerControls Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 13:43:34 volumio volumio[13756]: Express server listening on port 3000 Feb 12 13:43:34 volumio volumio[13756]: [Metrics] WebUI: 16s 307.86ms Feb 12 13:43:34 volumio volumio[13756]: info: CoreStateMachine::resetVolumioState Feb 12 13:43:34 volumio volumio[13756]: info: CoreStateMachine::getcurrentVolume Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 13:43:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:43:34 volumio go-librespot[13938]: go-librespot daemon starting... Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:43:34 volumio go-librespot[13943]: time="2026-02-12T13:43:34-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:43:34 volumio go-librespot[13943]: time="2026-02-12T13:43:34-06:00" level=debug msg="app state loaded" Feb 12 13:43:34 volumio go-librespot[13943]: time="2026-02-12T13:43:34-06:00" level=debug msg="stored credentials not found" Feb 12 13:43:34 volumio go-librespot[13943]: time="2026-02-12T13:43:34-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:43:34 volumio sudo[13950]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 13:43:34 volumio sudo[13950]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:34 volumio sudo[13950]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:34 volumio sudo[13952]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 13:43:34 volumio sudo[13952]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:34 volumio sudo[13952]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:34 volumio volumio[13756]: info: Volumio Network Manager: Network status updated: 1 Feb 12 13:43:34 volumio volumio-remote-updater[2265]: [2026-02-12 13:43:34] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770925413 101 Feb 12 13:43:34 volumio volumio[13756]: 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 12 13:43:34 volumio volumio[13756]: info: VolumeController:: Volume=100 Mute =false Feb 12 13:43:34 volumio volumio[13756]: info: CoreStateMachine::pushState Feb 12 13:43:34 volumio volumio[13756]: info: CorePlayQueue::getTrack 0 Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::volumioPushState Feb 12 13:43:34 volumio go-librespot[13943]: time="2026-02-12T13:43: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 12 13:43:34 volumio go-librespot[13943]: time="2026-02-12T13:43: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 12 13:43:34 volumio go-librespot[13943]: time="2026-02-12T13:43: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 12 13:43:34 volumio volumio[13756]: info: CoreStateMachine::updateTrackBlock Feb 12 13:43:34 volumio volumio[13756]: info: CorePlayQueue::getTrackBlock Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 13:43:34 volumio go-librespot[13943]: time="2026-02-12T13:43:34-06:00" level=info msg="zeroconf server listening on port 45387" Feb 12 13:43:34 volumio volumio[13756]: info: Reloading queue from file Feb 12 13:43:34 volumio volumio[13756]: info: CoreStateMachine::setRepeat null single undefined Feb 12 13:43:34 volumio volumio[13756]: info: CoreStateMachine::pushState Feb 12 13:43:34 volumio volumio[13756]: info: CorePlayQueue::getTrack 0 Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::volumioPushState Feb 12 13:43:34 volumio volumio[13756]: info: CoreStateMachine::setRandom null Feb 12 13:43:34 volumio volumio[13756]: info: CoreStateMachine::pushState Feb 12 13:43:34 volumio volumio[13756]: info: CorePlayQueue::getTrack 0 Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::volumioPushState Feb 12 13:43:34 volumio volumio[13756]: info: Setting Device type: Raspberry PI Feb 12 13:43:34 volumio go-librespot[13943]: time="2026-02-12T13:43:34-06:00" level=debug msg="obtained new client token: AAA8HbOtF14zupeCIVKCiaOle11n52iweoOu04b9P86PnfjUDrh/YpWS4QsFIuxTs/3Ov6tqHX1HgcQ6U3QJu00dQOLkHUng/tqnL91WL5O/eCqIJuC5aqG9uqDnY8YltRq/b0cq8DqOuZWlwzEOu8ojzaXWkMgqjN73/xfel1gwofrgo7sDJq0+XWEG8xRlLzbfRLCHvy55lN2EhKzwNr4ZDE6wNM4Y1BQMUBGXWmClTiHcrSTpZwxseQ==" Feb 12 13:43:34 volumio volumio[13756]: info: VolumeController:: Volume=100 Mute =false Feb 12 13:43:34 volumio volumio[13756]: info: CoreStateMachine::pushState Feb 12 13:43:34 volumio volumio[13756]: info: CorePlayQueue::getTrack 0 Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::volumioPushState Feb 12 13:43:34 volumio sudo[13968]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 12 13:43:34 volumio sudo[13968]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:34 volumio volumio[13756]: info: Completed loading Core Plugins Feb 12 13:43:34 volumio volumio[13756]: info: Preparing to generate the ALSA configuration file Feb 12 13:43:34 volumio go-librespot[13943]: time="2026-02-12T13:43:34-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Feb 12 13:43:34 volumio volumio[13756]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Feb 12 13:43:34 volumio volumio[13756]: info: Discovery: Found device Volumio Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::volumioGetState Feb 12 13:43:34 volumio volumio[13756]: info: CorePlayQueue::getTrack 0 Feb 12 13:43:34 volumio volumio[13756]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Feb 12 13:43:34 volumio volumio[13756]: info: Discovery: Found device Volumio Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::volumioGetState Feb 12 13:43:34 volumio volumio[13756]: info: CorePlayQueue::getTrack 0 Feb 12 13:43:34 volumio sudo[13968]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:34 volumio go-librespot[13943]: time="2026-02-12T13:43:34-06:00" level=debug msg="connected to ap-guc3.spotify.com:443" Feb 12 13:43:34 volumio volumio[13756]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Feb 12 13:43:34 volumio volumio[13756]: info: Reading ALSA contributions from plugins. Feb 12 13:43:34 volumio volumio[13756]: info: Upmpdcli Daemon Started Feb 12 13:43:34 volumio volumio[13756]: info: Asound.conf file unchanged, so no further update is needed Feb 12 13:43:34 volumio volumio[13756]: info: Output device has changed, restarting MPD Feb 12 13:43:34 volumio volumio[13756]: info: Output device has changed, restarting Shairport Sync Feb 12 13:43:34 volumio go-librespot[13943]: time="2026-02-12T13:43:34-06:00" level=debug msg="completed keyexchange" Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:43:34 volumio go-librespot[13943]: time="2026-02-12T13:43:34-06:00" level=debug msg="completed challenge" Feb 12 13:43:34 volumio sudo[13971]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 13:43:34 volumio sudo[13971]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:34 volumio sudo[13971]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:34 volumio sudo[13973]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 13:43:34 volumio sudo[13973]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:34 volumio volumio[13756]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 13:43:34 volumio volumio[13756]: info: ___________ START PLUGINS ___________ Feb 12 13:43:34 volumio go-librespot[13943]: time="2026-02-12T13:43:34-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 12 13:43:34 volumio volumio[13756]: info: ControllerMpd::onStart: Initializing MPD Feb 12 13:43:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:43:34 volumio volumio[13756]: info: Creating MPD Configuration file Feb 12 13:43:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:43:34 volumio volumio[13756]: info: [1770925414749] CoreMusicLibrary::Adding element Media Servers Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:43:34 volumio sudo[13981]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 13:43:34 volumio sudo[13981]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:34 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 12 13:43:34 volumio sudo[13981]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:34 volumio sudo[13983]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 13:43:34 volumio sudo[13983]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:43:34 volumio volumio[13756]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:43:34 volumio volumio[13756]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 13:43:34 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:43:34 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 12 13:43:34 volumio systemd[1]: mpd.service: Consumed 4.114s CPU time. Feb 12 13:43:34 volumio volumio[13756]: info: [1770925414871] CoreMusicLibrary::Adding element Last_100 Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:43:34 volumio volumio[13756]: info: [1770925414876] CoreMusicLibrary::Adding element Webradio Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:43:34 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 12 13:43:34 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 12 13:43:34 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 13:43:34 volumio volumio[13756]: info: Initializing BBC Radios Feb 12 13:43:34 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:43:34 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 12 13:43:34 volumio volumio[13756]: info: [1770925414957] CoreMusicLibrary::Adding element Bandcamp Discover Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:43:34 volumio volumio[13756]: Cannot find translation for source Bandcamp Discover Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:43:34 volumio volumio[13756]: info: [1770925414970] CoreMusicLibrary::Adding element SoundCloud Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:43:34 volumio volumio[13756]: Cannot find translation for source Bandcamp Discover Feb 12 13:43:34 volumio volumio[13756]: Cannot find translation for source SoundCloud Feb 12 13:43:34 volumio volumio[13756]: info: Creating Spotify config file Feb 12 13:43:34 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:35 volumio sudo[14008]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 12 13:43:35 volumio sudo[14008]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 12 13:43:35 volumio sudo[14008]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:35 volumio volumio[13756]: info: [squeezelite_mc] Starting proxy server... Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:43:35 volumio volumio[13756]: info: [1770925415323] CoreMusicLibrary::Adding element YouTube2 Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:43:35 volumio volumio[13756]: Cannot find translation for source Bandcamp Discover Feb 12 13:43:35 volumio volumio[13756]: Cannot find translation for source SoundCloud Feb 12 13:43:35 volumio volumio[13756]: Cannot find translation for source YouTube2 Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:43:35 volumio volumio[13756]: info: [1770925415341] CoreMusicLibrary::Adding element YouTube Music Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:43:35 volumio volumio[13756]: Cannot find translation for source Bandcamp Discover Feb 12 13:43:35 volumio volumio[13756]: Cannot find translation for source SoundCloud Feb 12 13:43:35 volumio volumio[13756]: Cannot find translation for source YouTube2 Feb 12 13:43:35 volumio volumio[13756]: Cannot find translation for source YouTube Music Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:43:35 volumio volumio[13756]: info: [1770925415352] CoreMusicLibrary::Adding element Podcast Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:43:35 volumio volumio[13756]: Cannot find translation for source Bandcamp Discover Feb 12 13:43:35 volumio volumio[13756]: Cannot find translation for source SoundCloud Feb 12 13:43:35 volumio volumio[13756]: Cannot find translation for source YouTube2 Feb 12 13:43:35 volumio volumio[13756]: Cannot find translation for source YouTube Music Feb 12 13:43:35 volumio volumio[13756]: Cannot find translation for source Podcast Feb 12 13:43:35 volumio volumio[13756]: info: Loading i18n strings for locale en Feb 12 13:43:35 volumio volumio[13756]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Feb 12 13:43:35 volumio volumio[13756]: Updating browse sources language Feb 12 13:43:35 volumio volumio[13756]: Cannot find translation for source Bandcamp Discover Feb 12 13:43:35 volumio volumio[13756]: Cannot find translation for source SoundCloud Feb 12 13:43:35 volumio volumio[13756]: Cannot find translation for source YouTube2 Feb 12 13:43:35 volumio volumio[13756]: Cannot find translation for source YouTube Music Feb 12 13:43:35 volumio volumio[13756]: Cannot find translation for source Podcast Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:43:35 volumio volumio[13756]: Cannot find translation for source Bandcamp Discover Feb 12 13:43:35 volumio volumio[13756]: Cannot find translation for source SoundCloud Feb 12 13:43:35 volumio volumio[13756]: Cannot find translation for source YouTube2 Feb 12 13:43:35 volumio volumio[13756]: Cannot find translation for source YouTube Music Feb 12 13:43:35 volumio volumio[13756]: Cannot find translation for source Podcast Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:43:35 volumio volumio[13756]: info: [1770925415400] CoreMusicLibrary::Adding element Volusonic Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:43:35 volumio volumio[13756]: Cannot find translation for source Bandcamp Discover Feb 12 13:43:35 volumio volumio[13756]: Cannot find translation for source SoundCloud Feb 12 13:43:35 volumio volumio[13756]: Cannot find translation for source YouTube2 Feb 12 13:43:35 volumio volumio[13756]: Cannot find translation for source YouTube Music Feb 12 13:43:35 volumio volumio[13756]: Cannot find translation for source Podcast Feb 12 13:43:35 volumio volumio[13756]: Cannot find translation for source Volusonic Feb 12 13:43:35 volumio volumio[13756]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Feb 12 13:43:35 volumio volumio[13756]: info: Volumio Calling Home Feb 12 13:43:35 volumio volumio[13756]: info: [squeezelite_mc] Proxy server started on port 42313 Feb 12 13:43:35 volumio volumio[13756]: info: Preparing to generate the ALSA configuration file Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 13:43:35 volumio volumio[13756]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Feb 12 13:43:35 volumio volumio[13756]: info: Reading ALSA contributions from plugins. Feb 12 13:43:35 volumio volumio[13756]: info: MPD Permissions set Feb 12 13:43:35 volumio volumio[13756]: info: MPD Permissions set Feb 12 13:43:35 volumio volumio[13756]: info: Spotify config file written Feb 12 13:43:35 volumio sudo[14018]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 12 13:43:35 volumio sudo[14018]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:35 volumio volumio[13756]: 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 12 13:43:35 volumio volumio[13756]: info: VolumeController:: Volume=100 Mute =false Feb 12 13:43:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:43:35 volumio volumio[13756]: info: CoreStateMachine::pushState Feb 12 13:43:35 volumio volumio[13756]: info: CorePlayQueue::getTrack 0 Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::volumioPushState Feb 12 13:43:35 volumio volumio[13756]: info: [squeezelite_mc] Server discovery started Feb 12 13:43:35 volumio volumio[13756]: info: [squeezelite_mc] Player finder started Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 13:43:35 volumio volumio[13756]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:43:35 volumio go-librespot[14020]: go-librespot daemon starting... Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:35 volumio sudo[14018]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:35 volumio go-librespot[14028]: time="2026-02-12T13:43:35-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:43:35 volumio go-librespot[14028]: time="2026-02-12T13:43:35-06:00" level=debug msg="app state loaded" Feb 12 13:43:35 volumio go-librespot[14028]: time="2026-02-12T13:43:35-06:00" level=debug msg="stored credentials not found" Feb 12 13:43:35 volumio go-librespot[14028]: time="2026-02-12T13:43:35-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:43:35 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:35 volumio volumio[13756]: info: No need to fix Spotify hosts Feb 12 13:43:36 volumio volumio[13756]: 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 12 13:43:36 volumio volumio[13756]: info: Volumio called home Feb 12 13:43:36 volumio volumio[13756]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Feb 12 13:43:36 volumio volumio[13756]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Feb 12 13:43:36 volumio volumio[13756]: 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 12 13:43:36 volumio volumio[13756]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 13:43:36 volumio volumio[13756]: SPOTIFY: BQB-1GHh_WDoSHmZ9CSuh0beHrZFczvovr7tqYA6Pwts-Y5DHyOTplq-jeytln0cIlixBsZwDQiMeNsgpE_QT9xqURLTJm_F_1fQ3AjKiIlJik8Krb2UnUjkbhanuH15BsSH7WDsSgkPxyyLdqZKCO2ydpYTWnWuBTpdXQc0y72z4doujH3FOR_btKGw_nl7d9xHhLuZ952_VhuwWj7rCGnBD8HX8tB6s9hZEYQ Feb 12 13:43:36 volumio volumio[13756]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 13:43:36 volumio volumio[13756]: info: New Spotify access token = BQB-1GHh_WDoSHmZ9CSuh0beHrZFczvovr7tqYA6Pwts-Y5DHyOTplq-jeytln0cIlixBsZwDQiMeNsgpE_QT9xqURLTJm_F_1fQ3AjKiIlJik8Krb2UnUjkbhanuH15BsSH7WDsSgkPxyyLdqZKCO2ydpYTWnWuBTpdXQc0y72z4doujH3FOR_btKGw_nl7d9xHhLuZ952_VhuwWj7rCGnBD8HX8tB6s9hZEYQ Feb 12 13:43:36 volumio volumio[13756]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 12 13:43:36 volumio sudo[14043]: 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 12 13:43:36 volumio sudo[14043]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:36 volumio sudo[14043]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:36 volumio go-librespot[14028]: time="2026-02-12T13:43:36-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 12 13:43:36 volumio go-librespot[14028]: time="2026-02-12T13:43:36-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 12 13:43:36 volumio go-librespot[14028]: time="2026-02-12T13:43:36-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 12 13:43:36 volumio volumio[13756]: info: Starting Shairport Sync Feb 12 13:43:36 volumio volumio[13756]: info: Starting Shairport Sync Feb 12 13:43:36 volumio go-librespot[14028]: time="2026-02-12T13:43:36-06:00" level=info msg="zeroconf server listening on port 45345" Feb 12 13:43:36 volumio volumio[13756]: info: Starting Shairport Sync Feb 12 13:43:36 volumio sudo[14046]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 13:43:36 volumio sudo[14046]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:36 volumio sudo[14048]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 13:43:36 volumio sudo[14048]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:36 volumio sudo[14050]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 13:43:36 volumio sudo[14050]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:36 volumio go-librespot[14028]: time="2026-02-12T13:43:36-06:00" level=debug msg="obtained new client token: AADj2QvJPfrlbyH/k5GH1ulrLC21utulDGgb4rlW0HHnsIefKKilfdgdB060GNGSHuUvumnifKGisfks6FzsbyvqGHnoMZrK5XDm+QsEcIbJW7Pt/Lei4HaU9fG4s/XytOGVvpgkePBQBJHxkRFItdP+PczafmDr2qlgmXgJ9rjhX0NsNVrdSB/ZBcOjPr1PS3cDKXGHJUkkF1M9jKrpmQLoGkc3AIuHEF50acbIoh5BNYjhZggWQoHvHg==" Feb 12 13:43:36 volumio volumio[13756]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Feb 12 13:43:36 volumio volumio[13756]: info: Asound.conf file unchanged, so no further update is needed Feb 12 13:43:36 volumio volumio[13756]: info: Output device has changed, restarting MPD Feb 12 13:43:36 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 13:43:36 volumio go-librespot[14028]: time="2026-02-12T13:43:36-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 13:43:36 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 13:43:36 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 13:43:36 volumio systemd[1]: shairport-sync.service: Consumed 2.018s CPU time. Feb 12 13:43:36 volumio sudo[14056]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Feb 12 13:43:36 volumio sudo[14056]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:36 volumio volumio[13756]: info: Output device has changed, restarting Shairport Sync Feb 12 13:43:36 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:36 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:43:36 volumio go-librespot[14028]: time="2026-02-12T13:43:36-06:00" level=debug msg="completed keyexchange" Feb 12 13:43:36 volumio go-librespot[14028]: time="2026-02-12T13:43:36-06:00" level=debug msg="completed challenge" Feb 12 13:43:36 volumio sudo[14056]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:36 volumio sudo[14062]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 13:43:36 volumio sudo[14062]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:36 volumio sudo[14058]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 13:43:36 volumio sudo[14058]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:36 volumio volumio[13756]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 13:43:36 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 13:43:36 volumio go-librespot[14028]: time="2026-02-12T13:43:36-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 13:43:36 volumio sudo[14058]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:36 volumio sudo[14048]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:43:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:43:36 volumio sudo[14050]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:36 volumio sudo[14046]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:36 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 12 13:43:36 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 12 13:43:36 volumio systemd[1]: mpd.service: Consumed 1.589s CPU time. Feb 12 13:43:36 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 12 13:43:36 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 12 13:43:36 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 12 13:43:36 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 12 13:43:36 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 12 13:43:36 volumio volumio[13756]: info: MPD Permissions set Feb 12 13:43:36 volumio volumio[13756]: info: Shairport-Sync Started Feb 12 13:43:36 volumio volumio[13756]: Error adding Membership: Error: addMembership EINVAL Feb 12 13:43:36 volumio volumio[13756]: info: Shairport-Sync Started Feb 12 13:43:36 volumio volumio[13756]: info: Shairport-Sync Started Feb 12 13:43:36 volumio volumio[13756]: 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 12 13:43:36 volumio sudo[14091]: 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 12 13:43:36 volumio sudo[14091]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:36 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:36 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:36 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:36 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:36 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:36 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:36 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:36 volumio sudo[14091]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:36 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:36 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:43:36 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:37 volumio volumio[13756]: info: CoreCommandRouter::volumioGetState Feb 12 13:43:37 volumio volumio[13756]: info: CorePlayQueue::getTrack 0 Feb 12 13:43:37 volumio volumio[13756]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Feb 12 13:43:37 volumio volumio[13756]: info: Starting Shairport Sync Feb 12 13:43:37 volumio sudo[14099]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Feb 12 13:43:37 volumio sudo[14088]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 12 13:43:37 volumio sudo[14099]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:37 volumio sudo[14088]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 12 13:43:37 volumio sudo[14088]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:37 volumio sudo[14103]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 13:43:37 volumio sudo[14103]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:37 volumio volumio[13756]: 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 12 13:43:37 volumio volumio[13756]: info: Spotify Successfully logged in Feb 12 13:43:37 volumio volumio[13756]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:43:37 volumio volumio[13756]: info: [1770925417122] CoreMusicLibrary::Adding element Spotify Feb 12 13:43:37 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:43:37 volumio volumio[13756]: Cannot find translation for source Bandcamp Discover Feb 12 13:43:37 volumio volumio[13756]: Cannot find translation for source SoundCloud Feb 12 13:43:37 volumio volumio[13756]: Cannot find translation for source YouTube2 Feb 12 13:43:37 volumio volumio[13756]: Cannot find translation for source YouTube Music Feb 12 13:43:37 volumio volumio[13756]: Cannot find translation for source Podcast Feb 12 13:43:37 volumio volumio[13756]: Cannot find translation for source Volusonic Feb 12 13:43:37 volumio volumio[13756]: Cannot find translation for source Spotify Feb 12 13:43:37 volumio systemd[1]: Reloading. Feb 12 13:43:38 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:38 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:38 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:43:38 volumio volumio[13756]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 13:43:38 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 12 13:43:39 volumio volumio[13756]: info: go-librespot daemon successfully initialized Feb 12 13:43:39 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 12 13:43:39 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 12 13:43:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 71. Feb 12 13:43:40 volumio sudo[14099]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:40 volumio volumio[13756]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 13:43:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:43:40 volumio sudo[14133]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 13:43:40 volumio sudo[14133]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:43:40 volumio go-librespot[14139]: go-librespot daemon starting... Feb 12 13:43:40 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 13:43:40 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 13:43:40 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 13:43:40 volumio systemd[1]: shairport-sync.service: Consumed 1.535s CPU time. Feb 12 13:43:40 volumio go-librespot[14142]: time="2026-02-12T13:43:40-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:43:40 volumio go-librespot[14142]: time="2026-02-12T13:43:40-06:00" level=debug msg="app state loaded" Feb 12 13:43:40 volumio go-librespot[14142]: time="2026-02-12T13:43:40-06:00" level=debug msg="stored credentials not found" Feb 12 13:43:40 volumio go-librespot[14142]: time="2026-02-12T13:43:40-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:43:40 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 13:43:40 volumio sudo[14103]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:40 volumio volumio[13756]: info: Shairport-Sync Started Feb 12 13:43:40 volumio sudo[14133]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:40 volumio volumio[13756]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Feb 12 13:43:40 volumio sudo[14164]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Feb 12 13:43:40 volumio sudo[14164]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:40 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 12 13:43:41 volumio go-librespot[14142]: time="2026-02-12T13:43:41-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:43:41 volumio go-librespot[14142]: time="2026-02-12T13:43:41-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 12 13:43:41 volumio go-librespot[14142]: time="2026-02-12T13:43:41-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 12 13:43:41 volumio go-librespot[14142]: time="2026-02-12T13:43:41-06:00" level=info msg="zeroconf server listening on port 44199" Feb 12 13:43:41 volumio systemd[1]: squeezelite.service: Deactivated successfully. Feb 12 13:43:41 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 12 13:43:41 volumio go-librespot[14142]: time="2026-02-12T13:43:41-06:00" level=debug msg="obtained new client token: AAAMsq/dSegHUChXIkmklj50n4SzsJZZAcvWI3eKA5lJddk3G7q6vt4WE2CaW6wzucZn/MJuEPTSfKWTyY060g3iMy4C5pH6TZEneu8rqqPANz62n4unigvIh6HOy7/ntCFvNzNpRB9wZ7lT+nfODcycoyRtC9BPqU95bMjxSnn1UaKqDmzcVvuCNX6+nrNQSeWjsqcrI5aG9Z22Arjwo6DI04BGZL6dlKUXE2S5Y4NAgCF/MB9pwNo=" Feb 12 13:43:41 volumio sudo[14164]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:41 volumio go-librespot[14142]: time="2026-02-12T13:43:41-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 13:43:41 volumio go-librespot[14142]: time="2026-02-12T13:43:41-06:00" level=debug msg="completed keyexchange" Feb 12 13:43:41 volumio go-librespot[14142]: time="2026-02-12T13:43:41-06:00" level=debug msg="completed challenge" Feb 12 13:43:41 volumio go-librespot[14142]: time="2026-02-12T13:43:41-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 13:43:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:43:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:43:41 volumio volumio[13756]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 13:43:41 volumio sudo[14168]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 13:43:41 volumio sudo[14168]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:41 volumio sudo[14168]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:41 volumio volumio[13756]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Feb 12 13:43:41 volumio sudo[14172]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Feb 12 13:43:41 volumio sudo[14172]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:41 volumio sudo[14172]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:41 volumio volumio[13756]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Feb 12 13:43:41 volumio sudo[14175]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Feb 12 13:43:41 volumio sudo[14175]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:42 volumio mpd[14104]: 2026-02-12T13:43:41 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 12 13:43:42 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 12 13:43:42 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 12 13:43:42 volumio sudo[14175]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:42 volumio volumio[13756]: info: Initializing connection to go-librespot Websocket Feb 12 13:43:42 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 12 13:43:42 volumio sudo[14062]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:42 volumio sudo[13983]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:42 volumio sudo[13973]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:42 volumio volumio[13756]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 13:43:42 volumio volumio[13756]: error: MPD error: The expression evaluated to a falsy value: Feb 12 13:43:42 volumio volumio[13756]: assert.ok(self.idling) Feb 12 13:43:42 volumio volumio[13756]: error: The expression evaluated to a falsy value: Feb 12 13:43:42 volumio volumio[13756]: assert.ok(self.idling) Feb 12 13:43:42 volumio volumio[13756]: error: MPD error: The expression evaluated to a falsy value: Feb 12 13:43:42 volumio volumio[13756]: assert.ok(self.idling) Feb 12 13:43:42 volumio volumio[13756]: error: The expression evaluated to a falsy value: Feb 12 13:43:42 volumio volumio[13756]: assert.ok(self.idling) Feb 12 13:43:42 volumio volumio[13756]: info: MPD running with PID14104 Feb 12 13:43:42 volumio volumio[13756]: ,establishing connection Feb 12 13:43:42 volumio volumio[13756]: error: updateQueue error: null Feb 12 13:43:42 volumio volumio[13756]: error: updateQueue error: null Feb 12 13:43:42 volumio volumio[13756]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 13:43:42 volumio sudo[14186]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 13:43:42 volumio sudo[14186]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:42 volumio sudo[14186]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:43 volumio volumio[13756]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 13:43:43 volumio sudo[14189]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 13:43:43 volumio sudo[14189]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:43 volumio sudo[14189]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:43 volumio volumio[13756]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 13:43:43 volumio sudo[14192]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 13:43:43 volumio sudo[14192]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:43 volumio sudo[14192]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:44 volumio volumio[13756]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 13:43:44 volumio sudo[14195]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 13:43:44 volumio sudo[14195]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 72. Feb 12 13:43:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:43:44 volumio kernel: hwmon hwmon1: Voltage normalised Feb 12 13:43:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:43:44 volumio go-librespot[14197]: go-librespot daemon starting... Feb 12 13:43:44 volumio sudo[14195]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:44 volumio go-librespot[14199]: time="2026-02-12T13:43:44-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:43:44 volumio go-librespot[14199]: time="2026-02-12T13:43:44-06:00" level=debug msg="app state loaded" Feb 12 13:43:44 volumio go-librespot[14199]: time="2026-02-12T13:43:44-06:00" level=debug msg="stored credentials not found" Feb 12 13:43:44 volumio go-librespot[14199]: time="2026-02-12T13:43:44-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:43:44 volumio go-librespot[14199]: time="2026-02-12T13:43:44-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:43:44 volumio go-librespot[14199]: time="2026-02-12T13:43:44-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 13:43:44 volumio go-librespot[14199]: time="2026-02-12T13:43:44-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 13:43:44 volumio go-librespot[14199]: time="2026-02-12T13:43:44-06:00" level=info msg="zeroconf server listening on port 39173" Feb 12 13:43:44 volumio go-librespot[14199]: time="2026-02-12T13:43:44-06:00" level=debug msg="obtained new client token: AABmoNUZTNmO6sB1kOd0ggw1jEiaU7gNwn3yfyY73h5irmg3YIv1H3eXARzDQJZ5pZ7Yhm2d+gc21KRS3exrqItcz25ME6dQ85FiuPfr7PSjKyTOLGeEorStnbTtBUBkb3bfBTpcCUWMfK0sL7xSKmIsu6V/SJ+gOnSbCDe58hH60CzdezN9JQWIiUVIXeGDaV+TrASYyQ5bG0Wy+QlqJJj7VFtdjIkBrFaUu+ICwPspTzmwF57Km3oPaw==" Feb 12 13:43:44 volumio go-librespot[14199]: time="2026-02-12T13:43:44-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 13:43:44 volumio go-librespot[14199]: time="2026-02-12T13:43:44-06:00" level=debug msg="completed keyexchange" Feb 12 13:43:44 volumio go-librespot[14199]: time="2026-02-12T13:43:44-06:00" level=debug msg="completed challenge" Feb 12 13:43:44 volumio go-librespot[14199]: time="2026-02-12T13:43:44-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 12 13:43:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:43:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:43:44 volumio volumio[13756]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 13:43:45 volumio sudo[14207]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 13:43:45 volumio sudo[14207]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:45 volumio sudo[14207]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:45 volumio volumio[13756]: info: Completed starting Core Plugins Feb 12 13:43:45 volumio volumio[13756]: info: ------------------------------------------- Feb 12 13:43:45 volumio volumio[13756]: info: ----- MyVolumio plugins startup ---- Feb 12 13:43:45 volumio volumio[13756]: info: ------------------------------------------- Feb 12 13:43:45 volumio volumio[13756]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 12 13:43:45 volumio volumio[13756]: info: Initializing connection to go-librespot Websocket Feb 12 13:43:45 volumio volumio[13756]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 13:43:45 volumio sudo[14210]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 12 13:43:45 volumio sudo[14210]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:45 volumio sudo[14212]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 12 13:43:45 volumio sudo[14212]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:45 volumio sudo[14215]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 12 13:43:45 volumio sudo[14215]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:45 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 12 13:43:45 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 12 13:43:45 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 12 13:43:45 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 12 13:43:45 volumio sudo[14210]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:45 volumio mpd_monitor.sh[14218]: MPD Monitor Service: Starting MPD Monitor Service Feb 12 13:43:45 volumio sudo[14215]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:45 volumio sudo[14212]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:45 volumio volumio[13756]: info: Successfully started MPD Monitor Feb 12 13:43:45 volumio volumio[13756]: info: Successfully started MPD Monitor Feb 12 13:43:45 volumio volumio[13756]: info: Successfully started MPD Monitor Feb 12 13:43:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 73. Feb 12 13:43:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:43:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:43:48 volumio go-librespot[14222]: go-librespot daemon starting... Feb 12 13:43:48 volumio go-librespot[14223]: time="2026-02-12T13:43:48-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:43:48 volumio go-librespot[14223]: time="2026-02-12T13:43:48-06:00" level=debug msg="app state loaded" Feb 12 13:43:48 volumio go-librespot[14223]: time="2026-02-12T13:43:48-06:00" level=debug msg="stored credentials not found" Feb 12 13:43:48 volumio go-librespot[14223]: time="2026-02-12T13:43:48-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:43:48 volumio volumio[13756]: info: Initializing connection to go-librespot Websocket Feb 12 13:43:48 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 12 13:43:48 volumio go-librespot[14223]: time="2026-02-12T13:43:48-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:43:48 volumio go-librespot[14223]: time="2026-02-12T13:43:48-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 12 13:43:48 volumio go-librespot[14223]: time="2026-02-12T13:43:48-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 12 13:43:48 volumio go-librespot[14223]: time="2026-02-12T13:43:48-06:00" level=info msg="zeroconf server listening on port 36989" Feb 12 13:43:48 volumio go-librespot[14223]: time="2026-02-12T13:43:48-06:00" level=debug msg="obtained new client token: AAAEzrnU5MNTbGO8nvEv4YkX64+TmUryIJ5eYUlbmjpmgtnz2kMP6h71xCIV+SVaMSDK4tyySGpvoaEJq3udcRbjI9iGhBOKvG1MQEIvDUe65lakGcohW4Zg+OIQA2pZej0tKlXBbrjJ7B28de1bpnofnJxNncLlrUEbQoOHXyqfujt9t1kxL/gkFa33u+srJfY9yEMzwCrm4X8Py3adqVgtTTUSpQGMrWhnWncMCJB0/QkAh6TZ9gvF1g==" Feb 12 13:43:48 volumio go-librespot[14223]: time="2026-02-12T13:43:48-06:00" level=debug msg="new websocket client" Feb 12 13:43:48 volumio go-librespot[14223]: time="2026-02-12T13:43:48-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 13:43:48 volumio go-librespot[14223]: time="2026-02-12T13:43:48-06:00" level=debug msg="completed keyexchange" Feb 12 13:43:48 volumio go-librespot[14223]: time="2026-02-12T13:43:48-06:00" level=debug msg="completed challenge" Feb 12 13:43:48 volumio go-librespot[14223]: time="2026-02-12T13:43:48-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 13:43:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:43:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:43:49 volumio volumio[13756]: info: Connection to go-librespot Websocket established Feb 12 13:43:49 volumio volumio[13756]: info: Connection to go-librespot Websocket closed Feb 12 13:43:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 74. Feb 12 13:43:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:43:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:43:52 volumio go-librespot[14247]: go-librespot daemon starting... Feb 12 13:43:52 volumio go-librespot[14248]: time="2026-02-12T13:43:52-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:43:52 volumio go-librespot[14248]: time="2026-02-12T13:43:52-06:00" level=debug msg="app state loaded" Feb 12 13:43:52 volumio go-librespot[14248]: time="2026-02-12T13:43:52-06:00" level=debug msg="stored credentials not found" Feb 12 13:43:52 volumio go-librespot[14248]: time="2026-02-12T13:43:52-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:43:52 volumio go-librespot[14248]: time="2026-02-12T13:43:52-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:43:52 volumio go-librespot[14248]: time="2026-02-12T13:43:52-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 12 13:43:52 volumio go-librespot[14248]: time="2026-02-12T13:43:52-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 12 13:43:52 volumio go-librespot[14248]: time="2026-02-12T13:43:52-06:00" level=info msg="zeroconf server listening on port 42033" Feb 12 13:43:52 volumio go-librespot[14248]: time="2026-02-12T13:43:52-06:00" level=debug msg="obtained new client token: AAAXcrojfNuZtr1HSp6RuGgfSuDjuBLwzw92QWEptzzv47kFE51w3tPy8Qh6RPsjRHiEVNk+9HlBVBg5t6HYw5Gf9Ieqt1orex3ndNE7ukeCreELg15mXPTcsIOVhkntFiEH0PP7kjbjdDSOYVBdXhMb+2WHoSqyfmOlP1D7B3RPvGOyBEVlS2QOFjVYcq0sE0uxQ/FV33lrbSHPP3AVuxMy19YMmiZUTivA+Ph8HxtFqgPpQ2umVAu9Jg==" Feb 12 13:43:52 volumio volumio[13756]: info: Getting Spotify volume Feb 12 13:43:52 volumio volumio[13756]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Feb 12 13:43:52 volumio go-librespot[14248]: time="2026-02-12T13:43:52-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 13:43:52 volumio volumio[13756]: info: CoreCommandRouter::volumioGetState Feb 12 13:43:52 volumio volumio[13756]: info: CorePlayQueue::getTrack 0 Feb 12 13:43:52 volumio volumio[13756]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 12 13:43:52 volumio volumio[13756]: SPOTIFY: SPOTIFY VOLUME undefined Feb 12 13:43:52 volumio volumio[13756]: SPOTIFY: VOLUMIO VOLUME 100 Feb 12 13:43:52 volumio volumio[13756]: info: Aligning Spotify Volume to Volumio Volume Feb 12 13:43:52 volumio volumio[13756]: info: CoreCommandRouter::volumioGetState Feb 12 13:43:52 volumio volumio[13756]: info: CorePlayQueue::getTrack 0 Feb 12 13:43:52 volumio volumio[13756]: info: Setting Spotify Volume from Volumio: 100 Feb 12 13:43:52 volumio go-librespot[14248]: time="2026-02-12T13:43:52-06:00" level=debug msg="completed keyexchange" Feb 12 13:43:52 volumio go-librespot[14248]: time="2026-02-12T13:43:52-06:00" level=debug msg="completed challenge" Feb 12 13:43:52 volumio go-librespot[14248]: time="2026-02-12T13:43:52-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 12 13:43:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:43:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:43:52 volumio volumio[13756]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 13:43:52 volumio volumio[13756]: Error: socket hang up Feb 12 13:43:52 volumio volumio[13756]: at connResetException (node:internal/errors:720:14) Feb 12 13:43:52 volumio volumio[13756]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 12 13:43:52 volumio volumio[13756]: at Socket.emit (node:events:526:35) Feb 12 13:43:52 volumio volumio[13756]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 12 13:43:52 volumio volumio[13756]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 12 13:43:52 volumio volumio[13756]: code: 'ECONNRESET', Feb 12 13:43:52 volumio volumio[13756]: response: undefined Feb 12 13:43:52 volumio volumio[13756]: } Feb 12 13:43:52 volumio volumio[13756]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 13:43:53 volumio sudo[14269]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 13:42' Feb 12 13:43:53 volumio sudo[14269]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:53 volumio sudo[14269]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:54 volumio volumio-remote-updater[2265]: [2026-02-12 13:43:54] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 12 13:43:54 volumio volumio-remote-updater[2265]: [2026-02-12 13:43:54] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 12 13:43:54 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:43:54 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 12 13:43:54 volumio systemd[1]: volumio.service: Consumed 46.931s CPU time. Feb 12 13:43:54 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 12 13:43:54 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 12 13:43:54 volumio kernel: hwmon hwmon1: Voltage normalised Feb 12 13:43:55 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 6576. Feb 12 13:43:55 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 12 13:43:55 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 12 13:43:55 volumio systemd[1]: volumio.service: Consumed 46.931s CPU time. Feb 12 13:43:55 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 12 13:43:55 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 12 13:43:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 75. Feb 12 13:43:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:43:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:43:55 volumio go-librespot[14305]: go-librespot daemon starting... Feb 12 13:43:55 volumio go-librespot[14306]: time="2026-02-12T13:43:55-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:43:55 volumio go-librespot[14306]: time="2026-02-12T13:43:55-06:00" level=debug msg="app state loaded" Feb 12 13:43:55 volumio go-librespot[14306]: time="2026-02-12T13:43:55-06:00" level=debug msg="stored credentials not found" Feb 12 13:43:55 volumio go-librespot[14306]: time="2026-02-12T13:43:55-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:43:56 volumio go-librespot[14306]: time="2026-02-12T13:43:56-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:43:56 volumio go-librespot[14306]: time="2026-02-12T13:43:56-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 12 13:43:56 volumio go-librespot[14306]: time="2026-02-12T13:43:56-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 12 13:43:56 volumio go-librespot[14306]: time="2026-02-12T13:43:56-06:00" level=info msg="zeroconf server listening on port 42683" Feb 12 13:43:56 volumio go-librespot[14306]: time="2026-02-12T13:43:56-06:00" level=debug msg="obtained new client token: AAB6BaPHKWHsDn8lvVhT/SgnRhwRs1H03Iaj8NOKeAddrrMfMJW5h0kj67Hy9wEHssB8s4TkkqXc0pl7UVM16KUgHiebnqdFVeJV97evyev8L0UoXKgLgTt7PJeaSidFzvyc0POtkuwzKNyYtNvVoCsYvm95iktIBjFb8jBqP4HUyZR+aw7l7r3NAKuL1pRCUsASuyR2UpMvD4InjsOSvah0leY7zoBRmT246Iw7ShY6/nxJplp/LVc=" Feb 12 13:43:56 volumio go-librespot[14306]: time="2026-02-12T13:43:56-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 13:43:56 volumio go-librespot[14306]: time="2026-02-12T13:43:56-06:00" level=debug msg="completed keyexchange" Feb 12 13:43:56 volumio go-librespot[14306]: time="2026-02-12T13:43:56-06:00" level=debug msg="completed challenge" Feb 12 13:43:56 volumio go-librespot[14306]: time="2026-02-12T13:43:56-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 13:43:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:43:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:43:57 volumio volumio[14290]: info: ------------------------------------------- Feb 12 13:43:57 volumio volumio[14290]: info: ----- Volumio3 ---- Feb 12 13:43:57 volumio volumio[14290]: info: ------------------------------------------- Feb 12 13:43:57 volumio volumio[14290]: info: ----- System startup ---- Feb 12 13:43:57 volumio volumio[14290]: info: ------------------------------------------- Feb 12 13:43:57 volumio volumio[14290]: info: MYVOLUMIO Environment detected Feb 12 13:43:57 volumio volumio[14290]: info: Plugin folders cleanup Feb 12 13:43:57 volumio volumio[14290]: info: Scanning into folder /volumio/app/plugins/ Feb 12 13:43:57 volumio volumio[14290]: info: Scanning category audio_interface Feb 12 13:43:57 volumio volumio[14290]: info: Scanning category miscellanea Feb 12 13:43:57 volumio volumio[14290]: info: Scanning category music_service Feb 12 13:43:57 volumio volumio[14290]: info: Scanning category plugins.json Feb 12 13:43:57 volumio volumio[14290]: info: Scanning category system_controller Feb 12 13:43:57 volumio volumio[14290]: info: Scanning category user_interface Feb 12 13:43:57 volumio volumio[14290]: info: Scanning into folder /data/plugins/ Feb 12 13:43:57 volumio volumio[14290]: info: Scanning category audio_interface Feb 12 13:43:57 volumio volumio[14290]: info: Scanning category music_service Feb 12 13:43:57 volumio volumio[14290]: info: Scanning category system_controller Feb 12 13:43:57 volumio volumio[14290]: info: Scanning category system_hardware Feb 12 13:43:57 volumio volumio[14290]: info: Scanning category user_interface Feb 12 13:43:57 volumio volumio[14290]: info: Plugin folders cleanup completed Feb 12 13:43:57 volumio volumio[14290]: info: ------------------------------------------- Feb 12 13:43:57 volumio volumio[14290]: info: ----- Core plugins startup ---- Feb 12 13:43:57 volumio volumio[14290]: info: ------------------------------------------- Feb 12 13:43:57 volumio volumio[14290]: info: Loading plugins from folder /volumio/app/plugins/ Feb 12 13:43:57 volumio volumio[14290]: info: Adding plugin upnp to MyMusic Plugins Feb 12 13:43:57 volumio volumio[14290]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 12 13:43:57 volumio volumio[14290]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 12 13:43:57 volumio volumio[14290]: info: Loading plugins from folder /data/plugins/ Feb 12 13:43:57 volumio volumio[14290]: info: Loading plugin "system"... Feb 12 13:43:57 volumio volumio[14290]: info: Loading plugin "appearance"... Feb 12 13:43:59 volumio volumio[14290]: info: Loading plugin "network"... Feb 12 13:43:59 volumio volumio[14290]: info: Refreshing Cached IP Addresses Feb 12 13:43:59 volumio sudo[14326]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 13:43:59 volumio sudo[14328]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 13:43:59 volumio sudo[14326]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:59 volumio sudo[14328]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:59 volumio sudo[14328]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:59 volumio sudo[14326]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:59 volumio volumio[14290]: info: Loading plugin "services"... Feb 12 13:43:59 volumio volumio[14290]: info: Loading plugin "alsa_controller"... Feb 12 13:43:59 volumio sudo[14341]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 12 13:43:59 volumio sudo[14341]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:59 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 13:43:59 volumio volumio[14290]: info: Loading plugin "wizard"... Feb 12 13:43:59 volumio volumio[14290]: info: Loading plugin "networkfs"... Feb 12 13:43:59 volumio volumio[14290]: info: Starting Udev Watcher for removable devices Feb 12 13:43:59 volumio volumio[14290]: info: Ignoring mount for partition: boot Feb 12 13:43:59 volumio volumio[14290]: info: Ignoring mount for partition: volumio Feb 12 13:43:59 volumio volumio[14290]: info: Ignoring mount for partition: volumio_data Feb 12 13:43:59 volumio volumio[14290]: info: Mounting Device Wikipedia Feb 12 13:43:59 volumio sudo[14365]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Feb 12 13:43:59 volumio sudo[14365]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:43:59 volumio sudo[14365]: pam_unix(sudo:session): session closed for user root Feb 12 13:43:59 volumio volumio[14290]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Feb 12 13:43:59 volumio volumio[14290]: dmesg(1) may have more information after failed mount system call. Feb 12 13:43:59 volumio volumio[14290]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Feb 12 13:43:59 volumio volumio[14290]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Feb 12 13:43:59 volumio volumio[14290]: dmesg(1) may have more information after failed mount system call. Feb 12 13:43:59 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 13:43:59 volumio volumio[14290]: info: Loading plugin "volumio_command_line_client"... Feb 12 13:43:59 volumio volumio[14290]: info: Loading plugin "upnp"... Feb 12 13:43:59 volumio volumio[14290]: info: [1770925439484] Starting Upmpd Daemon Feb 12 13:43:59 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 13:43:59 volumio volumio[14290]: info: Loading plugin "my_music"... Feb 12 13:43:59 volumio volumio[14290]: info: Loading plugin "mpd"... Feb 12 13:43:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 76. Feb 12 13:43:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:43:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:43:59 volumio go-librespot[14367]: go-librespot daemon starting... Feb 12 13:43:59 volumio go-librespot[14368]: time="2026-02-12T13:43:59-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:43:59 volumio go-librespot[14368]: time="2026-02-12T13:43:59-06:00" level=debug msg="app state loaded" Feb 12 13:43:59 volumio go-librespot[14368]: time="2026-02-12T13:43:59-06:00" level=debug msg="stored credentials not found" Feb 12 13:43:59 volumio go-librespot[14368]: time="2026-02-12T13:43:59-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:43:59 volumio volumio-remote-updater[2265]: [2026-02-12 13:43:59] [connect] Successful connection Feb 12 13:43:59 volumio sudo[14341]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:00 volumio go-librespot[14368]: time="2026-02-12T13:44:00-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:44:00 volumio go-librespot[14368]: time="2026-02-12T13:44:00-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 13:44:00 volumio go-librespot[14368]: time="2026-02-12T13:44:00-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 13:44:00 volumio go-librespot[14368]: time="2026-02-12T13:44:00-06:00" level=info msg="zeroconf server listening on port 44909" Feb 12 13:44:00 volumio volumio[14290]: info: Loading plugin "upnp_browser"... Feb 12 13:44:00 volumio go-librespot[14368]: time="2026-02-12T13:44:00-06:00" level=debug msg="obtained new client token: AAC4+h+oQxjRTjz+6IR8+uwv6eQ96mQkBv8V3IikRlnh09GhSSQJ9MzeA5Ipucf7VBOUMPDBSVjihPyAn32WRwnBKyIOCe+EJ9j3LUHNGQA0SeTQ+oSArwlAeJ1qFDQayUyCDmuaZxBOVJMEHEd1M1NV8XuxTzWwdoYKUGczTubQ+te5N99syqPRwoisMdkH7Fw6dBdQCkSBz/D0AWztwd6cq0eR2FX2ZJad49sKHUvUbd1GdduXaCA=" Feb 12 13:44:00 volumio go-librespot[14368]: time="2026-02-12T13:44:00-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 13:44:00 volumio go-librespot[14368]: time="2026-02-12T13:44:00-06:00" level=debug msg="completed keyexchange" Feb 12 13:44:00 volumio go-librespot[14368]: time="2026-02-12T13:44:00-06:00" level=debug msg="completed challenge" Feb 12 13:44:00 volumio go-librespot[14368]: time="2026-02-12T13:44:00-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 13:44:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:44:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:44:01 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 12 13:44:02 volumio volumio[14290]: info: Loading plugin "alarm-clock"... Feb 12 13:44:02 volumio volumio[14290]: info: Loading plugin "airplay_emulation"... Feb 12 13:44:02 volumio volumio[14290]: info: Starting Shairport Sync Feb 12 13:44:02 volumio volumio[14290]: info: Loading plugin "last_100"... Feb 12 13:44:02 volumio volumio[14290]: info: Loading plugin "webradio"... Feb 12 13:44:03 volumio volumio[14290]: info: Loading plugin "i2s_dacs"... Feb 12 13:44:03 volumio volumio[14290]: info: I2S DAC not set, start Auto-detection Feb 12 13:44:03 volumio volumio[14290]: info: Loading plugin "volumiodiscovery"... Feb 12 13:44:03 volumio volumio[14290]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 12 13:44:03 volumio volumio[14290]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 13:44:03 volumio volumio[14290]: *** WARNING *** For more information see Feb 12 13:44:03 volumio volumio[14290]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 12 13:44:03 volumio volumio[14290]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 13:44:03 volumio volumio[14290]: *** WARNING *** For more information see Feb 12 13:44:03 volumio node[14290]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 12 13:44:03 volumio node[14290]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 13:44:03 volumio node[14290]: *** WARNING *** For more information see Feb 12 13:44:03 volumio node[14290]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 12 13:44:03 volumio node[14290]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 13:44:03 volumio node[14290]: *** WARNING *** For more information see Feb 12 13:44:03 volumio volumio[14290]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 12 13:44:03 volumio volumio[14290]: info: Discovery: Started advertising with name: Volumio Feb 12 13:44:03 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 13:44:03 volumio volumio[14290]: info: Loading plugin "bandcamp"... Feb 12 13:44:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 77. Feb 12 13:44:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:03 volumio go-librespot[14378]: go-librespot daemon starting... Feb 12 13:44:03 volumio go-librespot[14379]: time="2026-02-12T13:44:03-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:44:03 volumio go-librespot[14379]: time="2026-02-12T13:44:03-06:00" level=debug msg="app state loaded" Feb 12 13:44:03 volumio go-librespot[14379]: time="2026-02-12T13:44:03-06:00" level=debug msg="stored credentials not found" Feb 12 13:44:03 volumio go-librespot[14379]: time="2026-02-12T13:44:03-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:44:03 volumio go-librespot[14379]: time="2026-02-12T13:44:03-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:44:03 volumio go-librespot[14379]: time="2026-02-12T13:44:03-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 12 13:44:03 volumio go-librespot[14379]: time="2026-02-12T13:44:03-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 12 13:44:03 volumio go-librespot[14379]: time="2026-02-12T13:44:03-06:00" level=info msg="zeroconf server listening on port 43211" Feb 12 13:44:03 volumio go-librespot[14379]: time="2026-02-12T13:44:03-06:00" level=debug msg="obtained new client token: AAA4nsazYkH4MzAu6C7oGCLmQ4bYVBhGxhzkMovbWAq2JyzOCHq5vuEjmRjHiF2XQXN7HtU1Y9b7dNA5/SQ/CHjPS/9naqs0Yxz3tcRJAC/83hi2treMxf7yDrTC/lTXm8mRTc5fYUEW1vn0Ub7WCOBuMTvqFHzYOAhqeAqLf5zpPibw9vXTglNdbT3E78i4eCoZ2v7gz0MWo6qj2sdnt/clb/ZhfBY8wAX9mjuEK/aeKSFpp7+Y8jbhhA==" Feb 12 13:44:04 volumio go-librespot[14379]: time="2026-02-12T13:44:04-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 13:44:04 volumio go-librespot[14379]: time="2026-02-12T13:44:04-06:00" level=debug msg="completed keyexchange" Feb 12 13:44:04 volumio go-librespot[14379]: time="2026-02-12T13:44:04-06:00" level=debug msg="completed challenge" Feb 12 13:44:04 volumio go-librespot[14379]: time="2026-02-12T13:44:04-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 13:44:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:44:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:44:04 volumio volumio[14290]: info: Plugin calmradio is not enabled Feb 12 13:44:04 volumio volumio[14290]: info: Loading plugin "soundcloud"... Feb 12 13:44:04 volumio volumio[14290]: info: Loading plugin "spop"... Feb 12 13:44:05 volumio kernel: hwmon hwmon1: Voltage normalised Feb 12 13:44:05 volumio volumio[14290]: info: Loading plugin "squeezelite_mc"... Feb 12 13:44:06 volumio volumio[14290]: info: Loading plugin "youtube2"... Feb 12 13:44:07 volumio volumio[14290]: info: Loading plugin "ytcr"... Feb 12 13:44:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 78. Feb 12 13:44:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:07 volumio go-librespot[14391]: go-librespot daemon starting... Feb 12 13:44:07 volumio go-librespot[14392]: time="2026-02-12T13:44:07-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:44:07 volumio go-librespot[14392]: time="2026-02-12T13:44:07-06:00" level=debug msg="app state loaded" Feb 12 13:44:07 volumio go-librespot[14392]: time="2026-02-12T13:44:07-06:00" level=debug msg="stored credentials not found" Feb 12 13:44:07 volumio go-librespot[14392]: time="2026-02-12T13:44:07-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:44:07 volumio go-librespot[14392]: time="2026-02-12T13:44:07-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 12 13:44:07 volumio go-librespot[14392]: time="2026-02-12T13:44:07-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 12 13:44:07 volumio go-librespot[14392]: time="2026-02-12T13:44:07-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 12 13:44:07 volumio go-librespot[14392]: time="2026-02-12T13:44:07-06:00" level=info msg="zeroconf server listening on port 44001" Feb 12 13:44:07 volumio go-librespot[14392]: time="2026-02-12T13:44:07-06:00" level=debug msg="obtained new client token: AAAQZhgKe0C1Y+FjV0+oip4Zc2f2bNWdNh2MT6d3jhWelvC7aolAPj+uB/ZiHZUBqFVJYpCOBCwoMF3Y18M3lSs2zv2JoX2Hplm2nOcfDOcaK0P4ODR/wz/gacmaGuj13c+VHT7UlGZgIyap/4dhKjfg1O1n2enRAdi9f1MIJKHtuW69zjO7HsOyA8SD/IeRQaUUP+ziy/HPbY+Mrykb2QBsfklEct491OSSxpWzXQgyoIrswyTZV8QW2A==" Feb 12 13:44:07 volumio go-librespot[14392]: time="2026-02-12T13:44:07-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 13:44:07 volumio go-librespot[14392]: time="2026-02-12T13:44:07-06:00" level=debug msg="completed keyexchange" Feb 12 13:44:07 volumio go-librespot[14392]: time="2026-02-12T13:44:07-06:00" level=debug msg="completed challenge" Feb 12 13:44:07 volumio go-librespot[14392]: time="2026-02-12T13:44:07-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 13:44:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:44:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:44:08 volumio volumio[14290]: info: Loading plugin "ytmusic"... Feb 12 13:44:09 volumio volumio[14290]: info: Plugin now_playing is not enabled Feb 12 13:44:09 volumio volumio[14290]: info: Loading plugin "outputs"... Feb 12 13:44:09 volumio volumio[14290]: info: Loading plugin "albumart"... Feb 12 13:44:09 volumio volumio[14290]: info: Plugin example_plugin is not enabled Feb 12 13:44:09 volumio volumio[14290]: info: Loading plugin "inputs"... Feb 12 13:44:09 volumio volumio[14290]: info: Loading plugin "updater_comm"... Feb 12 13:44:09 volumio volumio[14290]: info: Plugin mpdemulation is not enabled Feb 12 13:44:09 volumio volumio[14290]: info: Loading plugin "rest_api"... Feb 12 13:44:09 volumio volumio[14290]: info: Loading plugin "websocket"... Feb 12 13:44:09 volumio volumio[14290]: info: Starting Socket.io Server version 1.7.4 Feb 12 13:44:09 volumio volumio[14290]: info: Plugin fusiondsp is not enabled Feb 12 13:44:09 volumio volumio[14290]: info: Plugin mpdoutput is not enabled Feb 12 13:44:09 volumio volumio[14290]: info: Plugin RoonBridge is not enabled Feb 12 13:44:09 volumio volumio[14290]: info: Loading plugin "podcast"... Feb 12 13:44:09 volumio volumio[14290]: info: ControllerPodcast::constructor Feb 12 13:44:09 volumio volumio[14290]: info: Loading plugin "volusonic"... Feb 12 13:44:09 volumio volumio[14401]: Forking 3 albumart workers Feb 12 13:44:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 79. Feb 12 13:44:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:11 volumio go-librespot[14455]: go-librespot daemon starting... Feb 12 13:44:11 volumio go-librespot[14456]: time="2026-02-12T13:44:11-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:44:11 volumio go-librespot[14456]: time="2026-02-12T13:44:11-06:00" level=debug msg="app state loaded" Feb 12 13:44:11 volumio go-librespot[14456]: time="2026-02-12T13:44:11-06:00" level=debug msg="stored credentials not found" Feb 12 13:44:11 volumio go-librespot[14456]: time="2026-02-12T13:44:11-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:44:11 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 12 13:44:11 volumio go-librespot[14456]: time="2026-02-12T13:44:11-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 12 13:44:11 volumio go-librespot[14456]: time="2026-02-12T13:44:11-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 12 13:44:11 volumio go-librespot[14456]: time="2026-02-12T13:44:11-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 12 13:44:11 volumio volumio[14425]: Starting albumart workers Feb 12 13:44:11 volumio go-librespot[14456]: time="2026-02-12T13:44:11-06:00" level=info msg="zeroconf server listening on port 36557" Feb 12 13:44:11 volumio volumio[14290]: info: Applying required configuration parameters for plugin volusonic Feb 12 13:44:11 volumio volumio[14290]: info: Loading plugin "backup_restore"... Feb 12 13:44:11 volumio go-librespot[14456]: time="2026-02-12T13:44:11-06:00" level=debug msg="obtained new client token: AABMuLaaJ4nOK6xVbSpw9GQddxNdnKT0/BQl5ScV8GD5MyoMz8njjZSS75LYkxgdPKNOVTPiTb5tbIF4YII5yPJHvszTPFFfj+nYX8bYTipNz+vMq7/eUpidvQe5LZrs/wsmE1YuFY5KxDLoZMBjEj/TdZDwgEVa04VwLVfBJo1FZ+WX0Yn7BWEOywlygY/cwnjQp7yp3huxAWKHQ3UHu4RrEU/IEro4yzwgL9NE390iq9ggKi2kMKok0g==" Feb 12 13:44:12 volumio go-librespot[14456]: time="2026-02-12T13:44:12-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 13:44:12 volumio volumio[14427]: Starting albumart workers Feb 12 13:44:12 volumio volumio[14426]: Starting albumart workers Feb 12 13:44:12 volumio go-librespot[14456]: time="2026-02-12T13:44:12-06:00" level=debug msg="completed keyexchange" Feb 12 13:44:12 volumio go-librespot[14456]: time="2026-02-12T13:44:12-06:00" level=debug msg="completed challenge" Feb 12 13:44:12 volumio go-librespot[14456]: time="2026-02-12T13:44:12-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 13:44:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:44:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:44:12 volumio volumio-remote-updater[2265]: [2026-02-12 13:44:12] [connect] Successful connection Feb 12 13:44:12 volumio volumio[14290]: info: Applying required configuration parameters for plugin backup_restore Feb 12 13:44:12 volumio volumio[14290]: info: Plugin rpi_eeprom_config is not enabled Feb 12 13:44:12 volumio volumio[14290]: info: Plugin rpi_eeprom_updater is not enabled Feb 12 13:44:12 volumio volumio[14290]: info: Loading plugin "scheduledrestart"... Feb 12 13:44:12 volumio volumio[14290]: info: Applying required configuration parameters for plugin scheduledrestart Feb 12 13:44:12 volumio volumio[14290]: info: Plugin Bluetoothremote is not enabled Feb 12 13:44:12 volumio volumio[14290]: info: Plugin music_services_shield is not enabled Feb 12 13:44:12 volumio volumio[14290]: info: Loading plugin "Systeminfo"... Feb 12 13:44:13 volumio volumio[14290]: info: Plugin peppymeterbasic is not enabled Feb 12 13:44:13 volumio volumio[14290]: info: Loading plugin "peppyspectrum"... Feb 12 13:44:13 volumio volumio[14290]: info: Loading i18n strings for locale en Feb 12 13:44:13 volumio volumio[14290]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Feb 12 13:44:13 volumio volumio[14290]: Updating browse sources language Feb 12 13:44:13 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::initPlayerControls Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 13:44:14 volumio volumio[14290]: Express server listening on port 3000 Feb 12 13:44:14 volumio volumio[14290]: [Metrics] WebUI: 17s 561.68ms Feb 12 13:44:14 volumio volumio[14290]: info: CoreStateMachine::resetVolumioState Feb 12 13:44:14 volumio volumio[14290]: info: CoreStateMachine::getcurrentVolume Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:44:14 volumio sudo[14488]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 13:44:14 volumio sudo[14488]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:14 volumio sudo[14490]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 13:44:14 volumio sudo[14490]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:14 volumio sudo[14488]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:14 volumio sudo[14490]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:14 volumio volumio[14290]: info: Volumio Network Manager: Network status updated: 1 Feb 12 13:44:14 volumio volumio[14290]: info: VolumeController:: Volume=100 Mute =false Feb 12 13:44:14 volumio volumio[14290]: info: CoreStateMachine::pushState Feb 12 13:44:14 volumio volumio[14290]: info: CorePlayQueue::getTrack 0 Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::volumioPushState Feb 12 13:44:14 volumio volumio[14290]: info: CoreStateMachine::updateTrackBlock Feb 12 13:44:14 volumio volumio[14290]: info: CorePlayQueue::getTrackBlock Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 13:44:14 volumio volumio-remote-updater[2265]: [2026-02-12 13:44:14] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770925452 101 Feb 12 13:44:14 volumio volumio[14290]: 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 12 13:44:14 volumio volumio[14290]: info: Reloading queue from file Feb 12 13:44:14 volumio volumio[14290]: info: CoreStateMachine::setRepeat null single undefined Feb 12 13:44:14 volumio volumio[14290]: info: CoreStateMachine::pushState Feb 12 13:44:14 volumio volumio[14290]: info: CorePlayQueue::getTrack 0 Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::volumioPushState Feb 12 13:44:14 volumio volumio[14290]: info: CoreStateMachine::setRandom null Feb 12 13:44:14 volumio volumio[14290]: info: CoreStateMachine::pushState Feb 12 13:44:14 volumio volumio[14290]: info: CorePlayQueue::getTrack 0 Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::volumioPushState Feb 12 13:44:14 volumio volumio[14290]: info: Setting Device type: Raspberry PI Feb 12 13:44:14 volumio volumio[14290]: info: VolumeController:: Volume=100 Mute =false Feb 12 13:44:14 volumio volumio[14290]: info: CoreStateMachine::pushState Feb 12 13:44:14 volumio volumio[14290]: info: CorePlayQueue::getTrack 0 Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::volumioPushState Feb 12 13:44:14 volumio volumio[14290]: info: Completed loading Core Plugins Feb 12 13:44:14 volumio volumio[14290]: info: Preparing to generate the ALSA configuration file Feb 12 13:44:14 volumio sudo[14503]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 12 13:44:14 volumio sudo[14503]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:14 volumio volumio[14290]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Feb 12 13:44:14 volumio volumio[14290]: info: Discovery: Found device Volumio Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::volumioGetState Feb 12 13:44:14 volumio volumio[14290]: info: CorePlayQueue::getTrack 0 Feb 12 13:44:14 volumio volumio[14290]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Feb 12 13:44:14 volumio volumio[14290]: info: Discovery: Found device Volumio Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::volumioGetState Feb 12 13:44:14 volumio volumio[14290]: info: CorePlayQueue::getTrack 0 Feb 12 13:44:14 volumio volumio[14290]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Feb 12 13:44:14 volumio sudo[14503]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:14 volumio volumio[14290]: info: Reading ALSA contributions from plugins. Feb 12 13:44:14 volumio volumio[14290]: info: Upmpdcli Daemon Started Feb 12 13:44:14 volumio volumio[14290]: info: Asound.conf file unchanged, so no further update is needed Feb 12 13:44:14 volumio volumio[14290]: info: Output device has changed, restarting MPD Feb 12 13:44:14 volumio volumio[14290]: info: Output device has changed, restarting Shairport Sync Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:44:14 volumio sudo[14506]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 13:44:14 volumio sudo[14506]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:14 volumio sudo[14506]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:14 volumio sudo[14508]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 13:44:14 volumio sudo[14508]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:14 volumio volumio[14290]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 13:44:14 volumio volumio[14290]: info: ___________ START PLUGINS ___________ Feb 12 13:44:14 volumio volumio[14290]: info: ControllerMpd::onStart: Initializing MPD Feb 12 13:44:14 volumio volumio[14290]: info: Creating MPD Configuration file Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 13:44:14 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:44:14 volumio volumio[14290]: info: [1770925454698] CoreMusicLibrary::Adding element Media Servers Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:44:14 volumio sudo[14516]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 13:44:14 volumio sudo[14516]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:14 volumio sudo[14516]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:14 volumio sudo[14518]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 13:44:14 volumio sudo[14518]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:44:14 volumio volumio[14290]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:44:14 volumio volumio[14290]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:44:14 volumio volumio[14290]: info: [1770925454808] CoreMusicLibrary::Adding element Last_100 Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:44:14 volumio volumio[14290]: info: [1770925454812] CoreMusicLibrary::Adding element Webradio Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:44:14 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 13:44:14 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 12 13:44:14 volumio systemd[1]: mpd.service: Consumed 5.629s CPU time. Feb 12 13:44:14 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 12 13:44:14 volumio volumio[14290]: info: Initializing BBC Radios Feb 12 13:44:14 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 12 13:44:14 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:44:14 volumio volumio[14290]: info: [1770925454885] CoreMusicLibrary::Adding element Bandcamp Discover Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:44:14 volumio volumio[14290]: Cannot find translation for source Bandcamp Discover Feb 12 13:44:14 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 12 13:44:14 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:44:14 volumio volumio[14290]: info: [1770925454901] CoreMusicLibrary::Adding element SoundCloud Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:44:14 volumio volumio[14290]: Cannot find translation for source Bandcamp Discover Feb 12 13:44:14 volumio volumio[14290]: Cannot find translation for source SoundCloud Feb 12 13:44:14 volumio volumio[14290]: info: Creating Spotify config file Feb 12 13:44:14 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:15 volumio sudo[14543]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 12 13:44:15 volumio sudo[14543]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 12 13:44:15 volumio sudo[14543]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 80. Feb 12 13:44:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:15 volumio go-librespot[14546]: go-librespot daemon starting... Feb 12 13:44:15 volumio go-librespot[14547]: time="2026-02-12T13:44:15-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:44:15 volumio volumio[14290]: info: [squeezelite_mc] Starting proxy server... Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:44:15 volumio volumio[14290]: info: [1770925455284] CoreMusicLibrary::Adding element YouTube2 Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:44:15 volumio volumio[14290]: Cannot find translation for source Bandcamp Discover Feb 12 13:44:15 volumio volumio[14290]: Cannot find translation for source SoundCloud Feb 12 13:44:15 volumio volumio[14290]: Cannot find translation for source YouTube2 Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:44:15 volumio volumio[14290]: info: [1770925455309] CoreMusicLibrary::Adding element YouTube Music Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:44:15 volumio volumio[14290]: Cannot find translation for source Bandcamp Discover Feb 12 13:44:15 volumio volumio[14290]: Cannot find translation for source SoundCloud Feb 12 13:44:15 volumio volumio[14290]: Cannot find translation for source YouTube2 Feb 12 13:44:15 volumio volumio[14290]: Cannot find translation for source YouTube Music Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:44:15 volumio volumio[14290]: info: [1770925455323] CoreMusicLibrary::Adding element Podcast Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:44:15 volumio volumio[14290]: Cannot find translation for source Bandcamp Discover Feb 12 13:44:15 volumio volumio[14290]: Cannot find translation for source SoundCloud Feb 12 13:44:15 volumio volumio[14290]: Cannot find translation for source YouTube2 Feb 12 13:44:15 volumio volumio[14290]: Cannot find translation for source YouTube Music Feb 12 13:44:15 volumio volumio[14290]: Cannot find translation for source Podcast Feb 12 13:44:15 volumio volumio[14290]: info: Loading i18n strings for locale en Feb 12 13:44:15 volumio volumio[14290]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Feb 12 13:44:15 volumio volumio[14290]: Updating browse sources language Feb 12 13:44:15 volumio volumio[14290]: Cannot find translation for source Bandcamp Discover Feb 12 13:44:15 volumio volumio[14290]: Cannot find translation for source SoundCloud Feb 12 13:44:15 volumio volumio[14290]: Cannot find translation for source YouTube2 Feb 12 13:44:15 volumio volumio[14290]: Cannot find translation for source YouTube Music Feb 12 13:44:15 volumio volumio[14290]: Cannot find translation for source Podcast Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:44:15 volumio volumio[14290]: Cannot find translation for source Bandcamp Discover Feb 12 13:44:15 volumio volumio[14290]: Cannot find translation for source SoundCloud Feb 12 13:44:15 volumio volumio[14290]: Cannot find translation for source YouTube2 Feb 12 13:44:15 volumio volumio[14290]: Cannot find translation for source YouTube Music Feb 12 13:44:15 volumio volumio[14290]: Cannot find translation for source Podcast Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:44:15 volumio volumio[14290]: info: [1770925455375] CoreMusicLibrary::Adding element Volusonic Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:44:15 volumio volumio[14290]: Cannot find translation for source Bandcamp Discover Feb 12 13:44:15 volumio volumio[14290]: Cannot find translation for source SoundCloud Feb 12 13:44:15 volumio volumio[14290]: Cannot find translation for source YouTube2 Feb 12 13:44:15 volumio volumio[14290]: Cannot find translation for source YouTube Music Feb 12 13:44:15 volumio volumio[14290]: Cannot find translation for source Podcast Feb 12 13:44:15 volumio volumio[14290]: Cannot find translation for source Volusonic Feb 12 13:44:15 volumio volumio[14290]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Feb 12 13:44:15 volumio volumio[14290]: info: Volumio Calling Home Feb 12 13:44:15 volumio go-librespot[14547]: time="2026-02-12T13:44:15-06:00" level=info msg="zeroconf server listening on port 39443" Feb 12 13:44:15 volumio volumio[14290]: info: [squeezelite_mc] Proxy server started on port 33815 Feb 12 13:44:15 volumio volumio[14290]: info: Preparing to generate the ALSA configuration file Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 13:44:15 volumio volumio[14290]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Feb 12 13:44:15 volumio volumio[14290]: info: Reading ALSA contributions from plugins. Feb 12 13:44:15 volumio volumio[14290]: info: MPD Permissions set Feb 12 13:44:15 volumio volumio[14290]: info: MPD Permissions set Feb 12 13:44:15 volumio volumio[14290]: info: Spotify config file written Feb 12 13:44:15 volumio sudo[14560]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 12 13:44:15 volumio sudo[14560]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:15 volumio volumio[14290]: 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 12 13:44:15 volumio volumio[14290]: info: VolumeController:: Volume=100 Mute =false Feb 12 13:44:15 volumio volumio[14290]: info: CoreStateMachine::pushState Feb 12 13:44:15 volumio volumio[14290]: info: CorePlayQueue::getTrack 0 Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::volumioPushState Feb 12 13:44:15 volumio volumio[14290]: info: [squeezelite_mc] Server discovery started Feb 12 13:44:15 volumio volumio[14290]: info: [squeezelite_mc] Player finder started Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 13:44:15 volumio volumio[14290]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Feb 12 13:44:15 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 12 13:44:15 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 12 13:44:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:15 volumio sudo[14560]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:15 volumio go-librespot[14564]: go-librespot daemon starting... Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:44:15 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:15 volumio go-librespot[14575]: time="2026-02-12T13:44:15-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:44:15 volumio go-librespot[14575]: time="2026-02-12T13:44:15-06:00" level=debug msg="app state loaded" Feb 12 13:44:15 volumio go-librespot[14575]: time="2026-02-12T13:44:15-06:00" level=debug msg="stored credentials not found" Feb 12 13:44:15 volumio go-librespot[14575]: time="2026-02-12T13:44:15-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:44:15 volumio volumio[14290]: info: No need to fix Spotify hosts Feb 12 13:44:16 volumio volumio[14290]: 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 12 13:44:16 volumio volumio[14290]: info: Volumio called home Feb 12 13:44:16 volumio volumio[14290]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Feb 12 13:44:16 volumio volumio[14290]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Feb 12 13:44:16 volumio volumio[14290]: 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 12 13:44:16 volumio go-librespot[14575]: time="2026-02-12T13:44:16-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:44:16 volumio go-librespot[14575]: time="2026-02-12T13:44:16-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 13:44:16 volumio go-librespot[14575]: time="2026-02-12T13:44:16-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 13:44:16 volumio go-librespot[14575]: time="2026-02-12T13:44:16-06:00" level=info msg="zeroconf server listening on port 35711" Feb 12 13:44:16 volumio volumio[14290]: info: Starting Shairport Sync Feb 12 13:44:16 volumio volumio[14290]: info: Starting Shairport Sync Feb 12 13:44:16 volumio volumio[14290]: info: Starting Shairport Sync Feb 12 13:44:16 volumio sudo[14585]: 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 12 13:44:16 volumio sudo[14585]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:16 volumio sudo[14587]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 13:44:16 volumio sudo[14587]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:16 volumio sudo[14585]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:16 volumio sudo[14589]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 13:44:16 volumio go-librespot[14575]: time="2026-02-12T13:44:16-06:00" level=debug msg="obtained new client token: AAC0fxv46YN6cHr9YS7lbBvSXAF3opE0IPx+SjaawIa0PEcwTOpqfHw21xKV/QfgnQcIRleWzWev7KSsGIfH5llqeeQVPeBFj5qPGIo73lPTTJDh07umb4FM8qfqzgW3+KPrY+7wIgfjKsj6rbeCkdSP25v7/mjjzke/yau1N4qhnszjoYpqs5aGWopWLF7qP4VEPYILZ/MKdurxsglCyrOhi24ceBq7sT3Y7BN4jhfxdigvssjqJwFOYg==" Feb 12 13:44:16 volumio sudo[14589]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:16 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 13:44:16 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 13:44:16 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 13:44:16 volumio systemd[1]: shairport-sync.service: Consumed 2.015s CPU time. Feb 12 13:44:16 volumio sudo[14591]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 13:44:16 volumio sudo[14591]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:16 volumio go-librespot[14575]: time="2026-02-12T13:44:16-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 13:44:16 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 13:44:16 volumio go-librespot[14575]: time="2026-02-12T13:44:16-06:00" level=debug msg="completed keyexchange" Feb 12 13:44:16 volumio go-librespot[14575]: time="2026-02-12T13:44:16-06:00" level=debug msg="completed challenge" Feb 12 13:44:16 volumio sudo[14587]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:16 volumio go-librespot[14575]: time="2026-02-12T13:44:16-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 13:44:16 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 13:44:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:44:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:44:16 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 13:44:16 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 13:44:16 volumio volumio[14290]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Feb 12 13:44:16 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 13:44:16 volumio volumio[14290]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 13:44:16 volumio volumio[14290]: SPOTIFY: BQBz0WLh5plzLXK1wncnW5aHpHwZpKGvyz83H3EgUCZc1BPnmaKpRu0Iic0EY6bP-FkuLsaGuJiGfjUrkN-AYnYcOFYnxSkhvoLDAUuIGEp0MNG-UnRYRDZoa4SLIkXRFnsXLHs2ht8uf2yYyyQOlqIf12v9Y6eoE9kXzAsnBEUv0tUqmJCOsXA1pfijmaamtfQ-qvrGpzncuglK_reho_1o7kSotLuTTtpwK9I Feb 12 13:44:16 volumio volumio[14290]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 13:44:16 volumio volumio[14290]: info: New Spotify access token = BQBz0WLh5plzLXK1wncnW5aHpHwZpKGvyz83H3EgUCZc1BPnmaKpRu0Iic0EY6bP-FkuLsaGuJiGfjUrkN-AYnYcOFYnxSkhvoLDAUuIGEp0MNG-UnRYRDZoa4SLIkXRFnsXLHs2ht8uf2yYyyQOlqIf12v9Y6eoE9kXzAsnBEUv0tUqmJCOsXA1pfijmaamtfQ-qvrGpzncuglK_reho_1o7kSotLuTTtpwK9I Feb 12 13:44:16 volumio volumio[14290]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 12 13:44:16 volumio sudo[14589]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:16 volumio sudo[14591]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:16 volumio sudo[14604]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Feb 12 13:44:16 volumio sudo[14604]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:16 volumio volumio[14290]: info: Asound.conf file unchanged, so no further update is needed Feb 12 13:44:16 volumio volumio[14290]: info: Output device has changed, restarting MPD Feb 12 13:44:16 volumio sudo[14604]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:16 volumio volumio[14290]: info: Output device has changed, restarting Shairport Sync Feb 12 13:44:16 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:16 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:44:16 volumio sudo[14607]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 13:44:16 volumio sudo[14607]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:16 volumio sudo[14607]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:16 volumio volumio[14290]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 13:44:16 volumio sudo[14609]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 13:44:16 volumio sudo[14609]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:16 volumio volumio[14290]: info: Shairport-Sync Started Feb 12 13:44:16 volumio volumio[14290]: Error adding Membership: Error: addMembership EINVAL Feb 12 13:44:16 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 12 13:44:16 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 12 13:44:16 volumio systemd[1]: mpd.service: Consumed 1.795s CPU time. Feb 12 13:44:16 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 12 13:44:16 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 12 13:44:16 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 12 13:44:16 volumio volumio[14290]: info: MPD Permissions set Feb 12 13:44:16 volumio volumio[14290]: 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 12 13:44:16 volumio volumio[14290]: info: Shairport-Sync Started Feb 12 13:44:16 volumio volumio[14290]: info: Shairport-Sync Started Feb 12 13:44:16 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 12 13:44:16 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 12 13:44:16 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:16 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:16 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:16 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:16 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:16 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:16 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:16 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:16 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:44:16 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:17 volumio sudo[14636]: 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 12 13:44:17 volumio sudo[14636]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:17 volumio sudo[14636]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:17 volumio volumio[14290]: info: CoreCommandRouter::volumioGetState Feb 12 13:44:17 volumio volumio[14290]: info: CorePlayQueue::getTrack 0 Feb 12 13:44:17 volumio volumio[14290]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Feb 12 13:44:17 volumio volumio[14290]: info: Starting Shairport Sync Feb 12 13:44:17 volumio sudo[14645]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Feb 12 13:44:17 volumio sudo[14645]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:17 volumio sudo[14647]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 13:44:17 volumio sudo[14647]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:17 volumio systemd[1]: Reloading. Feb 12 13:44:17 volumio volumio[14290]: 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 12 13:44:17 volumio volumio[14290]: info: Spotify Successfully logged in Feb 12 13:44:17 volumio volumio[14290]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:44:17 volumio volumio[14290]: info: [1770925457198] CoreMusicLibrary::Adding element Spotify Feb 12 13:44:17 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:44:17 volumio volumio[14290]: Cannot find translation for source Bandcamp Discover Feb 12 13:44:17 volumio volumio[14290]: Cannot find translation for source SoundCloud Feb 12 13:44:17 volumio volumio[14290]: Cannot find translation for source YouTube2 Feb 12 13:44:17 volumio volumio[14290]: Cannot find translation for source YouTube Music Feb 12 13:44:17 volumio volumio[14290]: Cannot find translation for source Podcast Feb 12 13:44:17 volumio volumio[14290]: Cannot find translation for source Volusonic Feb 12 13:44:17 volumio volumio[14290]: Cannot find translation for source Spotify Feb 12 13:44:17 volumio sudo[14637]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 12 13:44:17 volumio sudo[14637]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 12 13:44:17 volumio sudo[14637]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:17 volumio kernel: hwmon hwmon1: Voltage normalised Feb 12 13:44:18 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:18 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:18 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:18 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 13:44:18 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 12 13:44:18 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 12 13:44:18 volumio sudo[14645]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:18 volumio volumio[14290]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 13:44:18 volumio sudo[14671]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 13:44:18 volumio sudo[14671]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:19 volumio sudo[14671]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:19 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 13:44:19 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 13:44:19 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 13:44:19 volumio systemd[1]: shairport-sync.service: Consumed 1.464s CPU time. Feb 12 13:44:19 volumio volumio[14290]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Feb 12 13:44:19 volumio sudo[14674]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Feb 12 13:44:19 volumio sudo[14674]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:19 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 13:44:19 volumio sudo[14647]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:19 volumio volumio[14290]: info: Shairport-Sync Started Feb 12 13:44:19 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 12 13:44:19 volumio volumio[14290]: info: go-librespot daemon successfully initialized Feb 12 13:44:19 volumio systemd[1]: squeezelite.service: Deactivated successfully. Feb 12 13:44:19 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 12 13:44:19 volumio sudo[14674]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 12 13:44:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:19 volumio go-librespot[14705]: go-librespot daemon starting... Feb 12 13:44:19 volumio volumio[14290]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 13:44:19 volumio go-librespot[14706]: time="2026-02-12T13:44:19-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:44:19 volumio go-librespot[14706]: time="2026-02-12T13:44:19-06:00" level=debug msg="app state loaded" Feb 12 13:44:19 volumio go-librespot[14706]: time="2026-02-12T13:44:19-06:00" level=debug msg="stored credentials not found" Feb 12 13:44:19 volumio go-librespot[14706]: time="2026-02-12T13:44:19-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:44:19 volumio sudo[14713]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 13:44:19 volumio sudo[14713]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:19 volumio sudo[14713]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:20 volumio volumio[14290]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Feb 12 13:44:20 volumio sudo[14718]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Feb 12 13:44:20 volumio sudo[14718]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:20 volumio sudo[14718]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:20 volumio volumio[14290]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Feb 12 13:44:20 volumio sudo[14721]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Feb 12 13:44:20 volumio sudo[14721]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:20 volumio go-librespot[14706]: time="2026-02-12T13:44:20-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:44:20 volumio go-librespot[14706]: time="2026-02-12T13:44:20-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 13:44:20 volumio go-librespot[14706]: time="2026-02-12T13:44:20-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 13:44:20 volumio go-librespot[14706]: time="2026-02-12T13:44:20-06:00" level=info msg="zeroconf server listening on port 33079" Feb 12 13:44:20 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 12 13:44:20 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 12 13:44:20 volumio sudo[14721]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:20 volumio go-librespot[14706]: time="2026-02-12T13:44:20-06:00" level=debug msg="obtained new client token: AABd40N1Do2pQAl3DQxYLHZF+grtrpJuIfy4bJAJu/vzyZ6lm755ge8LvIzT5gmEe/KDG2kJTF/o6GcWDGIMJZDNfXuC/twoXRhuMeLUqv2LpU6q8UJkt99p0/hhT4Ei54ic/5K67hwB3Zf2n0cfMIn5XuU7rvbHBE6k8OcbRIp/BE1Rzx7EJvdx98y0f3E83g8jC4mPFjAy4IuQBLRvNjsNyqR1ZNAFgfbW6Cw4Ps9nvGIu6C3LMkw9Zg==" Feb 12 13:44:20 volumio go-librespot[14706]: time="2026-02-12T13:44:20-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 13:44:20 volumio go-librespot[14706]: time="2026-02-12T13:44:20-06:00" level=debug msg="completed keyexchange" Feb 12 13:44:20 volumio go-librespot[14706]: time="2026-02-12T13:44:20-06:00" level=debug msg="completed challenge" Feb 12 13:44:20 volumio go-librespot[14706]: time="2026-02-12T13:44:20-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 13:44:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:44:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:44:20 volumio volumio[14290]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 13:44:20 volumio sudo[14729]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 13:44:20 volumio sudo[14729]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:20 volumio sudo[14729]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:21 volumio volumio[14290]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 13:44:21 volumio sudo[14732]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 13:44:21 volumio sudo[14732]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:21 volumio sudo[14732]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:22 volumio volumio[14290]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 13:44:22 volumio mpd[14669]: 2026-02-12T13:44:22 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 12 13:44:22 volumio sudo[14735]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 13:44:22 volumio sudo[14735]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:22 volumio sudo[14735]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:22 volumio volumio[14290]: info: Initializing connection to go-librespot Websocket Feb 12 13:44:22 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 12 13:44:22 volumio sudo[14609]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:22 volumio sudo[14518]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:22 volumio sudo[14508]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:22 volumio volumio[14290]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 13:44:22 volumio volumio[14290]: error: MPD error: The expression evaluated to a falsy value: Feb 12 13:44:22 volumio volumio[14290]: assert.ok(self.idling) Feb 12 13:44:22 volumio volumio[14290]: error: The expression evaluated to a falsy value: Feb 12 13:44:22 volumio volumio[14290]: assert.ok(self.idling) Feb 12 13:44:22 volumio volumio[14290]: error: MPD error: The expression evaluated to a falsy value: Feb 12 13:44:22 volumio volumio[14290]: assert.ok(self.idling) Feb 12 13:44:22 volumio volumio[14290]: error: The expression evaluated to a falsy value: Feb 12 13:44:22 volumio volumio[14290]: assert.ok(self.idling) Feb 12 13:44:22 volumio volumio[14290]: info: MPD running with PID14669 Feb 12 13:44:22 volumio volumio[14290]: ,establishing connection Feb 12 13:44:22 volumio volumio[14290]: error: updateQueue error: null Feb 12 13:44:22 volumio volumio[14290]: error: updateQueue error: null Feb 12 13:44:22 volumio volumio[14290]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 13:44:22 volumio sudo[14742]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 13:44:22 volumio sudo[14742]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:22 volumio sudo[14742]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:23 volumio volumio[14290]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 13:44:23 volumio sudo[14745]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 13:44:23 volumio sudo[14745]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:23 volumio sudo[14745]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:23 volumio volumio[14290]: info: Completed starting Core Plugins Feb 12 13:44:23 volumio volumio[14290]: info: ------------------------------------------- Feb 12 13:44:23 volumio volumio[14290]: info: ----- MyVolumio plugins startup ---- Feb 12 13:44:23 volumio volumio[14290]: info: ------------------------------------------- Feb 12 13:44:23 volumio volumio[14290]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 12 13:44:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 12 13:44:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:23 volumio go-librespot[14747]: go-librespot daemon starting... Feb 12 13:44:23 volumio go-librespot[14748]: time="2026-02-12T13:44:23-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:44:23 volumio go-librespot[14748]: time="2026-02-12T13:44:23-06:00" level=debug msg="app state loaded" Feb 12 13:44:23 volumio go-librespot[14748]: time="2026-02-12T13:44:23-06:00" level=debug msg="stored credentials not found" Feb 12 13:44:23 volumio go-librespot[14748]: time="2026-02-12T13:44:23-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:44:23 volumio go-librespot[14748]: time="2026-02-12T13:44:23-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 12 13:44:23 volumio go-librespot[14748]: time="2026-02-12T13:44:23-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 12 13:44:23 volumio go-librespot[14748]: time="2026-02-12T13:44:23-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 12 13:44:23 volumio go-librespot[14748]: time="2026-02-12T13:44:23-06:00" level=info msg="zeroconf server listening on port 33447" Feb 12 13:44:23 volumio go-librespot[14748]: time="2026-02-12T13:44:23-06:00" level=debug msg="obtained new client token: AAAtcv9oGX0bJ4w/+4/0CqvyP+EmgFkTHgxqtXYMFMAfbU5Xrht5zwb0sOIWHja2F6BELjbpyM39dlBEezsqXczM+UJQdPjjT0X33GZkCTKJ2XLRKFT5tHilL51OZFf/2mR3VUZGuOb5FA4isNVYRHWh2szhcPvONfFIISsL1DeTiEKkSInKg8inP3A58+IS5HZwgLXp1t/02ZGkEoFYRnjjY05o4jEEVlhr0wXMR9zQYvywxQxm5IGm4Q==" Feb 12 13:44:24 volumio go-librespot[14748]: time="2026-02-12T13:44:24-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 13:44:24 volumio go-librespot[14748]: time="2026-02-12T13:44:24-06:00" level=debug msg="completed keyexchange" Feb 12 13:44:24 volumio go-librespot[14748]: time="2026-02-12T13:44:24-06:00" level=debug msg="completed challenge" Feb 12 13:44:24 volumio go-librespot[14748]: time="2026-02-12T13:44:24-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 13:44:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:44:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:44:25 volumio volumio[14290]: info: Initializing connection to go-librespot Websocket Feb 12 13:44:25 volumio volumio[14290]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 13:44:25 volumio sudo[14756]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 12 13:44:25 volumio sudo[14756]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:25 volumio sudo[14758]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 12 13:44:25 volumio sudo[14758]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:25 volumio sudo[14761]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 12 13:44:25 volumio sudo[14761]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:25 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 12 13:44:25 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 12 13:44:25 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 12 13:44:25 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 12 13:44:25 volumio sudo[14756]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:25 volumio mpd_monitor.sh[14764]: MPD Monitor Service: Starting MPD Monitor Service Feb 12 13:44:25 volumio sudo[14758]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:25 volumio sudo[14761]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:25 volumio volumio[14290]: info: Successfully started MPD Monitor Feb 12 13:44:25 volumio volumio[14290]: info: Successfully started MPD Monitor Feb 12 13:44:25 volumio volumio[14290]: info: Successfully started MPD Monitor Feb 12 13:44:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 12 13:44:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:27 volumio go-librespot[14769]: go-librespot daemon starting... Feb 12 13:44:27 volumio go-librespot[14770]: time="2026-02-12T13:44:27-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:44:27 volumio go-librespot[14770]: time="2026-02-12T13:44:27-06:00" level=debug msg="app state loaded" Feb 12 13:44:27 volumio go-librespot[14770]: time="2026-02-12T13:44:27-06:00" level=debug msg="stored credentials not found" Feb 12 13:44:27 volumio go-librespot[14770]: time="2026-02-12T13:44:27-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:44:27 volumio go-librespot[14770]: time="2026-02-12T13:44:27-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 12 13:44:27 volumio go-librespot[14770]: time="2026-02-12T13:44:27-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 12 13:44:27 volumio go-librespot[14770]: time="2026-02-12T13:44:27-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 12 13:44:27 volumio go-librespot[14770]: time="2026-02-12T13:44:27-06:00" level=info msg="zeroconf server listening on port 43549" Feb 12 13:44:27 volumio go-librespot[14770]: time="2026-02-12T13:44:27-06:00" level=debug msg="obtained new client token: AADPSXSydwwyFi9g9p4iJA8SK+q/CGEOOEx2xem9Ialhucjz3LV3KNZgfKM8ViVh6n7sr0fweJZNPp3qAdRM++04PwnDsNp67ut8kkWJT8kDDRUt5ufsp4lILa7nDmq7JZz0r4tU6u2UziuyoY24LpMHAf5LRo38ZTnqTPj3rfF8nGPtALMYyF1BzWkQ1HUo5+WglHMkQhksobQ4p5kkp0ovASwuYpwTqe/7fbvEAlxpEgODqR/Uq5ZRTg==" Feb 12 13:44:27 volumio go-librespot[14770]: time="2026-02-12T13:44:27-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 13:44:27 volumio go-librespot[14770]: time="2026-02-12T13:44:27-06:00" level=debug msg="completed keyexchange" Feb 12 13:44:27 volumio go-librespot[14770]: time="2026-02-12T13:44:27-06:00" level=debug msg="completed challenge" Feb 12 13:44:27 volumio go-librespot[14770]: time="2026-02-12T13:44: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 12 13:44:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:44:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:44:28 volumio volumio[14290]: info: Initializing connection to go-librespot Websocket Feb 12 13:44:28 volumio volumio[14290]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 13:44:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 12 13:44:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:31 volumio go-librespot[14792]: go-librespot daemon starting... Feb 12 13:44:31 volumio go-librespot[14793]: time="2026-02-12T13:44:31-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:44:31 volumio go-librespot[14793]: time="2026-02-12T13:44:31-06:00" level=debug msg="app state loaded" Feb 12 13:44:31 volumio go-librespot[14793]: time="2026-02-12T13:44:31-06:00" level=debug msg="stored credentials not found" Feb 12 13:44:31 volumio go-librespot[14793]: time="2026-02-12T13:44:31-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:44:31 volumio go-librespot[14793]: time="2026-02-12T13:44:31-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 12 13:44:31 volumio go-librespot[14793]: time="2026-02-12T13:44:31-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 12 13:44:31 volumio go-librespot[14793]: time="2026-02-12T13:44:31-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 12 13:44:31 volumio go-librespot[14793]: time="2026-02-12T13:44:31-06:00" level=info msg="zeroconf server listening on port 35569" Feb 12 13:44:31 volumio go-librespot[14793]: time="2026-02-12T13:44:31-06:00" level=debug msg="obtained new client token: AABxH9P7jmiVJ8aocNrHG4eywgiab0Vl1cF16YOBOq6oWu7J57RX4jqRFN2cXWo4mv24746tfTfBTW1Jq/Qec6ueiNMsiswcs1jB73PUPDKBaEEYSqcpR8GosLynb7LhTaddO/Ll2UH+0/teMfrSqG+J70Gdy2j6Tjk+phhbGpsKRXdyI29qwdt92NDxuyYUpSNq3T58ZzrQa/vfItZikSyt9YskVhuFpKKJwpT4F6u/7PA744Q0MVTCpw==" Feb 12 13:44:31 volumio volumio[14290]: info: Initializing connection to go-librespot Websocket Feb 12 13:44:31 volumio go-librespot[14793]: time="2026-02-12T13:44:31-06:00" level=debug msg="new websocket client" Feb 12 13:44:31 volumio volumio[14290]: info: Connection to go-librespot Websocket established Feb 12 13:44:31 volumio go-librespot[14793]: time="2026-02-12T13:44:31-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 13:44:31 volumio volumio[14290]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 12 13:44:31 volumio volumio[14290]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 12 13:44:31 volumio volumio[14290]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 12 13:44:31 volumio volumio[14290]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 12 13:44:31 volumio volumio[14290]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 12 13:44:31 volumio volumio[14290]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 12 13:44:31 volumio volumio[14290]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 12 13:44:31 volumio volumio[14290]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 12 13:44:31 volumio volumio[14290]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 12 13:44:31 volumio volumio[14290]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 12 13:44:31 volumio volumio[14290]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 12 13:44:31 volumio volumio[14290]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 12 13:44:31 volumio volumio[14290]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 12 13:44:31 volumio volumio[14290]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 12 13:44:31 volumio volumio[14290]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 12 13:44:31 volumio volumio[14290]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 12 13:44:31 volumio volumio[14290]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 12 13:44:31 volumio volumio[14290]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 12 13:44:31 volumio volumio[14290]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 12 13:44:31 volumio volumio[14290]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 12 13:44:31 volumio volumio[14290]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 12 13:44:31 volumio volumio[14290]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 12 13:44:31 volumio volumio[14290]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 12 13:44:31 volumio volumio[14290]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 12 13:44:31 volumio volumio[14290]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 12 13:44:31 volumio volumio[14290]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 12 13:44:31 volumio volumio[14290]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 12 13:44:31 volumio volumio[14290]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 12 13:44:31 volumio volumio[14290]: info: Adding plugin bluetooth to MyMusic Plugins Feb 12 13:44:31 volumio volumio[14290]: info: Adding plugin multiroom to MyMusic Plugins Feb 12 13:44:31 volumio volumio[14290]: info: Adding plugin metavolumio to MyMusic Plugins Feb 12 13:44:31 volumio volumio[14290]: info: Adding plugin cd_controller to MyMusic Plugins Feb 12 13:44:31 volumio volumio[14290]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 12 13:44:31 volumio volumio[14290]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 12 13:44:31 volumio volumio[14290]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 12 13:44:31 volumio volumio[14290]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 12 13:44:31 volumio go-librespot[14793]: time="2026-02-12T13:44:31-06:00" level=debug msg="completed keyexchange" Feb 12 13:44:31 volumio go-librespot[14793]: time="2026-02-12T13:44:31-06:00" level=debug msg="completed challenge" Feb 12 13:44:31 volumio go-librespot[14793]: time="2026-02-12T13:44: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 12 13:44:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:44:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:44:32 volumio volumio[14290]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 12 13:44:32 volumio volumio[14290]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 12 13:44:32 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:44:32 volumio volumio[14290]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:44:32 volumio volumio[14290]: info: Starting MyVolumio Remote Streaming Endpoints Feb 12 13:44:32 volumio volumio[14290]: info: MyVolumio login type: Token Feb 12 13:44:32 volumio volumio[14290]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 12 13:44:32 volumio volumio[14290]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 12 13:44:33 volumio volumio[14290]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 12 13:44:33 volumio volumio[14290]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 12 13:44:33 volumio volumio[14290]: info: Streaming services startup Feb 12 13:44:33 volumio volumio[14290]: info: Starting Streaming Daemon Feb 12 13:44:33 volumio sudo[14801]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 12 13:44:33 volumio sudo[14801]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:33 volumio volumio[14290]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 12 13:44:33 volumio sudo[14801]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:33 volumio volumio[14290]: info: Connection to go-librespot Websocket closed Feb 12 13:44:33 volumio volumio[14290]: error: Cannot start Volumio Streaming Daemon Feb 12 13:44:33 volumio volumio[14290]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 12 13:44:33 volumio volumio[14290]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 12 13:44:33 volumio volumio[14290]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 12 13:44:34 volumio volumio[14290]: info: Getting Spotify volume Feb 12 13:44:34 volumio volumio[14290]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 13:44:34 volumio volumio[14290]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 13:44:34 volumio volumio[14290]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 12 13:44:34 volumio volumio[14290]: errno: -111, Feb 12 13:44:34 volumio volumio[14290]: code: 'ECONNREFUSED', Feb 12 13:44:34 volumio volumio[14290]: syscall: 'connect', Feb 12 13:44:34 volumio volumio[14290]: address: '127.0.0.1', Feb 12 13:44:34 volumio volumio[14290]: port: 9879, Feb 12 13:44:34 volumio volumio[14290]: response: undefined Feb 12 13:44:34 volumio volumio[14290]: } Feb 12 13:44:34 volumio volumio[14290]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 13:44:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 12 13:44:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:34 volumio go-librespot[14822]: go-librespot daemon starting... Feb 12 13:44:34 volumio go-librespot[14823]: time="2026-02-12T13:44:34-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:44:34 volumio go-librespot[14823]: time="2026-02-12T13:44:34-06:00" level=debug msg="app state loaded" Feb 12 13:44:34 volumio go-librespot[14823]: time="2026-02-12T13:44:34-06:00" level=debug msg="stored credentials not found" Feb 12 13:44:34 volumio go-librespot[14823]: time="2026-02-12T13:44:34-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:44:35 volumio go-librespot[14823]: time="2026-02-12T13:44:35-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:44:35 volumio go-librespot[14823]: time="2026-02-12T13:44:35-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 12 13:44:35 volumio go-librespot[14823]: time="2026-02-12T13:44:35-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 12 13:44:35 volumio go-librespot[14823]: time="2026-02-12T13:44:35-06:00" level=info msg="zeroconf server listening on port 37355" Feb 12 13:44:35 volumio go-librespot[14823]: time="2026-02-12T13:44:35-06:00" level=debug msg="obtained new client token: AACAc+QRt/iYHqlqBmkx5bnsrmZstQjW1qrYTModNkyR5V8On9M2zAfM9VeJGW/eBIBUKQc6OUulJZ4yLjY07j/jBfTHjx83llmeG9jcYmPvm8GtaCZeR2tuPCiT8UiDkl+IO2uudZMTMw97mXdCTEtCn68bfWfTulhBIXCck6qSDmxqQVrxY43OVOjd6nP0QnAXpg9B0M8AsEl9sC4rEGwSFfW6RBYp5a96+EmOZyHccuA23rLC4Z0=" Feb 12 13:44:35 volumio sudo[14832]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 13:43' Feb 12 13:44:35 volumio sudo[14832]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:35 volumio go-librespot[14823]: time="2026-02-12T13:44:35-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 13:44:35 volumio go-librespot[14823]: time="2026-02-12T13:44:35-06:00" level=debug msg="completed keyexchange" Feb 12 13:44:35 volumio go-librespot[14823]: time="2026-02-12T13:44:35-06:00" level=debug msg="completed challenge" Feb 12 13:44:35 volumio go-librespot[14823]: time="2026-02-12T13:44: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 12 13:44:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:44:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. 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"