Apr 14 05:39:00 volumio volumio-remote-updater[945]: [2026-04-14 05:39:00] [connect] Successful connection Apr 14 05:39:00 volumio volumio-remote-updater[945]: [2026-04-14 05:39:00] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1776141540 101 Apr 14 05:39:00 volumio volumio[3686]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 2 Apr 14 05:39:00 volumio go-librespot[3906]: time="2026-04-14T05:39:00+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:00 volumio go-librespot[3906]: time="2026-04-14T05:39:00+01:00" level=debug msg="completed challenge" Apr 14 05:39:00 volumio go-librespot[3906]: time="2026-04-14T05:39:00+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:00 volumio sudo[3725]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:00 volumio go-librespot[3906]: time="2026-04-14T05:39:00+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 14 05:39:00 volumio go-librespot[3906]: time="2026-04-14T05:39:00+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:00 volumio go-librespot[3906]: time="2026-04-14T05:39:00+01:00" level=debug msg="completed challenge" Apr 14 05:39:00 volumio go-librespot[3906]: time="2026-04-14T05:39:00+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:01 volumio go-librespot[3906]: time="2026-04-14T05:39:01+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 14 05:39:01 volumio go-librespot[3906]: time="2026-04-14T05:39:01+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:01 volumio go-librespot[3906]: time="2026-04-14T05:39:01+01:00" level=debug msg="completed challenge" Apr 14 05:39:01 volumio go-librespot[3906]: time="2026-04-14T05:39:01+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:01 volumio volumio[3686]: info: go-librespot daemon successfully initialized Apr 14 05:39:01 volumio go-librespot[3906]: time="2026-04-14T05:39:01+01:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Apr 14 05:39:02 volumio go-librespot[3906]: time="2026-04-14T05:39:02+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:02 volumio go-librespot[3906]: time="2026-04-14T05:39:02+01:00" level=debug msg="completed challenge" Apr 14 05:39:02 volumio go-librespot[3906]: time="2026-04-14T05:39:02+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:02 volumio go-librespot[3906]: time="2026-04-14T05:39:02+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Apr 14 05:39:02 volumio go-librespot[3906]: time="2026-04-14T05:39:02+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:02 volumio go-librespot[3906]: time="2026-04-14T05:39:02+01:00" level=debug msg="completed challenge" Apr 14 05:39:02 volumio go-librespot[3906]: time="2026-04-14T05:39:02+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:03 volumio go-librespot[3906]: time="2026-04-14T05:39:03+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 14 05:39:03 volumio go-librespot[3906]: time="2026-04-14T05:39:03+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:03 volumio go-librespot[3906]: time="2026-04-14T05:39:03+01:00" level=debug msg="completed challenge" Apr 14 05:39:04 volumio go-librespot[3906]: time="2026-04-14T05:39:04+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:04 volumio go-librespot[3906]: time="2026-04-14T05:39:04+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 05:39:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 05:39:04 volumio volumio[3686]: info: Initializing connection to go-librespot Websocket Apr 14 05:39:04 volumio volumio[3686]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 14 05:39:06 volumio sudo[3961]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 05:39:06 volumio sudo[3961]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:06 volumio sudo[3963]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 05:39:06 volumio sudo[3961]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:06 volumio sudo[3963]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:06 volumio sudo[3963]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:06 volumio sudo[3966]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 14 05:39:06 volumio sudo[3966]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:06 volumio sudo[3966]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:06 volumio volumio[3686]: info: Upmpdcli Daemon Started Apr 14 05:39:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Apr 14 05:39:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 05:39:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 05:39:07 volumio go-librespot[3969]: go-librespot daemon starting... Apr 14 05:39:07 volumio go-librespot[3970]: time="2026-04-14T05:39:07+01:00" level=info msg="running go-librespot 0.6.2" Apr 14 05:39:07 volumio go-librespot[3970]: time="2026-04-14T05:39:07+01:00" level=debug msg="app state loaded" Apr 14 05:39:07 volumio go-librespot[3970]: time="2026-04-14T05:39:07+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 05:39:07 volumio go-librespot[3970]: time="2026-04-14T05:39:07+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 14 05:39:07 volumio go-librespot[3970]: time="2026-04-14T05:39:07+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 14 05:39:07 volumio go-librespot[3970]: time="2026-04-14T05:39:07+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 14 05:39:07 volumio go-librespot[3970]: time="2026-04-14T05:39:07+01:00" level=info msg="zeroconf server listening on port 34617" Apr 14 05:39:07 volumio go-librespot[3970]: time="2026-04-14T05:39:07+01:00" level=debug msg="obtained new client token: AAClJWpw86kbNZDNRa05U9ybQnHM4toOvs71+9gzgHf/j2aSTsGsy24ZL1yZjKj1SJj4vIVw44IC5cKLgPkK2O8GhFpBgRWRNDmWoiHr14a0yj9zfFePCKSr5DcDX+4tFPI1/7FfJ1Z2g/1qDcWV5ogwlBAP+Dal9KZRokjgIlFIY7kVomZVHA+NAtFu22O25i9V3UrWxKeztBHp/l+j2+yGtIGZWcI5XdEILKwQwnPGqGcRhFUa0CnCcA==" Apr 14 05:39:07 volumio go-librespot[3970]: time="2026-04-14T05:39:07+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 14 05:39:07 volumio go-librespot[3970]: time="2026-04-14T05:39:07+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:07 volumio go-librespot[3970]: time="2026-04-14T05:39:07+01:00" level=debug msg="completed challenge" Apr 14 05:39:07 volumio go-librespot[3970]: time="2026-04-14T05:39:07+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 14 05:39:07 volumio volumio[3686]: info: Adding plugin bluetooth to MyMusic Plugins Apr 14 05:39:07 volumio volumio[3686]: info: Adding plugin multiroom to MyMusic Plugins Apr 14 05:39:07 volumio volumio[3686]: info: Adding plugin metavolumio to MyMusic Plugins Apr 14 05:39:07 volumio volumio[3686]: info: Adding plugin cd_controller to MyMusic Plugins Apr 14 05:39:07 volumio volumio[3686]: info: Adding plugin qobuzconnect to MyMusic Plugins Apr 14 05:39:07 volumio volumio[3686]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 14 05:39:07 volumio volumio[3686]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 14 05:39:07 volumio volumio[3686]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:07 volumio volumio[3686]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:07 volumio volumio[3686]: info: Starting MyVolumio Remote Streaming Endpoints Apr 14 05:39:07 volumio volumio[3686]: info: MyVolumio login type: Token Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 14 05:39:07 volumio volumio[3686]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 14 05:39:08 volumio go-librespot[3970]: time="2026-04-14T05:39:08+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 14 05:39:08 volumio go-librespot[3970]: time="2026-04-14T05:39:08+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:08 volumio go-librespot[3970]: time="2026-04-14T05:39:08+01:00" level=debug msg="completed challenge" Apr 14 05:39:08 volumio go-librespot[3970]: time="2026-04-14T05:39:08+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:08 volumio volumio[3686]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 14 05:39:08 volumio volumio[3686]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 14 05:39:08 volumio volumio[3686]: info: Streaming services startup Apr 14 05:39:08 volumio volumio[3686]: info: Starting Streaming Daemon Apr 14 05:39:08 volumio sudo[3980]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 14 05:39:08 volumio sudo[3980]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:08 volumio volumio[3686]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 14 05:39:08 volumio sudo[3980]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:08 volumio volumio[3686]: info: Initializing connection to go-librespot Websocket Apr 14 05:39:08 volumio volumio[3686]: error: Cannot start Volumio Streaming Daemon Apr 14 05:39:08 volumio volumio[3686]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 14 05:39:08 volumio volumio[3686]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 14 05:39:08 volumio go-librespot[3970]: time="2026-04-14T05:39:08+01:00" level=debug msg="new websocket client" Apr 14 05:39:08 volumio volumio[3686]: info: Connection to go-librespot Websocket established Apr 14 05:39:08 volumio go-librespot[3970]: time="2026-04-14T05:39:08+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 14 05:39:08 volumio go-librespot[3970]: time="2026-04-14T05:39:08+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:08 volumio go-librespot[3970]: time="2026-04-14T05:39:08+01:00" level=debug msg="completed challenge" Apr 14 05:39:08 volumio go-librespot[3970]: time="2026-04-14T05:39:08+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:08 volumio volumio[3686]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 14 05:39:08 volumio volumio[3686]: info: MyVolumio token set successfully Apr 14 05:39:08 volumio volumio[3686]: info: MYVOLUMIO: Adding device Apr 14 05:39:08 volumio volumio[3686]: info: MYVOLUMIO: Evaluating Server Apr 14 05:39:09 volumio volumio[3686]: info: MyVolumio status changed Apr 14 05:39:09 volumio volumio[3686]: info: Streaming services startup Apr 14 05:39:09 volumio volumio[3686]: info: Starting Streaming Daemon Apr 14 05:39:09 volumio volumio[3686]: info: Removing browser output: myVolumio user plan is not superstar Apr 14 05:39:09 volumio volumio[3686]: info: Removing audio output: Apr 14 05:39:09 volumio volumio[3686]: info: Stoppping Tunnel 1 Apr 14 05:39:09 volumio sudo[4008]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 14 05:39:09 volumio sudo[4008]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:09 volumio sudo[4010]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Apr 14 05:39:09 volumio sudo[4010]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:09 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. Apr 14 05:39:09 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. Apr 14 05:39:09 volumio sudo[4008]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:09 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. Apr 14 05:39:09 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. Apr 14 05:39:09 volumio volumio[3686]: error: Cannot start Volumio Streaming Daemon Apr 14 05:39:09 volumio volumio[3686]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 14 05:39:09 volumio volumio[3686]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 14 05:39:09 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. Apr 14 05:39:09 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. Apr 14 05:39:09 volumio sudo[4010]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:09 volumio volumio[3686]: info: Remote SSH Stopped Apr 14 05:39:09 volumio go-librespot[3970]: time="2026-04-14T05:39:09+01:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Apr 14 05:39:09 volumio go-librespot[3970]: time="2026-04-14T05:39:09+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:09 volumio go-librespot[3970]: time="2026-04-14T05:39:09+01:00" level=debug msg="completed challenge" Apr 14 05:39:09 volumio volumio[3686]: info: Setting Geolocation for MyVolumio to eu3 Apr 14 05:39:09 volumio volumio[3686]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:09 volumio volumio[3686]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:09 volumio volumio[3686]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:09 volumio go-librespot[3970]: time="2026-04-14T05:39:09+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:09 volumio volumio[3686]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Apr 14 05:39:10 volumio go-librespot[3970]: time="2026-04-14T05:39:10+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Apr 14 05:39:10 volumio go-librespot[3970]: time="2026-04-14T05:39:10+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:10 volumio go-librespot[3970]: time="2026-04-14T05:39:10+01:00" level=debug msg="completed challenge" Apr 14 05:39:10 volumio go-librespot[3970]: time="2026-04-14T05:39:10+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:10 volumio volumio[3686]: info: Updating MyVolumio device info Apr 14 05:39:10 volumio volumio[3686]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:10 volumio volumio[3686]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:10 volumio volumio[3686]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:10 volumio volumio[3686]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Apr 14 05:39:10 volumio go-librespot[3970]: time="2026-04-14T05:39:10+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 14 05:39:11 volumio go-librespot[3970]: time="2026-04-14T05:39:11+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:11 volumio go-librespot[3970]: time="2026-04-14T05:39:11+01:00" level=debug msg="completed challenge" Apr 14 05:39:11 volumio volumio[3686]: info: Getting Spotify volume Apr 14 05:39:11 volumio volumio[3686]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Apr 14 05:39:11 volumio volumio[3686]: info: CoreCommandRouter::volumioGetState Apr 14 05:39:11 volumio volumio[3686]: info: CorePlayQueue::getTrack 0 Apr 14 05:39:11 volumio volumio[3686]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Apr 14 05:39:11 volumio volumio[3686]: SPOTIFY: SPOTIFY VOLUME undefined Apr 14 05:39:11 volumio volumio[3686]: SPOTIFY: VOLUMIO VOLUME 0 Apr 14 05:39:11 volumio volumio[3686]: info: Aligning Spotify Volume to Volumio Volume Apr 14 05:39:11 volumio volumio[3686]: info: CoreCommandRouter::volumioGetState Apr 14 05:39:11 volumio volumio[3686]: info: CorePlayQueue::getTrack 0 Apr 14 05:39:11 volumio volumio[3686]: info: Setting Spotify Volume from Volumio: 0 Apr 14 05:39:11 volumio go-librespot[3970]: time="2026-04-14T05:39:11+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:11 volumio go-librespot[3970]: time="2026-04-14T05:39:11+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 05:39:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 05:39:11 volumio volumio[3686]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 05:39:11 volumio volumio[3686]: Error: socket hang up Apr 14 05:39:11 volumio volumio[3686]: at connResetException (node:internal/errors:720:14) Apr 14 05:39:11 volumio volumio[3686]: at Socket.socketOnEnd (node:_http_client:519:23) Apr 14 05:39:11 volumio volumio[3686]: at Socket.emit (node:events:526:35) Apr 14 05:39:11 volumio volumio[3686]: at endReadableNT (node:internal/streams/readable:1376:12) Apr 14 05:39:11 volumio volumio[3686]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Apr 14 05:39:11 volumio volumio[3686]: code: 'ECONNRESET', Apr 14 05:39:11 volumio volumio[3686]: response: undefined Apr 14 05:39:11 volumio volumio[3686]: } Apr 14 05:39:11 volumio volumio[3686]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 05:39:11 volumio sudo[4027]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-14 05:38' Apr 14 05:39:11 volumio sudo[4027]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:11 volumio sudo[4027]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:11 volumio volumio-remote-updater[945]: [2026-04-14 05:39:11] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Apr 14 05:39:11 volumio volumio-remote-updater[945]: [2026-04-14 05:39:11] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Apr 14 05:39:11 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Apr 14 05:39:11 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Apr 14 05:39:11 volumio systemd[1]: volumio.service: Consumed 8.970s CPU time. Apr 14 05:39:11 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 14 05:39:11 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 14 05:39:11 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 119776. Apr 14 05:39:11 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 14 05:39:11 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Apr 14 05:39:11 volumio systemd[1]: volumio.service: Consumed 8.970s CPU time. Apr 14 05:39:11 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Apr 14 05:39:11 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 14 05:39:12 volumio volumio[4039]: info: ------------------------------------------- Apr 14 05:39:12 volumio volumio[4039]: info: ----- Volumio3 ---- Apr 14 05:39:12 volumio volumio[4039]: info: ------------------------------------------- Apr 14 05:39:12 volumio volumio[4039]: info: ----- System startup ---- Apr 14 05:39:12 volumio volumio[4039]: info: ------------------------------------------- Apr 14 05:39:12 volumio volumio[4039]: info: MYVOLUMIO Environment detected Apr 14 05:39:12 volumio volumio[4039]: info: Plugin folders cleanup Apr 14 05:39:12 volumio volumio[4039]: info: Scanning into folder /volumio/app/plugins/ Apr 14 05:39:12 volumio volumio[4039]: info: Scanning category audio_interface Apr 14 05:39:12 volumio volumio[4039]: info: Scanning category miscellanea Apr 14 05:39:12 volumio volumio[4039]: info: Scanning category music_service Apr 14 05:39:12 volumio volumio[4039]: info: Scanning category plugins.json Apr 14 05:39:12 volumio volumio[4039]: info: Scanning category system_controller Apr 14 05:39:12 volumio volumio[4039]: info: Scanning category user_interface Apr 14 05:39:12 volumio volumio[4039]: info: Scanning into folder /data/plugins/ Apr 14 05:39:12 volumio volumio[4039]: info: Scanning category music_service Apr 14 05:39:12 volumio volumio[4039]: info: Plugin folders cleanup completed Apr 14 05:39:12 volumio volumio[4039]: info: ------------------------------------------- Apr 14 05:39:12 volumio volumio[4039]: info: ----- Core plugins startup ---- Apr 14 05:39:12 volumio volumio[4039]: info: ------------------------------------------- Apr 14 05:39:12 volumio volumio[4039]: info: Loading plugins from folder /volumio/app/plugins/ Apr 14 05:39:12 volumio volumio[4039]: info: Adding plugin upnp to MyMusic Plugins Apr 14 05:39:12 volumio volumio[4039]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 14 05:39:12 volumio volumio[4039]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 14 05:39:12 volumio volumio[4039]: info: Loading plugins from folder /data/plugins/ Apr 14 05:39:12 volumio volumio[4039]: info: Adding plugin rtlsdr_radio to MyMusic Plugins Apr 14 05:39:12 volumio volumio[4039]: info: Loading plugin "system"... Apr 14 05:39:12 volumio volumio[4039]: info: Loading plugin "appearance"... Apr 14 05:39:13 volumio volumio[4039]: info: Loading plugin "network"... Apr 14 05:39:13 volumio volumio[4039]: info: Refreshing Cached IP Addresses Apr 14 05:39:13 volumio sudo[4067]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 05:39:13 volumio sudo[4067]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:13 volumio sudo[4069]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 05:39:13 volumio sudo[4069]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:13 volumio sudo[4067]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:13 volumio volumio[4039]: info: Loading plugin "services"... Apr 14 05:39:13 volumio volumio[4039]: info: Loading plugin "alsa_controller"... Apr 14 05:39:13 volumio sudo[4069]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:13 volumio sudo[4077]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 14 05:39:13 volumio sudo[4077]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:13 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 05:39:13 volumio volumio[4039]: info: Loading plugin "wizard"... Apr 14 05:39:13 volumio volumio[4039]: info: Loading plugin "networkfs"... Apr 14 05:39:13 volumio volumio[4039]: info: Starting Udev Watcher for removable devices Apr 14 05:39:13 volumio volumio[4039]: info: Mounting Device 0ACB-A1DE Apr 14 05:39:13 volumio sudo[4106]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/0ACB-A1DE -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Apr 14 05:39:13 volumio sudo[4106]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:13 volumio sudo[4106]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:13 volumio volumio[4039]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Apr 14 05:39:13 volumio volumio[4039]: dmesg(1) may have more information after failed mount system call. Apr 14 05:39:13 volumio volumio[4039]: error: Failed to mount 0ACB-A1DE: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/0ACB-A1DE" -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Apr 14 05:39:13 volumio volumio[4039]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Apr 14 05:39:13 volumio volumio[4039]: dmesg(1) may have more information after failed mount system call. Apr 14 05:39:13 volumio volumio[4039]: info: Ignoring mount for partition: boot Apr 14 05:39:13 volumio volumio[4039]: info: Ignoring mount for partition: volumio Apr 14 05:39:13 volumio volumio[4039]: info: Ignoring mount for partition: volumio_data Apr 14 05:39:13 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 05:39:13 volumio volumio[4039]: info: Loading plugin "volumio_command_line_client"... Apr 14 05:39:13 volumio volumio[4039]: info: Loading plugin "upnp"... Apr 14 05:39:13 volumio volumio[4039]: info: [1776141553134] Starting Upmpd Daemon Apr 14 05:39:13 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 05:39:13 volumio volumio[4039]: info: Loading plugin "my_music"... Apr 14 05:39:13 volumio volumio[4039]: info: Loading plugin "mpd"... Apr 14 05:39:13 volumio volumio[4039]: info: Loading plugin "upnp_browser"... Apr 14 05:39:13 volumio volumio[4039]: info: Starting UPNP Browser Apr 14 05:39:13 volumio volumio[4039]: info: Loading plugin "alarm-clock"... Apr 14 05:39:13 volumio volumio[4039]: info: Loading plugin "airplay_emulation"... Apr 14 05:39:13 volumio volumio[4039]: info: Starting Shairport Sync Apr 14 05:39:13 volumio volumio[4039]: info: Loading plugin "last_100"... Apr 14 05:39:13 volumio volumio[4039]: info: Loading plugin "webradio"... Apr 14 05:39:13 volumio volumio[4039]: info: Loading plugin "i2s_dacs"... Apr 14 05:39:13 volumio volumio[4039]: info: Loading plugin "volumiodiscovery"... Apr 14 05:39:13 volumio volumio[4039]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 14 05:39:13 volumio volumio[4039]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 05:39:13 volumio volumio[4039]: *** WARNING *** For more information see Apr 14 05:39:13 volumio volumio[4039]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 14 05:39:13 volumio volumio[4039]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 05:39:13 volumio volumio[4039]: *** WARNING *** For more information see Apr 14 05:39:13 volumio node[4039]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 14 05:39:13 volumio node[4039]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 05:39:13 volumio node[4039]: *** WARNING *** For more information see Apr 14 05:39:13 volumio node[4039]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 14 05:39:13 volumio node[4039]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 05:39:13 volumio node[4039]: *** WARNING *** For more information see Apr 14 05:39:13 volumio volumio[4039]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 14 05:39:13 volumio volumio[4039]: info: Discovery: Started advertising with name: Volumio Apr 14 05:39:13 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 05:39:13 volumio volumio[4039]: info: Loading plugin "spop"... Apr 14 05:39:14 volumio volumio[4039]: info: Loading plugin "ytmusic"... Apr 14 05:39:14 volumio volumio[4039]: info: Loading plugin "outputs"... Apr 14 05:39:14 volumio volumio[4039]: info: Loading plugin "albumart"... Apr 14 05:39:14 volumio volumio[4039]: info: Plugin example_plugin is not enabled Apr 14 05:39:14 volumio volumio[4039]: info: Loading plugin "inputs"... Apr 14 05:39:14 volumio volumio[4039]: info: Loading plugin "updater_comm"... Apr 14 05:39:14 volumio volumio[4039]: info: Plugin mpdemulation is not enabled Apr 14 05:39:14 volumio volumio[4039]: info: Loading plugin "rest_api"... Apr 14 05:39:14 volumio volumio[4039]: info: Loading plugin "websocket"... Apr 14 05:39:14 volumio volumio[4039]: info: Starting Socket.io Server version 1.7.4 Apr 14 05:39:14 volumio volumio[4039]: info: Loading plugin "podcast"... Apr 14 05:39:14 volumio volumio[4039]: info: ControllerPodcast::constructor Apr 14 05:39:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Apr 14 05:39:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 05:39:14 volumio volumio[4039]: info: Loading plugin "rtlsdr_radio"... Apr 14 05:39:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 05:39:14 volumio go-librespot[4120]: go-librespot daemon starting... Apr 14 05:39:14 volumio go-librespot[4121]: time="2026-04-14T05:39:14+01:00" level=info msg="running go-librespot 0.6.2" Apr 14 05:39:14 volumio go-librespot[4121]: time="2026-04-14T05:39:14+01:00" level=debug msg="app state loaded" Apr 14 05:39:14 volumio volumio[4110]: Forking 3 albumart workers Apr 14 05:39:14 volumio go-librespot[4121]: time="2026-04-14T05:39:14+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 05:39:14 volumio volumio[4039]: info: Loading i18n strings for locale en Apr 14 05:39:14 volumio volumio[4039]: Updating browse sources language Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::initPlayerControls Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 05:39:14 volumio volumio[4039]: Express server listening on port 3000 Apr 14 05:39:14 volumio volumio[4039]: [Metrics] WebUI: 2s 357.77ms Apr 14 05:39:14 volumio volumio[4039]: info: CoreStateMachine::resetVolumioState Apr 14 05:39:14 volumio volumio[4039]: info: CoreStateMachine::getcurrentVolume Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::volumioRetrievevolume Apr 14 05:39:14 volumio volumio[4039]: info: Volumio Network Manager: Network status updated: 2 Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:14 volumio volumio[4039]: info: Reloading queue from file Apr 14 05:39:14 volumio volumio[4039]: info: VolumeController:: Volume=36 Mute =true Apr 14 05:39:14 volumio volumio[4039]: info: CoreStateMachine::pushState Apr 14 05:39:14 volumio volumio[4039]: info: CorePlayQueue::getTrack 0 Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::volumioPushState Apr 14 05:39:14 volumio volumio[4039]: info: CoreStateMachine::updateTrackBlock Apr 14 05:39:14 volumio volumio[4039]: info: CorePlayQueue::getTrackBlock Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::volumioRetrievevolume Apr 14 05:39:14 volumio volumio[4039]: info: CoreStateMachine::setRepeat null single undefined Apr 14 05:39:14 volumio volumio[4039]: info: CoreStateMachine::pushState Apr 14 05:39:14 volumio volumio[4039]: info: CorePlayQueue::getTrack 0 Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::volumioPushState Apr 14 05:39:14 volumio volumio[4039]: info: CoreStateMachine::setRandom true Apr 14 05:39:14 volumio volumio[4039]: info: CoreStateMachine::pushState Apr 14 05:39:14 volumio volumio[4039]: info: CorePlayQueue::getTrack 0 Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::volumioPushState Apr 14 05:39:14 volumio volumio[4039]: info: Setting Device type: Raspberry PI Apr 14 05:39:14 volumio volumio[4039]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Apr 14 05:39:14 volumio volumio[4039]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04170 Apr 14 05:39:14 volumio volumio[4039]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Apr 14 05:39:14 volumio volumio[4039]: info: Completed loading Core Plugins Apr 14 05:39:14 volumio volumio[4039]: info: Preparing to generate the ALSA configuration file Apr 14 05:39:14 volumio volumio[4039]: info: Asound.conf file unchanged, so no further update is needed Apr 14 05:39:14 volumio volumio[4039]: info: Output device has changed, restarting MPD Apr 14 05:39:14 volumio volumio[4039]: info: Output device has changed, restarting Shairport Sync Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:14 volumio sudo[4177]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 14 05:39:14 volumio sudo[4175]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 14 05:39:14 volumio sudo[4177]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:14 volumio go-librespot[4121]: time="2026-04-14T05:39:14+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 14 05:39:14 volumio go-librespot[4121]: time="2026-04-14T05:39:14+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 14 05:39:14 volumio go-librespot[4121]: time="2026-04-14T05:39:14+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 14 05:39:14 volumio sudo[4175]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:14 volumio sudo[4175]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:14 volumio volumio[4039]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 05:39:14 volumio volumio[4039]: info: ___________ START PLUGINS ___________ Apr 14 05:39:14 volumio go-librespot[4121]: time="2026-04-14T05:39:14+01:00" level=info msg="zeroconf server listening on port 43957" Apr 14 05:39:14 volumio volumio[4039]: info: ControllerMpd::onStart: Initializing MPD Apr 14 05:39:14 volumio volumio[4039]: info: Creating MPD Configuration file Apr 14 05:39:14 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 05:39:14 volumio volumio[4039]: info: [1776141554899] CoreMusicLibrary::Adding element Media Servers Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 05:39:14 volumio sudo[4187]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 14 05:39:14 volumio sudo[4187]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:14 volumio sudo[4187]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:14 volumio volumio[4039]: info: UPNP Browser: Client initialized successfully Apr 14 05:39:14 volumio sudo[4189]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 14 05:39:14 volumio sudo[4189]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:14 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 14 05:39:14 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 14 05:39:14 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 14 05:39:14 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 14 05:39:14 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:14 volumio volumio[4129]: Starting albumart workers Apr 14 05:39:14 volumio volumio[4127]: Starting albumart workers Apr 14 05:39:14 volumio volumio[4128]: Starting albumart workers Apr 14 05:39:14 volumio volumio[4039]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:14 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 14 05:39:14 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 14 05:39:14 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 14 05:39:14 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 14 05:39:14 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 14 05:39:14 volumio volumio[4039]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 05:39:14 volumio volumio[4039]: info: [1776141554967] CoreMusicLibrary::Adding element Last_100 Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 05:39:14 volumio volumio[4039]: info: [1776141554968] CoreMusicLibrary::Adding element Webradio Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 05:39:14 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 14 05:39:14 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 14 05:39:14 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 14 05:39:14 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 05:39:14 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 14 05:39:14 volumio volumio[4039]: info: Initializing BBC Radios Apr 14 05:39:15 volumio sudo[4203]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 14 05:39:15 volumio sudo[4203]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 14 05:39:15 volumio sudo[4203]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:15 volumio volumio[4039]: info: Creating Spotify config file Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:15 volumio go-librespot[4121]: time="2026-04-14T05:39:15+01:00" level=debug msg="obtained new client token: AABoED+g3uygAoeLJrFkpXyaNAW8JCugJcdu7ZPTnopG/1EH3L9uRm6VHqKrke0+OdZTlljZ+AMnkD+raGWeqhnyerbUy2H/SRu1vluDLLKt6MQsdrEWG8Tgsi/6tqUYdNOS7ZsQ5+9bvjCcpDHCC9D/QuacLRx20z4GoiZwIvBmJdvipYwJWnP9LdwZ9+jcof9PiAR7mLVbj+aomeEAVVruxLH2+OEIj4bjqWJdm2hAjqUu48oiJds=" Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 05:39:15 volumio volumio[4039]: info: [1776141555229] CoreMusicLibrary::Adding element YouTube Music Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 05:39:15 volumio volumio[4039]: Cannot find translation for source YouTube Music Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 05:39:15 volumio volumio[4039]: info: [1776141555234] CoreMusicLibrary::Adding element Podcast Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 05:39:15 volumio volumio[4039]: Cannot find translation for source YouTube Music Apr 14 05:39:15 volumio volumio[4039]: Cannot find translation for source Podcast Apr 14 05:39:15 volumio volumio[4039]: info: [RTL-SDR Radio] Starting plugin Apr 14 05:39:15 volumio volumio[4039]: info: [RTL-SDR Radio] Loaded i18n strings for language: en Apr 14 05:39:15 volumio volumio[4039]: info: Volumio Calling Home Apr 14 05:39:15 volumio volumio[4039]: info: [RTL-SDR Radio] snd-aloop already loaded Apr 14 05:39:15 volumio volumio[4039]: info: [RTL-SDR Radio] No stations database found, creating v2 Apr 14 05:39:15 volumio volumio[4039]: info: [RTL-SDR Radio] Database loaded at: 2026-04-14T04:39:15.278Z Apr 14 05:39:15 volumio volumio[4039]: info: [RTL-SDR Radio] Loading blocklist from: /data/plugins/music_service/rtlsdr_radio/blocklist.json Apr 14 05:39:15 volumio volumio[4039]: info: [RTL-SDR Radio] Got 21 phrases from file Apr 14 05:39:15 volumio volumio[4039]: info: [RTL-SDR Radio] Updated metadata blocklist Apr 14 05:39:15 volumio volumio[4039]: info: [RTL-SDR Radio] Metadata module now has 21 phrases Apr 14 05:39:15 volumio volumio[4039]: info: [RTL-SDR Radio] Management server started on port 3456 Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 05:39:15 volumio volumio[4039]: info: [1776141555311] CoreMusicLibrary::Adding element FM/DAB Radio Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 05:39:15 volumio volumio[4039]: Cannot find translation for source YouTube Music Apr 14 05:39:15 volumio volumio[4039]: Cannot find translation for source Podcast Apr 14 05:39:15 volumio volumio[4039]: Cannot find translation for source FM/DAB Radio Apr 14 05:39:15 volumio volumio[4039]: info: [RTL-SDR Radio] Plugin started successfully Apr 14 05:39:15 volumio volumio[4039]: info: VolumeController:: Volume=36 Mute =true Apr 14 05:39:15 volumio volumio[4039]: info: CoreStateMachine::pushState Apr 14 05:39:15 volumio volumio[4039]: info: CorePlayQueue::getTrack 0 Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::volumioPushState Apr 14 05:39:15 volumio volumio[4039]: info: Discovery: adding 072f109f-54a2-4344-b8c4-538b45da7e51 Apr 14 05:39:15 volumio volumio[4039]: info: Discovery: Found device Volumio Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::volumioGetState Apr 14 05:39:15 volumio volumio[4039]: info: CorePlayQueue::getTrack 0 Apr 14 05:39:15 volumio volumio[4039]: info: MPD Permissions set Apr 14 05:39:15 volumio volumio[4039]: info: MPD Permissions set Apr 14 05:39:15 volumio volumio[4039]: info: Spotify config file written Apr 14 05:39:15 volumio sudo[4246]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 14 05:39:15 volumio sudo[4246]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:15 volumio volumio[4039]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:15 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Apr 14 05:39:15 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Apr 14 05:39:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:15 volumio volumio[4039]: info: No need to fix Spotify hosts Apr 14 05:39:15 volumio volumio[4039]: info: Discovery: this is already registered, 072f109f-54a2-4344-b8c4-538b45da7e51 Apr 14 05:39:15 volumio volumio[4039]: info: Discovery: Found device Volumio Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::volumioGetState Apr 14 05:39:15 volumio volumio[4039]: info: CorePlayQueue::getTrack 0 Apr 14 05:39:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 05:39:15 volumio go-librespot[4250]: go-librespot daemon starting... Apr 14 05:39:15 volumio sudo[4246]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:15 volumio go-librespot[4259]: time="2026-04-14T05:39:15+01:00" level=info msg="running go-librespot 0.6.2" Apr 14 05:39:15 volumio go-librespot[4259]: time="2026-04-14T05:39:15+01:00" level=debug msg="app state loaded" Apr 14 05:39:15 volumio go-librespot[4259]: time="2026-04-14T05:39:15+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 05:39:15 volumio volumio[4039]: info: Starting Shairport Sync Apr 14 05:39:15 volumio volumio[4039]: info: Starting Shairport Sync Apr 14 05:39:15 volumio volumio[4039]: info: Starting Shairport Sync Apr 14 05:39:15 volumio sudo[4266]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 05:39:15 volumio sudo[4266]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:15 volumio sudo[4268]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 05:39:15 volumio sudo[4268]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:15 volumio sudo[4270]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 05:39:15 volumio sudo[4270]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:15 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 14 05:39:15 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 14 05:39:15 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 05:39:15 volumio systemd[1]: shairport-sync.service: Consumed 1.551s CPU time. Apr 14 05:39:15 volumio volumio[4039]: info: CoreCommandRouter::volumioGetState Apr 14 05:39:15 volumio volumio[4039]: info: CorePlayQueue::getTrack 0 Apr 14 05:39:15 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 05:39:15 volumio sudo[4266]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:15 volumio volumio[4039]: info: Shairport-Sync Started Apr 14 05:39:15 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 14 05:39:15 volumio sudo[4270]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:15 volumio volumio[4039]: Error adding Membership: Error: addMembership EINVAL Apr 14 05:39:15 volumio volumio[4039]: info: Shairport-Sync Started Apr 14 05:39:15 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 14 05:39:15 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 05:39:15 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 05:39:15 volumio sudo[4268]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:15 volumio volumio[4039]: info: Shairport-Sync Started Apr 14 05:39:15 volumio volumio[4039]: info: Volumio called home Apr 14 05:39:15 volumio mpd[4213]: 2026-04-14T05:39:15 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 14 05:39:15 volumio systemd[1]: Started mpd.service - Music Player Daemon. Apr 14 05:39:15 volumio sudo[4189]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:15 volumio sudo[4177]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:15 volumio volumio[4039]: info: Completed starting Core Plugins Apr 14 05:39:15 volumio volumio[4039]: info: ------------------------------------------- Apr 14 05:39:15 volumio volumio[4039]: info: ----- MyVolumio plugins startup ---- Apr 14 05:39:15 volumio volumio[4039]: info: ------------------------------------------- Apr 14 05:39:15 volumio volumio[4039]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 14 05:39:15 volumio volumio[4039]: error: MPD error: The expression evaluated to a falsy value: Apr 14 05:39:15 volumio volumio[4039]: assert.ok(self.idling) Apr 14 05:39:15 volumio volumio[4039]: error: The expression evaluated to a falsy value: Apr 14 05:39:15 volumio volumio[4039]: assert.ok(self.idling) Apr 14 05:39:15 volumio volumio[4039]: info: MPD running with PID4213 Apr 14 05:39:15 volumio volumio[4039]: ,establishing connection Apr 14 05:39:15 volumio volumio[4039]: error: updateQueue error: null Apr 14 05:39:15 volumio volumio[4039]: error: updateQueue error: null Apr 14 05:39:15 volumio go-librespot[4259]: time="2026-04-14T05:39:15+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 14 05:39:15 volumio go-librespot[4259]: time="2026-04-14T05:39:15+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 14 05:39:15 volumio go-librespot[4259]: time="2026-04-14T05:39:15+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 14 05:39:15 volumio go-librespot[4259]: time="2026-04-14T05:39:15+01:00" level=info msg="zeroconf server listening on port 35657" Apr 14 05:39:15 volumio volumio[4039]: info: An error occurred while refreshing Spotify Token Error: Bad Request Apr 14 05:39:16 volumio go-librespot[4259]: time="2026-04-14T05:39:16+01:00" level=debug msg="obtained new client token: AADzqFyJo8l8AB4lUXVbcuxWcfkg7K+uZFikn1rlWzby/Ufo0EZoAiJa0GWQZpBadblMN891sxbiwbFlw66hH1ufhiy9G2h5287qz2+KlNJ0zavjdV3cF+5aHAf/MGIC4SncYxPDBQdwKnTeca6CofBQ0kyrRy9roootRUkexycou4oJ3zRpm90E4SZ/gN9/Rhcy3PVgdGACs0THT7rzNF4hu/1OAVpqL5IND4QsWj1Ja7oWd+f7GMs=" Apr 14 05:39:16 volumio go-librespot[4259]: time="2026-04-14T05:39:16+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 14 05:39:16 volumio go-librespot[4259]: time="2026-04-14T05:39:16+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:16 volumio go-librespot[4259]: time="2026-04-14T05:39:16+01:00" level=debug msg="completed challenge" Apr 14 05:39:16 volumio volumio-remote-updater[945]: [2026-04-14 05:39:16] [connect] Successful connection Apr 14 05:39:16 volumio volumio-remote-updater[945]: [2026-04-14 05:39:16] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1776141556 101 Apr 14 05:39:16 volumio volumio[4039]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 2 Apr 14 05:39:16 volumio go-librespot[4259]: time="2026-04-14T05:39:16+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:16 volumio sudo[4077]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:17 volumio go-librespot[4259]: time="2026-04-14T05:39:17+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 14 05:39:17 volumio go-librespot[4259]: time="2026-04-14T05:39:17+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:17 volumio go-librespot[4259]: time="2026-04-14T05:39:17+01:00" level=debug msg="completed challenge" Apr 14 05:39:17 volumio go-librespot[4259]: time="2026-04-14T05:39:17+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:17 volumio go-librespot[4259]: time="2026-04-14T05:39:17+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 14 05:39:17 volumio go-librespot[4259]: time="2026-04-14T05:39:17+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:17 volumio go-librespot[4259]: time="2026-04-14T05:39:17+01:00" level=debug msg="completed challenge" Apr 14 05:39:17 volumio go-librespot[4259]: time="2026-04-14T05:39:17+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:18 volumio volumio[4039]: info: go-librespot daemon successfully initialized Apr 14 05:39:18 volumio go-librespot[4259]: time="2026-04-14T05:39:18+01:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Apr 14 05:39:18 volumio go-librespot[4259]: time="2026-04-14T05:39:18+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:18 volumio go-librespot[4259]: time="2026-04-14T05:39:18+01:00" level=debug msg="completed challenge" Apr 14 05:39:18 volumio go-librespot[4259]: time="2026-04-14T05:39:18+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:19 volumio go-librespot[4259]: time="2026-04-14T05:39:19+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Apr 14 05:39:19 volumio go-librespot[4259]: time="2026-04-14T05:39:19+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:19 volumio go-librespot[4259]: time="2026-04-14T05:39:19+01:00" level=debug msg="completed challenge" Apr 14 05:39:19 volumio go-librespot[4259]: time="2026-04-14T05:39:19+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:20 volumio go-librespot[4259]: time="2026-04-14T05:39:20+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 14 05:39:20 volumio go-librespot[4259]: time="2026-04-14T05:39:20+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:20 volumio go-librespot[4259]: time="2026-04-14T05:39:20+01:00" level=debug msg="completed challenge" Apr 14 05:39:20 volumio go-librespot[4259]: time="2026-04-14T05:39:20+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:20 volumio go-librespot[4259]: time="2026-04-14T05:39:20+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 05:39:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 05:39:21 volumio volumio[4039]: info: Initializing connection to go-librespot Websocket Apr 14 05:39:21 volumio volumio[4039]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 14 05:39:23 volumio sudo[4313]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 05:39:23 volumio sudo[4313]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:23 volumio sudo[4313]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:23 volumio sudo[4315]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 05:39:23 volumio sudo[4315]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:23 volumio sudo[4315]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:23 volumio sudo[4318]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 14 05:39:23 volumio sudo[4318]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:23 volumio sudo[4318]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:23 volumio volumio[4039]: info: Upmpdcli Daemon Started Apr 14 05:39:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Apr 14 05:39:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 05:39:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 05:39:23 volumio go-librespot[4321]: go-librespot daemon starting... Apr 14 05:39:23 volumio go-librespot[4322]: time="2026-04-14T05:39:23+01:00" level=info msg="running go-librespot 0.6.2" Apr 14 05:39:23 volumio go-librespot[4322]: time="2026-04-14T05:39:23+01:00" level=debug msg="app state loaded" Apr 14 05:39:23 volumio go-librespot[4322]: time="2026-04-14T05:39:23+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 05:39:24 volumio go-librespot[4322]: time="2026-04-14T05:39:24+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 14 05:39:24 volumio go-librespot[4322]: time="2026-04-14T05:39:24+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 14 05:39:24 volumio go-librespot[4322]: time="2026-04-14T05:39:24+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 14 05:39:24 volumio go-librespot[4322]: time="2026-04-14T05:39:24+01:00" level=info msg="zeroconf server listening on port 44281" Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 14 05:39:24 volumio volumio[4039]: info: Adding plugin bluetooth to MyMusic Plugins Apr 14 05:39:24 volumio volumio[4039]: info: Adding plugin multiroom to MyMusic Plugins Apr 14 05:39:24 volumio volumio[4039]: info: Adding plugin metavolumio to MyMusic Plugins Apr 14 05:39:24 volumio volumio[4039]: info: Adding plugin cd_controller to MyMusic Plugins Apr 14 05:39:24 volumio volumio[4039]: info: Adding plugin qobuzconnect to MyMusic Plugins Apr 14 05:39:24 volumio volumio[4039]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 14 05:39:24 volumio volumio[4039]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 14 05:39:24 volumio go-librespot[4322]: time="2026-04-14T05:39:24+01:00" level=debug msg="obtained new client token: AACBHPbNSRaVSrAl4mqmfb5pveDR0ZQEjgfyo+vuGJ/6C3WtKGXjKGMngU0aAiVcfLgCLvCv3sypIpfR3rYiIdLBfLOgfkznpH7oljT2DBt/BxO1zYwOLENNzkqHr6w3JlCpm6pIAtABoLdnz4speVSo7Du3042eOsC2p8Yiegd7vJSjV2ghUDx4dBUGdscBqSN7xk4V2Zcfx5QWxufWZ5zD1oGytFvCEfZo+htiu/hhmUqlvIa0D6w=" Apr 14 05:39:24 volumio go-librespot[4322]: time="2026-04-14T05:39:24+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 14 05:39:24 volumio go-librespot[4322]: time="2026-04-14T05:39:24+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:24 volumio go-librespot[4322]: time="2026-04-14T05:39:24+01:00" level=debug msg="completed challenge" Apr 14 05:39:24 volumio go-librespot[4322]: time="2026-04-14T05:39:24+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 14 05:39:24 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:24 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:24 volumio volumio[4039]: info: Starting MyVolumio Remote Streaming Endpoints Apr 14 05:39:24 volumio volumio[4039]: info: MyVolumio login type: Token Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 14 05:39:24 volumio volumio[4039]: info: Streaming services startup Apr 14 05:39:24 volumio volumio[4039]: info: Starting Streaming Daemon Apr 14 05:39:24 volumio sudo[4332]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 14 05:39:24 volumio sudo[4332]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:24 volumio volumio[4039]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 14 05:39:24 volumio sudo[4332]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:24 volumio volumio[4039]: info: Initializing connection to go-librespot Websocket Apr 14 05:39:24 volumio volumio[4039]: error: Cannot start Volumio Streaming Daemon Apr 14 05:39:24 volumio volumio[4039]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 14 05:39:24 volumio volumio[4039]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 14 05:39:24 volumio go-librespot[4322]: time="2026-04-14T05:39:24+01:00" level=debug msg="new websocket client" Apr 14 05:39:24 volumio volumio[4039]: info: Connection to go-librespot Websocket established Apr 14 05:39:24 volumio go-librespot[4322]: time="2026-04-14T05:39:24+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 14 05:39:24 volumio go-librespot[4322]: time="2026-04-14T05:39:24+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:24 volumio go-librespot[4322]: time="2026-04-14T05:39:24+01:00" level=debug msg="completed challenge" Apr 14 05:39:24 volumio go-librespot[4322]: time="2026-04-14T05:39:24+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:25 volumio volumio[4039]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 14 05:39:25 volumio go-librespot[4322]: time="2026-04-14T05:39:25+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 14 05:39:25 volumio go-librespot[4322]: time="2026-04-14T05:39:25+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:25 volumio go-librespot[4322]: time="2026-04-14T05:39:25+01:00" level=debug msg="completed challenge" Apr 14 05:39:25 volumio go-librespot[4322]: time="2026-04-14T05:39:25+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:25 volumio volumio[4039]: info: MyVolumio token set successfully Apr 14 05:39:25 volumio volumio[4039]: info: MYVOLUMIO: Adding device Apr 14 05:39:25 volumio volumio[4039]: info: MYVOLUMIO: Evaluating Server Apr 14 05:39:25 volumio volumio[4039]: info: MyVolumio status changed Apr 14 05:39:25 volumio volumio[4039]: info: Streaming services startup Apr 14 05:39:25 volumio volumio[4039]: info: Starting Streaming Daemon Apr 14 05:39:25 volumio volumio[4039]: info: Removing browser output: myVolumio user plan is not superstar Apr 14 05:39:25 volumio volumio[4039]: info: Removing audio output: Apr 14 05:39:25 volumio volumio[4039]: info: Stoppping Tunnel 1 Apr 14 05:39:25 volumio sudo[4359]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 14 05:39:25 volumio sudo[4359]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:25 volumio sudo[4361]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Apr 14 05:39:25 volumio sudo[4361]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:25 volumio sudo[4359]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:25 volumio volumio[4039]: error: Cannot start Volumio Streaming Daemon Apr 14 05:39:25 volumio volumio[4039]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 14 05:39:25 volumio volumio[4039]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 14 05:39:25 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. Apr 14 05:39:25 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. Apr 14 05:39:25 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. Apr 14 05:39:25 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. Apr 14 05:39:25 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. Apr 14 05:39:25 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. Apr 14 05:39:25 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. Apr 14 05:39:25 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. Apr 14 05:39:25 volumio sudo[4361]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:25 volumio volumio[4039]: info: Remote SSH Stopped Apr 14 05:39:26 volumio volumio[4039]: info: Setting Geolocation for MyVolumio to eu3 Apr 14 05:39:26 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:26 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:26 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:26 volumio go-librespot[4322]: time="2026-04-14T05:39:26+01:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Apr 14 05:39:26 volumio go-librespot[4322]: time="2026-04-14T05:39:26+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:26 volumio go-librespot[4322]: time="2026-04-14T05:39:26+01:00" level=debug msg="completed challenge" Apr 14 05:39:26 volumio go-librespot[4322]: time="2026-04-14T05:39:26+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:26 volumio volumio[4039]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Apr 14 05:39:26 volumio go-librespot[4322]: time="2026-04-14T05:39:26+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Apr 14 05:39:26 volumio go-librespot[4322]: time="2026-04-14T05:39:26+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:26 volumio go-librespot[4322]: time="2026-04-14T05:39:26+01:00" level=debug msg="completed challenge" Apr 14 05:39:26 volumio go-librespot[4322]: time="2026-04-14T05:39:26+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:27 volumio volumio[4039]: info: Updating MyVolumio device info Apr 14 05:39:27 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:27 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:27 volumio volumio[4039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:27 volumio volumio[4039]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Apr 14 05:39:27 volumio go-librespot[4322]: time="2026-04-14T05:39:27+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 14 05:39:27 volumio volumio[4039]: info: Getting Spotify volume Apr 14 05:39:27 volumio volumio[4039]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Apr 14 05:39:27 volumio volumio[4039]: info: CoreCommandRouter::volumioGetState Apr 14 05:39:27 volumio volumio[4039]: info: CorePlayQueue::getTrack 0 Apr 14 05:39:27 volumio volumio[4039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Apr 14 05:39:27 volumio volumio[4039]: SPOTIFY: SPOTIFY VOLUME undefined Apr 14 05:39:27 volumio volumio[4039]: SPOTIFY: VOLUMIO VOLUME 0 Apr 14 05:39:27 volumio volumio[4039]: info: Aligning Spotify Volume to Volumio Volume Apr 14 05:39:27 volumio volumio[4039]: info: CoreCommandRouter::volumioGetState Apr 14 05:39:27 volumio volumio[4039]: info: CorePlayQueue::getTrack 0 Apr 14 05:39:27 volumio volumio[4039]: info: Setting Spotify Volume from Volumio: 0 Apr 14 05:39:27 volumio go-librespot[4322]: time="2026-04-14T05:39:27+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:27 volumio go-librespot[4322]: time="2026-04-14T05:39:27+01:00" level=debug msg="completed challenge" Apr 14 05:39:28 volumio go-librespot[4322]: time="2026-04-14T05:39:28+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:28 volumio go-librespot[4322]: time="2026-04-14T05:39:28+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 05:39:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 05:39:28 volumio volumio[4039]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 05:39:28 volumio volumio[4039]: Error: socket hang up Apr 14 05:39:28 volumio volumio[4039]: at connResetException (node:internal/errors:720:14) Apr 14 05:39:28 volumio volumio[4039]: at Socket.socketOnEnd (node:_http_client:519:23) Apr 14 05:39:28 volumio volumio[4039]: at Socket.emit (node:events:526:35) Apr 14 05:39:28 volumio volumio[4039]: at endReadableNT (node:internal/streams/readable:1376:12) Apr 14 05:39:28 volumio volumio[4039]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Apr 14 05:39:28 volumio volumio[4039]: code: 'ECONNRESET', Apr 14 05:39:28 volumio volumio[4039]: response: undefined Apr 14 05:39:28 volumio volumio[4039]: } Apr 14 05:39:28 volumio volumio[4039]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 05:39:28 volumio sudo[4379]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-14 05:38' Apr 14 05:39:28 volumio sudo[4379]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:28 volumio sudo[4379]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:28 volumio volumio-remote-updater[945]: [2026-04-14 05:39:28] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Apr 14 05:39:28 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Apr 14 05:39:28 volumio volumio-remote-updater[945]: [2026-04-14 05:39:28] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Apr 14 05:39:28 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Apr 14 05:39:28 volumio systemd[1]: volumio.service: Consumed 8.993s CPU time. Apr 14 05:39:28 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 14 05:39:28 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 14 05:39:28 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 119777. Apr 14 05:39:28 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 14 05:39:28 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Apr 14 05:39:28 volumio systemd[1]: volumio.service: Consumed 8.993s CPU time. Apr 14 05:39:28 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Apr 14 05:39:28 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 14 05:39:29 volumio volumio[4391]: info: ------------------------------------------- Apr 14 05:39:29 volumio volumio[4391]: info: ----- Volumio3 ---- Apr 14 05:39:29 volumio volumio[4391]: info: ------------------------------------------- Apr 14 05:39:29 volumio volumio[4391]: info: ----- System startup ---- Apr 14 05:39:29 volumio volumio[4391]: info: ------------------------------------------- Apr 14 05:39:29 volumio volumio[4391]: info: MYVOLUMIO Environment detected Apr 14 05:39:29 volumio volumio[4391]: info: Plugin folders cleanup Apr 14 05:39:29 volumio volumio[4391]: info: Scanning into folder /volumio/app/plugins/ Apr 14 05:39:29 volumio volumio[4391]: info: Scanning category audio_interface Apr 14 05:39:29 volumio volumio[4391]: info: Scanning category miscellanea Apr 14 05:39:29 volumio volumio[4391]: info: Scanning category music_service Apr 14 05:39:29 volumio volumio[4391]: info: Scanning category plugins.json Apr 14 05:39:29 volumio volumio[4391]: info: Scanning category system_controller Apr 14 05:39:29 volumio volumio[4391]: info: Scanning category user_interface Apr 14 05:39:29 volumio volumio[4391]: info: Scanning into folder /data/plugins/ Apr 14 05:39:29 volumio volumio[4391]: info: Scanning category music_service Apr 14 05:39:29 volumio volumio[4391]: info: Plugin folders cleanup completed Apr 14 05:39:29 volumio volumio[4391]: info: ------------------------------------------- Apr 14 05:39:29 volumio volumio[4391]: info: ----- Core plugins startup ---- Apr 14 05:39:29 volumio volumio[4391]: info: ------------------------------------------- Apr 14 05:39:29 volumio volumio[4391]: info: Loading plugins from folder /volumio/app/plugins/ Apr 14 05:39:29 volumio volumio[4391]: info: Adding plugin upnp to MyMusic Plugins Apr 14 05:39:29 volumio volumio[4391]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 14 05:39:29 volumio volumio[4391]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 14 05:39:29 volumio volumio[4391]: info: Loading plugins from folder /data/plugins/ Apr 14 05:39:29 volumio volumio[4391]: info: Adding plugin rtlsdr_radio to MyMusic Plugins Apr 14 05:39:29 volumio volumio[4391]: info: Loading plugin "system"... Apr 14 05:39:29 volumio volumio[4391]: info: Loading plugin "appearance"... Apr 14 05:39:29 volumio volumio[4391]: info: Loading plugin "network"... Apr 14 05:39:29 volumio volumio[4391]: info: Refreshing Cached IP Addresses Apr 14 05:39:29 volumio sudo[4420]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 05:39:29 volumio sudo[4420]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:29 volumio sudo[4422]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 05:39:29 volumio sudo[4422]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:29 volumio sudo[4420]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:29 volumio sudo[4422]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:29 volumio volumio[4391]: info: Loading plugin "services"... Apr 14 05:39:29 volumio volumio[4391]: info: Loading plugin "alsa_controller"... Apr 14 05:39:29 volumio sudo[4429]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 14 05:39:29 volumio sudo[4429]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:29 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 05:39:29 volumio volumio[4391]: info: Loading plugin "wizard"... Apr 14 05:39:29 volumio volumio[4391]: info: Loading plugin "networkfs"... Apr 14 05:39:29 volumio volumio[4391]: info: Starting Udev Watcher for removable devices Apr 14 05:39:29 volumio volumio[4391]: info: Mounting Device 0ACB-A1DE Apr 14 05:39:29 volumio sudo[4459]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/0ACB-A1DE -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Apr 14 05:39:29 volumio sudo[4459]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:29 volumio sudo[4459]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:29 volumio volumio[4391]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Apr 14 05:39:29 volumio volumio[4391]: dmesg(1) may have more information after failed mount system call. Apr 14 05:39:29 volumio volumio[4391]: error: Failed to mount 0ACB-A1DE: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/0ACB-A1DE" -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Apr 14 05:39:29 volumio volumio[4391]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Apr 14 05:39:29 volumio volumio[4391]: dmesg(1) may have more information after failed mount system call. Apr 14 05:39:29 volumio volumio[4391]: info: Ignoring mount for partition: boot Apr 14 05:39:29 volumio volumio[4391]: info: Ignoring mount for partition: volumio Apr 14 05:39:29 volumio volumio[4391]: info: Ignoring mount for partition: volumio_data Apr 14 05:39:29 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 05:39:29 volumio volumio[4391]: info: Loading plugin "volumio_command_line_client"... Apr 14 05:39:29 volumio volumio[4391]: info: Loading plugin "upnp"... Apr 14 05:39:29 volumio volumio[4391]: info: [1776141569856] Starting Upmpd Daemon Apr 14 05:39:29 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 05:39:29 volumio volumio[4391]: info: Loading plugin "my_music"... Apr 14 05:39:29 volumio volumio[4391]: info: Loading plugin "mpd"... Apr 14 05:39:29 volumio volumio[4391]: info: Loading plugin "upnp_browser"... Apr 14 05:39:30 volumio volumio[4391]: info: Starting UPNP Browser Apr 14 05:39:30 volumio volumio[4391]: info: Loading plugin "alarm-clock"... Apr 14 05:39:30 volumio volumio[4391]: info: Loading plugin "airplay_emulation"... Apr 14 05:39:30 volumio volumio[4391]: info: Starting Shairport Sync Apr 14 05:39:30 volumio volumio[4391]: info: Loading plugin "last_100"... Apr 14 05:39:30 volumio volumio[4391]: info: Loading plugin "webradio"... Apr 14 05:39:30 volumio volumio[4391]: info: Loading plugin "i2s_dacs"... Apr 14 05:39:30 volumio volumio[4391]: info: Loading plugin "volumiodiscovery"... Apr 14 05:39:30 volumio volumio[4391]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 14 05:39:30 volumio volumio[4391]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 05:39:30 volumio volumio[4391]: *** WARNING *** For more information see Apr 14 05:39:30 volumio volumio[4391]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 14 05:39:30 volumio volumio[4391]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 05:39:30 volumio volumio[4391]: *** WARNING *** For more information see Apr 14 05:39:30 volumio node[4391]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 14 05:39:30 volumio node[4391]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 05:39:30 volumio node[4391]: *** WARNING *** For more information see Apr 14 05:39:30 volumio node[4391]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 14 05:39:30 volumio node[4391]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 05:39:30 volumio node[4391]: *** WARNING *** For more information see Apr 14 05:39:30 volumio volumio[4391]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 14 05:39:30 volumio volumio[4391]: info: Discovery: Started advertising with name: Volumio Apr 14 05:39:30 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 05:39:30 volumio volumio[4391]: info: Loading plugin "spop"... Apr 14 05:39:30 volumio volumio[4391]: info: Loading plugin "ytmusic"... Apr 14 05:39:30 volumio volumio[4391]: info: Loading plugin "outputs"... Apr 14 05:39:30 volumio volumio[4391]: info: Loading plugin "albumart"... Apr 14 05:39:30 volumio volumio[4391]: info: Plugin example_plugin is not enabled Apr 14 05:39:30 volumio volumio[4391]: info: Loading plugin "inputs"... Apr 14 05:39:31 volumio volumio[4391]: info: Loading plugin "updater_comm"... Apr 14 05:39:31 volumio volumio[4391]: info: Plugin mpdemulation is not enabled Apr 14 05:39:31 volumio volumio[4391]: info: Loading plugin "rest_api"... Apr 14 05:39:31 volumio volumio[4391]: info: Loading plugin "websocket"... Apr 14 05:39:31 volumio volumio[4391]: info: Starting Socket.io Server version 1.7.4 Apr 14 05:39:31 volumio volumio[4391]: info: Loading plugin "podcast"... Apr 14 05:39:31 volumio volumio[4391]: info: ControllerPodcast::constructor Apr 14 05:39:31 volumio volumio[4391]: info: Loading plugin "rtlsdr_radio"... Apr 14 05:39:31 volumio volumio[4463]: Forking 3 albumart workers Apr 14 05:39:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Apr 14 05:39:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 05:39:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 05:39:31 volumio go-librespot[4473]: go-librespot daemon starting... Apr 14 05:39:31 volumio go-librespot[4492]: time="2026-04-14T05:39:31+01:00" level=info msg="running go-librespot 0.6.2" Apr 14 05:39:31 volumio go-librespot[4492]: time="2026-04-14T05:39:31+01:00" level=debug msg="app state loaded" Apr 14 05:39:31 volumio go-librespot[4492]: time="2026-04-14T05:39:31+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 05:39:31 volumio volumio[4391]: info: Loading i18n strings for locale en Apr 14 05:39:31 volumio volumio[4391]: Updating browse sources language Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::initPlayerControls Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 05:39:31 volumio volumio[4391]: Express server listening on port 3000 Apr 14 05:39:31 volumio volumio[4391]: [Metrics] WebUI: 2s 277.70ms Apr 14 05:39:31 volumio volumio[4391]: info: CoreStateMachine::resetVolumioState Apr 14 05:39:31 volumio volumio[4391]: info: CoreStateMachine::getcurrentVolume Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::volumioRetrievevolume Apr 14 05:39:31 volumio volumio[4391]: info: Volumio Network Manager: Network status updated: 2 Apr 14 05:39:31 volumio volumio[4391]: info: VolumeController:: Volume=36 Mute =true Apr 14 05:39:31 volumio volumio[4391]: info: CoreStateMachine::pushState Apr 14 05:39:31 volumio volumio[4391]: info: CorePlayQueue::getTrack 0 Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::volumioPushState Apr 14 05:39:31 volumio volumio[4391]: info: CoreStateMachine::updateTrackBlock Apr 14 05:39:31 volumio volumio[4391]: info: CorePlayQueue::getTrackBlock Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::volumioRetrievevolume Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:31 volumio volumio[4391]: info: Reloading queue from file Apr 14 05:39:31 volumio volumio[4391]: info: CoreStateMachine::setRepeat null single undefined Apr 14 05:39:31 volumio volumio[4391]: info: CoreStateMachine::pushState Apr 14 05:39:31 volumio volumio[4391]: info: CorePlayQueue::getTrack 0 Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::volumioPushState Apr 14 05:39:31 volumio volumio[4391]: info: CoreStateMachine::setRandom true Apr 14 05:39:31 volumio volumio[4391]: info: CoreStateMachine::pushState Apr 14 05:39:31 volumio volumio[4391]: info: CorePlayQueue::getTrack 0 Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::volumioPushState Apr 14 05:39:31 volumio volumio[4391]: info: Setting Device type: Raspberry PI Apr 14 05:39:31 volumio volumio[4391]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Apr 14 05:39:31 volumio volumio[4391]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04170 Apr 14 05:39:31 volumio volumio[4391]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Apr 14 05:39:31 volumio volumio[4391]: info: Completed loading Core Plugins Apr 14 05:39:31 volumio volumio[4391]: info: Preparing to generate the ALSA configuration file Apr 14 05:39:31 volumio volumio[4391]: info: VolumeController:: Volume=36 Mute =true Apr 14 05:39:31 volumio volumio[4391]: info: CoreStateMachine::pushState Apr 14 05:39:31 volumio volumio[4391]: info: CorePlayQueue::getTrack 0 Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::volumioPushState Apr 14 05:39:31 volumio volumio[4391]: info: Asound.conf file unchanged, so no further update is needed Apr 14 05:39:31 volumio volumio[4391]: info: Output device has changed, restarting MPD Apr 14 05:39:31 volumio volumio[4391]: info: Output device has changed, restarting Shairport Sync Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:31 volumio sudo[4528]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 14 05:39:31 volumio sudo[4528]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:31 volumio sudo[4528]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:31 volumio sudo[4529]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 14 05:39:31 volumio sudo[4529]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:31 volumio volumio[4391]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 05:39:31 volumio volumio[4391]: info: ___________ START PLUGINS ___________ Apr 14 05:39:31 volumio volumio[4391]: info: ControllerMpd::onStart: Initializing MPD Apr 14 05:39:31 volumio volumio[4391]: info: Creating MPD Configuration file Apr 14 05:39:31 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 14 05:39:31 volumio sudo[4537]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 05:39:31 volumio volumio[4391]: info: [1776141571571] CoreMusicLibrary::Adding element Media Servers Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 05:39:31 volumio sudo[4537]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:31 volumio volumio[4391]: info: UPNP Browser: Client initialized successfully Apr 14 05:39:31 volumio sudo[4537]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:31 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 14 05:39:31 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 14 05:39:31 volumio go-librespot[4492]: time="2026-04-14T05:39:31+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 14 05:39:31 volumio go-librespot[4492]: time="2026-04-14T05:39:31+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Apr 14 05:39:31 volumio go-librespot[4492]: time="2026-04-14T05:39:31+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Apr 14 05:39:31 volumio sudo[4539]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 14 05:39:31 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 14 05:39:31 volumio sudo[4539]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:31 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 14 05:39:31 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:31 volumio go-librespot[4492]: time="2026-04-14T05:39:31+01:00" level=info msg="zeroconf server listening on port 40653" Apr 14 05:39:31 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 14 05:39:31 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 14 05:39:31 volumio volumio[4391]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:31 volumio volumio[4391]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 05:39:31 volumio volumio[4391]: info: [1776141571638] CoreMusicLibrary::Adding element Last_100 Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 05:39:31 volumio volumio[4391]: info: [1776141571640] CoreMusicLibrary::Adding element Webradio Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 05:39:31 volumio volumio[4391]: info: Initializing BBC Radios Apr 14 05:39:31 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 14 05:39:31 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 14 05:39:31 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 14 05:39:31 volumio volumio[4475]: Starting albumart workers Apr 14 05:39:31 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 14 05:39:31 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 14 05:39:31 volumio volumio[4474]: Starting albumart workers Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:31 volumio volumio[4391]: info: Creating Spotify config file Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:31 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 14 05:39:31 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 14 05:39:31 volumio volumio[4476]: Starting albumart workers Apr 14 05:39:31 volumio sudo[4568]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 14 05:39:31 volumio sudo[4568]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 14 05:39:31 volumio sudo[4568]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 05:39:31 volumio volumio[4391]: info: [1776141571827] CoreMusicLibrary::Adding element YouTube Music Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 05:39:31 volumio volumio[4391]: Cannot find translation for source YouTube Music Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 05:39:31 volumio volumio[4391]: info: [1776141571831] CoreMusicLibrary::Adding element Podcast Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 05:39:31 volumio volumio[4391]: Cannot find translation for source YouTube Music Apr 14 05:39:31 volumio volumio[4391]: Cannot find translation for source Podcast Apr 14 05:39:31 volumio volumio[4391]: info: [RTL-SDR Radio] Starting plugin Apr 14 05:39:31 volumio volumio[4391]: info: [RTL-SDR Radio] Loaded i18n strings for language: en Apr 14 05:39:31 volumio volumio[4391]: info: Volumio Calling Home Apr 14 05:39:31 volumio volumio[4391]: info: [RTL-SDR Radio] snd-aloop already loaded Apr 14 05:39:31 volumio volumio[4391]: info: [RTL-SDR Radio] No stations database found, creating v2 Apr 14 05:39:31 volumio volumio[4391]: info: [RTL-SDR Radio] Database loaded at: 2026-04-14T04:39:31.882Z Apr 14 05:39:31 volumio volumio[4391]: info: [RTL-SDR Radio] Loading blocklist from: /data/plugins/music_service/rtlsdr_radio/blocklist.json Apr 14 05:39:31 volumio volumio[4391]: info: [RTL-SDR Radio] Got 21 phrases from file Apr 14 05:39:31 volumio volumio[4391]: info: [RTL-SDR Radio] Updated metadata blocklist Apr 14 05:39:31 volumio volumio[4391]: info: [RTL-SDR Radio] Metadata module now has 21 phrases Apr 14 05:39:31 volumio volumio[4391]: info: [RTL-SDR Radio] Management server started on port 3456 Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 05:39:31 volumio volumio[4391]: info: [1776141571922] CoreMusicLibrary::Adding element FM/DAB Radio Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 05:39:31 volumio volumio[4391]: Cannot find translation for source YouTube Music Apr 14 05:39:31 volumio volumio[4391]: Cannot find translation for source Podcast Apr 14 05:39:31 volumio volumio[4391]: Cannot find translation for source FM/DAB Radio Apr 14 05:39:31 volumio volumio[4391]: info: [RTL-SDR Radio] Plugin started successfully Apr 14 05:39:31 volumio volumio[4391]: info: Discovery: adding 072f109f-54a2-4344-b8c4-538b45da7e51 Apr 14 05:39:31 volumio volumio[4391]: info: Discovery: Found device Volumio Apr 14 05:39:31 volumio volumio[4391]: info: CoreCommandRouter::volumioGetState Apr 14 05:39:31 volumio volumio[4391]: info: CorePlayQueue::getTrack 0 Apr 14 05:39:31 volumio volumio[4391]: info: MPD Permissions set Apr 14 05:39:31 volumio volumio[4391]: info: MPD Permissions set Apr 14 05:39:31 volumio volumio[4391]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Apr 14 05:39:31 volumio volumio[4391]: info: Spotify config file written Apr 14 05:39:32 volumio sudo[4585]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 14 05:39:32 volumio sudo[4585]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:32 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:32 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:32 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:32 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:32 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:32 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:32 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:32 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:32 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Apr 14 05:39:32 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Apr 14 05:39:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 05:39:32 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:32 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:32 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:32 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:32 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:32 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:32 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:32 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:32 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:32 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 05:39:32 volumio go-librespot[4605]: go-librespot daemon starting... Apr 14 05:39:32 volumio sudo[4585]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:32 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:32 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:32 volumio volumio[4391]: info: No need to fix Spotify hosts Apr 14 05:39:32 volumio volumio[4391]: info: Starting Shairport Sync Apr 14 05:39:32 volumio go-librespot[4610]: time="2026-04-14T05:39:32+01:00" level=info msg="running go-librespot 0.6.2" Apr 14 05:39:32 volumio go-librespot[4610]: time="2026-04-14T05:39:32+01:00" level=debug msg="app state loaded" Apr 14 05:39:32 volumio go-librespot[4610]: time="2026-04-14T05:39:32+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 05:39:32 volumio volumio[4391]: info: Starting Shairport Sync Apr 14 05:39:32 volumio volumio[4391]: info: Starting Shairport Sync Apr 14 05:39:32 volumio sudo[4618]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 05:39:32 volumio sudo[4618]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:32 volumio volumio[4391]: info: Volumio called home Apr 14 05:39:32 volumio sudo[4620]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 05:39:32 volumio sudo[4620]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:32 volumio sudo[4622]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 05:39:32 volumio sudo[4622]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:32 volumio volumio[4391]: info: Discovery: this is already registered, 072f109f-54a2-4344-b8c4-538b45da7e51 Apr 14 05:39:32 volumio volumio[4391]: info: Discovery: Found device Volumio Apr 14 05:39:32 volumio volumio[4391]: info: CoreCommandRouter::volumioGetState Apr 14 05:39:32 volumio volumio[4391]: info: CorePlayQueue::getTrack 0 Apr 14 05:39:32 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 14 05:39:32 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 14 05:39:32 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 05:39:32 volumio systemd[1]: shairport-sync.service: Consumed 1.558s CPU time. Apr 14 05:39:32 volumio volumio[4391]: info: CoreCommandRouter::volumioGetState Apr 14 05:39:32 volumio volumio[4391]: info: CorePlayQueue::getTrack 0 Apr 14 05:39:32 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 05:39:32 volumio sudo[4622]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:32 volumio sudo[4618]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:32 volumio sudo[4620]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:32 volumio volumio[4391]: info: Shairport-Sync Started Apr 14 05:39:32 volumio volumio[4391]: Error adding Membership: Error: addMembership EINVAL Apr 14 05:39:32 volumio volumio[4391]: info: Shairport-Sync Started Apr 14 05:39:32 volumio volumio[4391]: info: Shairport-Sync Started Apr 14 05:39:32 volumio volumio[4391]: info: An error occurred while refreshing Spotify Token Error: Bad Request Apr 14 05:39:32 volumio mpd[4570]: 2026-04-14T05:39:32 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 14 05:39:32 volumio systemd[1]: Started mpd.service - Music Player Daemon. Apr 14 05:39:32 volumio sudo[4529]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:32 volumio sudo[4539]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:32 volumio volumio[4391]: info: Completed starting Core Plugins Apr 14 05:39:32 volumio volumio[4391]: info: ------------------------------------------- Apr 14 05:39:32 volumio volumio[4391]: info: ----- MyVolumio plugins startup ---- Apr 14 05:39:32 volumio volumio[4391]: info: ------------------------------------------- Apr 14 05:39:32 volumio volumio[4391]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 14 05:39:32 volumio volumio[4391]: error: MPD error: The expression evaluated to a falsy value: Apr 14 05:39:32 volumio volumio[4391]: assert.ok(self.idling) Apr 14 05:39:32 volumio volumio[4391]: error: The expression evaluated to a falsy value: Apr 14 05:39:32 volumio volumio[4391]: assert.ok(self.idling) Apr 14 05:39:32 volumio volumio[4391]: error: updateQueue error: null Apr 14 05:39:32 volumio volumio[4391]: info: MPD running with PID4570 Apr 14 05:39:32 volumio volumio[4391]: ,establishing connection Apr 14 05:39:32 volumio volumio[4391]: error: updateQueue error: null Apr 14 05:39:32 volumio go-librespot[4610]: time="2026-04-14T05:39:32+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 14 05:39:32 volumio go-librespot[4610]: time="2026-04-14T05:39:32+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 14 05:39:32 volumio go-librespot[4610]: time="2026-04-14T05:39:32+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 14 05:39:32 volumio go-librespot[4610]: time="2026-04-14T05:39:32+01:00" level=info msg="zeroconf server listening on port 33163" Apr 14 05:39:32 volumio go-librespot[4610]: time="2026-04-14T05:39:32+01:00" level=debug msg="obtained new client token: AABBaNW0YRUnkadqQNT4pj/AjahwUsxpSFDfP1W06Q8a4bR5YUL5xhRijoS2aH7gZ3UzpX3zCSerb9x5lAw11dJ3WD3QIbJKVzhc2YA+3zWTsx3JgEOCnkURmpf7Dy9qslMACUgmBQOhawFNUcZ2ctWhqwuM7bP38pP0IILoW4uqqh5+S8GRNjrCR+UQANUAupPBdXBekUPz8/ugoA19Y+pw4N/I0zFboTi8Mpy6kMuHutrqEPX0jdXh4w==" Apr 14 05:39:33 volumio go-librespot[4610]: time="2026-04-14T05:39:33+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 14 05:39:33 volumio go-librespot[4610]: time="2026-04-14T05:39:33+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:33 volumio go-librespot[4610]: time="2026-04-14T05:39:33+01:00" level=debug msg="completed challenge" Apr 14 05:39:33 volumio go-librespot[4610]: time="2026-04-14T05:39:33+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:33 volumio volumio-remote-updater[945]: [2026-04-14 05:39:33] [connect] Successful connection Apr 14 05:39:33 volumio volumio-remote-updater[945]: [2026-04-14 05:39:33] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1776141573 101 Apr 14 05:39:33 volumio volumio[4391]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 2 Apr 14 05:39:33 volumio sudo[4429]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:33 volumio go-librespot[4610]: time="2026-04-14T05:39:33+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 14 05:39:33 volumio go-librespot[4610]: time="2026-04-14T05:39:33+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:33 volumio go-librespot[4610]: time="2026-04-14T05:39:33+01:00" level=debug msg="completed challenge" Apr 14 05:39:33 volumio go-librespot[4610]: time="2026-04-14T05:39:33+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:34 volumio go-librespot[4610]: time="2026-04-14T05:39:34+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 14 05:39:34 volumio go-librespot[4610]: time="2026-04-14T05:39:34+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:34 volumio go-librespot[4610]: time="2026-04-14T05:39:34+01:00" level=debug msg="completed challenge" Apr 14 05:39:34 volumio go-librespot[4610]: time="2026-04-14T05:39:34+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:35 volumio volumio[4391]: info: go-librespot daemon successfully initialized Apr 14 05:39:35 volumio go-librespot[4610]: time="2026-04-14T05:39:35+01:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Apr 14 05:39:35 volumio go-librespot[4610]: time="2026-04-14T05:39:35+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:35 volumio go-librespot[4610]: time="2026-04-14T05:39:35+01:00" level=debug msg="completed challenge" Apr 14 05:39:35 volumio go-librespot[4610]: time="2026-04-14T05:39:35+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:35 volumio go-librespot[4610]: time="2026-04-14T05:39:35+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.1.133:443: connect: connection refused" Apr 14 05:39:36 volumio go-librespot[4610]: time="2026-04-14T05:39:36+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 14 05:39:36 volumio go-librespot[4610]: time="2026-04-14T05:39:36+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:36 volumio go-librespot[4610]: time="2026-04-14T05:39:36+01:00" level=debug msg="completed challenge" Apr 14 05:39:36 volumio go-librespot[4610]: time="2026-04-14T05:39:36+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:37 volumio go-librespot[4610]: time="2026-04-14T05:39:37+01:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Apr 14 05:39:37 volumio go-librespot[4610]: time="2026-04-14T05:39:37+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 14 05:39:37 volumio go-librespot[4610]: time="2026-04-14T05:39:37+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:37 volumio go-librespot[4610]: time="2026-04-14T05:39:37+01:00" level=debug msg="completed challenge" Apr 14 05:39:37 volumio go-librespot[4610]: time="2026-04-14T05:39:37+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:37 volumio go-librespot[4610]: time="2026-04-14T05:39:37+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 05:39:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 05:39:38 volumio volumio[4391]: info: Initializing connection to go-librespot Websocket Apr 14 05:39:38 volumio volumio[4391]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 14 05:39:39 volumio sudo[4664]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 05:39:39 volumio sudo[4664]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:39 volumio sudo[4664]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:39 volumio sudo[4666]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 05:39:39 volumio sudo[4666]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:39 volumio sudo[4666]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:39 volumio sudo[4670]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 14 05:39:39 volumio sudo[4670]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:39 volumio sudo[4670]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:39 volumio volumio[4391]: info: Upmpdcli Daemon Started Apr 14 05:39:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Apr 14 05:39:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 05:39:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 05:39:40 volumio go-librespot[4672]: go-librespot daemon starting... Apr 14 05:39:40 volumio go-librespot[4673]: time="2026-04-14T05:39:40+01:00" level=info msg="running go-librespot 0.6.2" Apr 14 05:39:40 volumio go-librespot[4673]: time="2026-04-14T05:39:40+01:00" level=debug msg="app state loaded" Apr 14 05:39:40 volumio go-librespot[4673]: time="2026-04-14T05:39:40+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 05:39:40 volumio go-librespot[4673]: time="2026-04-14T05:39:40+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 14 05:39:40 volumio go-librespot[4673]: time="2026-04-14T05:39:40+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 14 05:39:40 volumio go-librespot[4673]: time="2026-04-14T05:39:40+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 14 05:39:40 volumio go-librespot[4673]: time="2026-04-14T05:39:40+01:00" level=info msg="zeroconf server listening on port 32875" Apr 14 05:39:40 volumio go-librespot[4673]: time="2026-04-14T05:39:40+01:00" level=debug msg="obtained new client token: AAAzNrtSk0QEk2DQJ3XRKaFZOF2/OW/pblHeTSGEaQrRLRb6gy9GkVuWhzNASg5UCajduCfVFXZb/OGr/Hc8PT1VVrabGeYkeCcO4K59jEgq/d3bWu+UB1QW8XiQa74FGhw87C8PTsjleRZ3ThQnTGDl9cow8+BsuwWXW6HE5CyycJYyoEhgDG+sEo0fccF/gu7wNgJPw84Qd2lZFFgrL1ZJ0xTcF7Fy3xiJEYuvuxpA/IrlbcYX1SFlZA==" Apr 14 05:39:40 volumio go-librespot[4673]: time="2026-04-14T05:39:40+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 14 05:39:40 volumio go-librespot[4673]: time="2026-04-14T05:39:40+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:40 volumio go-librespot[4673]: time="2026-04-14T05:39:40+01:00" level=debug msg="completed challenge" Apr 14 05:39:40 volumio go-librespot[4673]: time="2026-04-14T05:39:40+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:40 volumio volumio[4391]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 14 05:39:40 volumio volumio[4391]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 14 05:39:40 volumio volumio[4391]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 14 05:39:40 volumio volumio[4391]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 14 05:39:40 volumio volumio[4391]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 14 05:39:40 volumio volumio[4391]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 14 05:39:40 volumio volumio[4391]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 14 05:39:40 volumio volumio[4391]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 14 05:39:40 volumio volumio[4391]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 14 05:39:40 volumio volumio[4391]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 14 05:39:40 volumio volumio[4391]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Apr 14 05:39:40 volumio volumio[4391]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 14 05:39:40 volumio volumio[4391]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 14 05:39:40 volumio volumio[4391]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 14 05:39:40 volumio volumio[4391]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 14 05:39:40 volumio volumio[4391]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 14 05:39:40 volumio volumio[4391]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 14 05:39:40 volumio volumio[4391]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 14 05:39:40 volumio volumio[4391]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 14 05:39:40 volumio volumio[4391]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 14 05:39:40 volumio volumio[4391]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 14 05:39:40 volumio volumio[4391]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Apr 14 05:39:40 volumio volumio[4391]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 14 05:39:40 volumio volumio[4391]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 14 05:39:40 volumio volumio[4391]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 14 05:39:40 volumio volumio[4391]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 14 05:39:40 volumio volumio[4391]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 14 05:39:40 volumio volumio[4391]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 14 05:39:40 volumio volumio[4391]: info: Adding plugin bluetooth to MyMusic Plugins Apr 14 05:39:40 volumio volumio[4391]: info: Adding plugin multiroom to MyMusic Plugins Apr 14 05:39:40 volumio volumio[4391]: info: Adding plugin metavolumio to MyMusic Plugins Apr 14 05:39:40 volumio volumio[4391]: info: Adding plugin cd_controller to MyMusic Plugins Apr 14 05:39:40 volumio volumio[4391]: info: Adding plugin qobuzconnect to MyMusic Plugins Apr 14 05:39:40 volumio volumio[4391]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 14 05:39:40 volumio volumio[4391]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 14 05:39:40 volumio volumio[4391]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 14 05:39:41 volumio volumio[4391]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 14 05:39:41 volumio volumio[4391]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 14 05:39:41 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:41 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:41 volumio volumio[4391]: info: Starting MyVolumio Remote Streaming Endpoints Apr 14 05:39:41 volumio volumio[4391]: info: MyVolumio login type: Token Apr 14 05:39:41 volumio volumio[4391]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 14 05:39:41 volumio volumio[4391]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 14 05:39:41 volumio go-librespot[4673]: time="2026-04-14T05:39:41+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 14 05:39:41 volumio go-librespot[4673]: time="2026-04-14T05:39:41+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:41 volumio go-librespot[4673]: time="2026-04-14T05:39:41+01:00" level=debug msg="completed challenge" Apr 14 05:39:41 volumio go-librespot[4673]: time="2026-04-14T05:39:41+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:41 volumio volumio[4391]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 14 05:39:41 volumio volumio[4391]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 14 05:39:41 volumio volumio[4391]: info: Streaming services startup Apr 14 05:39:41 volumio volumio[4391]: info: Starting Streaming Daemon Apr 14 05:39:41 volumio sudo[4683]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 14 05:39:41 volumio sudo[4683]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:41 volumio volumio[4391]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 14 05:39:41 volumio sudo[4683]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:41 volumio volumio[4391]: info: Initializing connection to go-librespot Websocket Apr 14 05:39:41 volumio volumio[4391]: error: Cannot start Volumio Streaming Daemon Apr 14 05:39:41 volumio volumio[4391]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 14 05:39:41 volumio volumio[4391]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 14 05:39:41 volumio go-librespot[4673]: time="2026-04-14T05:39:41+01:00" level=debug msg="new websocket client" Apr 14 05:39:41 volumio volumio[4391]: info: Connection to go-librespot Websocket established Apr 14 05:39:41 volumio go-librespot[4673]: time="2026-04-14T05:39:41+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 14 05:39:41 volumio go-librespot[4673]: time="2026-04-14T05:39:41+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:41 volumio go-librespot[4673]: time="2026-04-14T05:39:41+01:00" level=debug msg="completed challenge" Apr 14 05:39:41 volumio go-librespot[4673]: time="2026-04-14T05:39:41+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:41 volumio volumio[4391]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 14 05:39:42 volumio volumio[4391]: info: MyVolumio token set successfully Apr 14 05:39:42 volumio volumio[4391]: info: MYVOLUMIO: Adding device Apr 14 05:39:42 volumio volumio[4391]: info: MYVOLUMIO: Evaluating Server Apr 14 05:39:42 volumio volumio[4391]: info: MyVolumio status changed Apr 14 05:39:42 volumio volumio[4391]: info: Streaming services startup Apr 14 05:39:42 volumio volumio[4391]: info: Starting Streaming Daemon Apr 14 05:39:42 volumio volumio[4391]: info: Removing browser output: myVolumio user plan is not superstar Apr 14 05:39:42 volumio volumio[4391]: info: Removing audio output: Apr 14 05:39:42 volumio volumio[4391]: info: Stoppping Tunnel 1 Apr 14 05:39:42 volumio sudo[4710]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 14 05:39:42 volumio sudo[4710]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:42 volumio sudo[4712]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Apr 14 05:39:42 volumio sudo[4712]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:42 volumio sudo[4710]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:42 volumio volumio[4391]: error: Cannot start Volumio Streaming Daemon Apr 14 05:39:42 volumio volumio[4391]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 14 05:39:42 volumio volumio[4391]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 14 05:39:42 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. Apr 14 05:39:42 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. Apr 14 05:39:42 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. Apr 14 05:39:42 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. Apr 14 05:39:42 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. Apr 14 05:39:42 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. Apr 14 05:39:42 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. Apr 14 05:39:42 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. Apr 14 05:39:42 volumio sudo[4712]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:42 volumio volumio[4391]: info: Remote SSH Stopped Apr 14 05:39:42 volumio go-librespot[4673]: time="2026-04-14T05:39:42+01:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Apr 14 05:39:42 volumio go-librespot[4673]: time="2026-04-14T05:39:42+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:42 volumio go-librespot[4673]: time="2026-04-14T05:39:42+01:00" level=debug msg="completed challenge" Apr 14 05:39:42 volumio volumio[4391]: info: Setting Geolocation for MyVolumio to eu3 Apr 14 05:39:42 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:42 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:42 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:42 volumio go-librespot[4673]: time="2026-04-14T05:39:42+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:43 volumio volumio[4391]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Apr 14 05:39:43 volumio go-librespot[4673]: time="2026-04-14T05:39:43+01:00" level=debug msg="connected to ap-gue1.spotify.com:443" Apr 14 05:39:43 volumio go-librespot[4673]: time="2026-04-14T05:39:43+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:43 volumio go-librespot[4673]: time="2026-04-14T05:39:43+01:00" level=debug msg="completed challenge" Apr 14 05:39:43 volumio go-librespot[4673]: time="2026-04-14T05:39:43+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:43 volumio volumio[4391]: info: Updating MyVolumio device info Apr 14 05:39:43 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:43 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:43 volumio volumio[4391]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:44 volumio go-librespot[4673]: time="2026-04-14T05:39:44+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 14 05:39:44 volumio volumio[4391]: info: Getting Spotify volume Apr 14 05:39:44 volumio volumio[4391]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Apr 14 05:39:44 volumio volumio[4391]: info: CoreCommandRouter::volumioGetState Apr 14 05:39:44 volumio volumio[4391]: info: CorePlayQueue::getTrack 0 Apr 14 05:39:44 volumio volumio[4391]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Apr 14 05:39:44 volumio volumio[4391]: SPOTIFY: SPOTIFY VOLUME undefined Apr 14 05:39:44 volumio volumio[4391]: SPOTIFY: VOLUMIO VOLUME 0 Apr 14 05:39:44 volumio volumio[4391]: info: Aligning Spotify Volume to Volumio Volume Apr 14 05:39:44 volumio volumio[4391]: info: CoreCommandRouter::volumioGetState Apr 14 05:39:44 volumio volumio[4391]: info: CorePlayQueue::getTrack 0 Apr 14 05:39:44 volumio volumio[4391]: info: Setting Spotify Volume from Volumio: 0 Apr 14 05:39:44 volumio go-librespot[4673]: time="2026-04-14T05:39:44+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:44 volumio go-librespot[4673]: time="2026-04-14T05:39:44+01:00" level=debug msg="completed challenge" Apr 14 05:39:44 volumio volumio[4391]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Apr 14 05:39:44 volumio go-librespot[4673]: time="2026-04-14T05:39:44+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:44 volumio go-librespot[4673]: time="2026-04-14T05:39:44+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 05:39:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 05:39:44 volumio volumio[4391]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 05:39:44 volumio volumio[4391]: Error: socket hang up Apr 14 05:39:44 volumio volumio[4391]: at connResetException (node:internal/errors:720:14) Apr 14 05:39:44 volumio volumio[4391]: at Socket.socketOnEnd (node:_http_client:519:23) Apr 14 05:39:44 volumio volumio[4391]: at Socket.emit (node:events:526:35) Apr 14 05:39:44 volumio volumio[4391]: at endReadableNT (node:internal/streams/readable:1376:12) Apr 14 05:39:44 volumio volumio[4391]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Apr 14 05:39:44 volumio volumio[4391]: code: 'ECONNRESET', Apr 14 05:39:44 volumio volumio[4391]: response: undefined Apr 14 05:39:44 volumio volumio[4391]: } Apr 14 05:39:44 volumio volumio[4391]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 05:39:45 volumio sudo[4729]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-14 05:38' Apr 14 05:39:45 volumio sudo[4729]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:45 volumio sudo[4729]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:45 volumio volumio-remote-updater[945]: [2026-04-14 05:39:45] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Apr 14 05:39:45 volumio volumio-remote-updater[945]: [2026-04-14 05:39:45] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Apr 14 05:39:45 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Apr 14 05:39:45 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Apr 14 05:39:45 volumio systemd[1]: volumio.service: Consumed 8.881s CPU time. Apr 14 05:39:45 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 14 05:39:45 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 14 05:39:45 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 119778. Apr 14 05:39:45 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 14 05:39:45 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Apr 14 05:39:45 volumio systemd[1]: volumio.service: Consumed 8.881s CPU time. Apr 14 05:39:45 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Apr 14 05:39:45 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 14 05:39:45 volumio volumio[4741]: info: ------------------------------------------- Apr 14 05:39:45 volumio volumio[4741]: info: ----- Volumio3 ---- Apr 14 05:39:45 volumio volumio[4741]: info: ------------------------------------------- Apr 14 05:39:45 volumio volumio[4741]: info: ----- System startup ---- Apr 14 05:39:45 volumio volumio[4741]: info: ------------------------------------------- Apr 14 05:39:46 volumio volumio[4741]: info: MYVOLUMIO Environment detected Apr 14 05:39:46 volumio volumio[4741]: info: Plugin folders cleanup Apr 14 05:39:46 volumio volumio[4741]: info: Scanning into folder /volumio/app/plugins/ Apr 14 05:39:46 volumio volumio[4741]: info: Scanning category audio_interface Apr 14 05:39:46 volumio volumio[4741]: info: Scanning category miscellanea Apr 14 05:39:46 volumio volumio[4741]: info: Scanning category music_service Apr 14 05:39:46 volumio volumio[4741]: info: Scanning category plugins.json Apr 14 05:39:46 volumio volumio[4741]: info: Scanning category system_controller Apr 14 05:39:46 volumio volumio[4741]: info: Scanning category user_interface Apr 14 05:39:46 volumio volumio[4741]: info: Scanning into folder /data/plugins/ Apr 14 05:39:46 volumio volumio[4741]: info: Scanning category music_service Apr 14 05:39:46 volumio volumio[4741]: info: Plugin folders cleanup completed Apr 14 05:39:46 volumio volumio[4741]: info: ------------------------------------------- Apr 14 05:39:46 volumio volumio[4741]: info: ----- Core plugins startup ---- Apr 14 05:39:46 volumio volumio[4741]: info: ------------------------------------------- Apr 14 05:39:46 volumio volumio[4741]: info: Loading plugins from folder /volumio/app/plugins/ Apr 14 05:39:46 volumio volumio[4741]: info: Adding plugin upnp to MyMusic Plugins Apr 14 05:39:46 volumio volumio[4741]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 14 05:39:46 volumio volumio[4741]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 14 05:39:46 volumio volumio[4741]: info: Loading plugins from folder /data/plugins/ Apr 14 05:39:46 volumio volumio[4741]: info: Adding plugin rtlsdr_radio to MyMusic Plugins Apr 14 05:39:46 volumio volumio[4741]: info: Loading plugin "system"... Apr 14 05:39:46 volumio volumio[4741]: info: Loading plugin "appearance"... Apr 14 05:39:46 volumio volumio[4741]: info: Loading plugin "network"... Apr 14 05:39:46 volumio volumio[4741]: info: Refreshing Cached IP Addresses Apr 14 05:39:46 volumio sudo[4769]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 05:39:46 volumio sudo[4769]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:46 volumio sudo[4771]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 05:39:46 volumio sudo[4771]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:46 volumio sudo[4769]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:46 volumio sudo[4771]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:46 volumio volumio[4741]: info: Loading plugin "services"... Apr 14 05:39:46 volumio volumio[4741]: info: Loading plugin "alsa_controller"... Apr 14 05:39:46 volumio sudo[4780]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 14 05:39:46 volumio sudo[4780]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:46 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 05:39:46 volumio volumio[4741]: info: Loading plugin "wizard"... Apr 14 05:39:46 volumio volumio[4741]: info: Loading plugin "networkfs"... Apr 14 05:39:46 volumio volumio[4741]: info: Starting Udev Watcher for removable devices Apr 14 05:39:46 volumio volumio[4741]: info: Mounting Device 0ACB-A1DE Apr 14 05:39:46 volumio sudo[4808]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/0ACB-A1DE -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Apr 14 05:39:46 volumio sudo[4808]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:46 volumio sudo[4808]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:46 volumio volumio[4741]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Apr 14 05:39:46 volumio volumio[4741]: dmesg(1) may have more information after failed mount system call. Apr 14 05:39:46 volumio volumio[4741]: error: Failed to mount 0ACB-A1DE: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/0ACB-A1DE" -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Apr 14 05:39:46 volumio volumio[4741]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Apr 14 05:39:46 volumio volumio[4741]: dmesg(1) may have more information after failed mount system call. Apr 14 05:39:46 volumio volumio[4741]: info: Ignoring mount for partition: boot Apr 14 05:39:46 volumio volumio[4741]: info: Ignoring mount for partition: volumio Apr 14 05:39:46 volumio volumio[4741]: info: Ignoring mount for partition: volumio_data Apr 14 05:39:46 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 05:39:46 volumio volumio[4741]: info: Loading plugin "volumio_command_line_client"... Apr 14 05:39:46 volumio volumio[4741]: info: Loading plugin "upnp"... Apr 14 05:39:46 volumio volumio[4741]: info: [1776141586624] Starting Upmpd Daemon Apr 14 05:39:46 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 05:39:46 volumio volumio[4741]: info: Loading plugin "my_music"... Apr 14 05:39:46 volumio volumio[4741]: info: Loading plugin "mpd"... Apr 14 05:39:46 volumio volumio[4741]: info: Loading plugin "upnp_browser"... Apr 14 05:39:47 volumio volumio[4741]: info: Starting UPNP Browser Apr 14 05:39:47 volumio volumio[4741]: info: Loading plugin "alarm-clock"... Apr 14 05:39:47 volumio volumio[4741]: info: Loading plugin "airplay_emulation"... Apr 14 05:39:47 volumio volumio[4741]: info: Starting Shairport Sync Apr 14 05:39:47 volumio volumio[4741]: info: Loading plugin "last_100"... Apr 14 05:39:47 volumio volumio[4741]: info: Loading plugin "webradio"... Apr 14 05:39:47 volumio volumio[4741]: info: Loading plugin "i2s_dacs"... Apr 14 05:39:47 volumio volumio[4741]: info: Loading plugin "volumiodiscovery"... Apr 14 05:39:47 volumio volumio[4741]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 14 05:39:47 volumio volumio[4741]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 05:39:47 volumio volumio[4741]: *** WARNING *** For more information see Apr 14 05:39:47 volumio volumio[4741]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 14 05:39:47 volumio volumio[4741]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 05:39:47 volumio volumio[4741]: *** WARNING *** For more information see Apr 14 05:39:47 volumio node[4741]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 14 05:39:47 volumio node[4741]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 05:39:47 volumio node[4741]: *** WARNING *** For more information see Apr 14 05:39:47 volumio node[4741]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 14 05:39:47 volumio node[4741]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 05:39:47 volumio node[4741]: *** WARNING *** For more information see Apr 14 05:39:47 volumio volumio[4741]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 14 05:39:47 volumio volumio[4741]: info: Discovery: Started advertising with name: Volumio Apr 14 05:39:47 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 05:39:47 volumio volumio[4741]: info: Loading plugin "spop"... Apr 14 05:39:47 volumio volumio[4741]: info: Loading plugin "ytmusic"... Apr 14 05:39:47 volumio volumio[4741]: info: Loading plugin "outputs"... Apr 14 05:39:47 volumio volumio[4741]: info: Loading plugin "albumart"... Apr 14 05:39:47 volumio volumio[4741]: info: Plugin example_plugin is not enabled Apr 14 05:39:47 volumio volumio[4741]: info: Loading plugin "inputs"... Apr 14 05:39:47 volumio volumio[4741]: info: Loading plugin "updater_comm"... Apr 14 05:39:47 volumio volumio[4741]: info: Plugin mpdemulation is not enabled Apr 14 05:39:47 volumio volumio[4741]: info: Loading plugin "rest_api"... Apr 14 05:39:47 volumio volumio[4741]: info: Loading plugin "websocket"... Apr 14 05:39:47 volumio volumio[4741]: info: Starting Socket.io Server version 1.7.4 Apr 14 05:39:47 volumio volumio[4741]: info: Loading plugin "podcast"... Apr 14 05:39:47 volumio volumio[4741]: info: ControllerPodcast::constructor Apr 14 05:39:47 volumio volumio[4741]: info: Loading plugin "rtlsdr_radio"... Apr 14 05:39:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Apr 14 05:39:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 05:39:47 volumio volumio[4812]: Forking 3 albumart workers Apr 14 05:39:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 05:39:47 volumio go-librespot[4822]: go-librespot daemon starting... Apr 14 05:39:47 volumio go-librespot[4824]: time="2026-04-14T05:39:47+01:00" level=info msg="running go-librespot 0.6.2" Apr 14 05:39:47 volumio go-librespot[4824]: time="2026-04-14T05:39:47+01:00" level=debug msg="app state loaded" Apr 14 05:39:47 volumio go-librespot[4824]: time="2026-04-14T05:39:47+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 05:39:48 volumio volumio[4741]: info: Loading i18n strings for locale en Apr 14 05:39:48 volumio volumio[4741]: Updating browse sources language Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::initPlayerControls Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: Express server listening on port 3000 Apr 14 05:39:48 volumio volumio[4741]: [Metrics] WebUI: 2s 337.80ms Apr 14 05:39:48 volumio volumio[4741]: info: CoreStateMachine::resetVolumioState Apr 14 05:39:48 volumio volumio[4741]: info: CoreStateMachine::getcurrentVolume Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::volumioRetrievevolume Apr 14 05:39:48 volumio volumio[4741]: info: Volumio Network Manager: Network status updated: 2 Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: Reloading queue from file Apr 14 05:39:48 volumio volumio[4741]: info: VolumeController:: Volume=36 Mute =true Apr 14 05:39:48 volumio volumio[4741]: info: CoreStateMachine::pushState Apr 14 05:39:48 volumio volumio[4741]: info: CorePlayQueue::getTrack 0 Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::volumioPushState Apr 14 05:39:48 volumio volumio[4741]: info: CoreStateMachine::updateTrackBlock Apr 14 05:39:48 volumio volumio[4741]: info: CorePlayQueue::getTrackBlock Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::volumioRetrievevolume Apr 14 05:39:48 volumio volumio[4741]: info: CoreStateMachine::setRepeat null single undefined Apr 14 05:39:48 volumio volumio[4741]: info: CoreStateMachine::pushState Apr 14 05:39:48 volumio volumio[4741]: info: CorePlayQueue::getTrack 0 Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::volumioPushState Apr 14 05:39:48 volumio volumio[4741]: info: CoreStateMachine::setRandom true Apr 14 05:39:48 volumio volumio[4741]: info: CoreStateMachine::pushState Apr 14 05:39:48 volumio volumio[4741]: info: CorePlayQueue::getTrack 0 Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::volumioPushState Apr 14 05:39:48 volumio volumio[4741]: info: Setting Device type: Raspberry PI Apr 14 05:39:48 volumio volumio[4741]: info: Completed loading Core Plugins Apr 14 05:39:48 volumio volumio[4741]: info: Preparing to generate the ALSA configuration file Apr 14 05:39:48 volumio volumio[4741]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Apr 14 05:39:48 volumio volumio[4741]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04170 Apr 14 05:39:48 volumio volumio[4741]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Apr 14 05:39:48 volumio volumio[4830]: Starting albumart workers Apr 14 05:39:48 volumio volumio[4823]: Starting albumart workers Apr 14 05:39:48 volumio go-librespot[4824]: time="2026-04-14T05:39:48+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 14 05:39:48 volumio go-librespot[4824]: time="2026-04-14T05:39:48+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 14 05:39:48 volumio go-librespot[4824]: time="2026-04-14T05:39:48+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 14 05:39:48 volumio volumio[4741]: info: Asound.conf file unchanged, so no further update is needed Apr 14 05:39:48 volumio volumio[4741]: info: Output device has changed, restarting MPD Apr 14 05:39:48 volumio go-librespot[4824]: time="2026-04-14T05:39:48+01:00" level=info msg="zeroconf server listening on port 43343" Apr 14 05:39:48 volumio volumio[4741]: info: Output device has changed, restarting Shairport Sync Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:48 volumio sudo[4878]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 14 05:39:48 volumio sudo[4878]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:48 volumio sudo[4878]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:48 volumio volumio[4741]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 05:39:48 volumio volumio[4741]: info: ___________ START PLUGINS ___________ Apr 14 05:39:48 volumio sudo[4880]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 14 05:39:48 volumio volumio[4741]: info: ControllerMpd::onStart: Initializing MPD Apr 14 05:39:48 volumio volumio[4741]: info: Creating MPD Configuration file Apr 14 05:39:48 volumio sudo[4880]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:48 volumio sudo[4888]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 05:39:48 volumio volumio[4741]: info: [1776141588431] CoreMusicLibrary::Adding element Media Servers Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 05:39:48 volumio sudo[4888]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:48 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 14 05:39:48 volumio volumio[4741]: info: UPNP Browser: Client initialized successfully Apr 14 05:39:48 volumio sudo[4888]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:48 volumio sudo[4890]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:48 volumio sudo[4890]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:48 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 14 05:39:48 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 14 05:39:48 volumio volumio[4828]: Starting albumart workers Apr 14 05:39:48 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 14 05:39:48 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 14 05:39:48 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 14 05:39:48 volumio volumio[4741]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:48 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 14 05:39:48 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 14 05:39:48 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 14 05:39:48 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 14 05:39:48 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 14 05:39:48 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 14 05:39:48 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 14 05:39:48 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 14 05:39:48 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 14 05:39:48 volumio volumio[4741]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 05:39:48 volumio volumio[4741]: info: [1776141588529] CoreMusicLibrary::Adding element Last_100 Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 05:39:48 volumio volumio[4741]: info: [1776141588530] CoreMusicLibrary::Adding element Webradio Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 05:39:48 volumio volumio[4741]: info: Initializing BBC Radios Apr 14 05:39:48 volumio sudo[4904]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 14 05:39:48 volumio sudo[4904]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 14 05:39:48 volumio sudo[4904]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: Creating Spotify config file Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:48 volumio go-librespot[4824]: time="2026-04-14T05:39:48+01:00" level=debug msg="obtained new client token: AAD0SB0G8Q3BcNBiIq8wi/fssDflrTKEsCAKB1jEmUfKGUIJK10b+wWDZVqdAMB3f07QkRNIk1XSjxcbEp6c/qN2/R6tHaBDxdpjZ1LkdebVi5uQLyl7+skUqF/OvI0DMVpyoGf5wyfNCDxv/m4+bB6qB3RPlknW02gainkimu0DCFYUfL6X6Jy3oC4pEQw/nWBKyfLACxUBPeZMdHxdBdEROrHU16E+2JpyF1SZL0fgsjUrJVf0qVh4Fg==" Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 05:39:48 volumio volumio[4741]: info: [1776141588740] CoreMusicLibrary::Adding element YouTube Music Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 05:39:48 volumio volumio[4741]: Cannot find translation for source YouTube Music Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 05:39:48 volumio volumio[4741]: info: [1776141588745] CoreMusicLibrary::Adding element Podcast Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 05:39:48 volumio volumio[4741]: Cannot find translation for source YouTube Music Apr 14 05:39:48 volumio volumio[4741]: Cannot find translation for source Podcast Apr 14 05:39:48 volumio volumio[4741]: info: [RTL-SDR Radio] Starting plugin Apr 14 05:39:48 volumio volumio[4741]: info: [RTL-SDR Radio] Loaded i18n strings for language: en Apr 14 05:39:48 volumio volumio[4741]: info: Volumio Calling Home Apr 14 05:39:48 volumio volumio[4741]: info: [RTL-SDR Radio] snd-aloop already loaded Apr 14 05:39:48 volumio volumio[4741]: info: [RTL-SDR Radio] No stations database found, creating v2 Apr 14 05:39:48 volumio volumio[4741]: info: [RTL-SDR Radio] Database loaded at: 2026-04-14T04:39:48.788Z Apr 14 05:39:48 volumio volumio[4741]: info: [RTL-SDR Radio] Loading blocklist from: /data/plugins/music_service/rtlsdr_radio/blocklist.json Apr 14 05:39:48 volumio volumio[4741]: info: [RTL-SDR Radio] Got 21 phrases from file Apr 14 05:39:48 volumio volumio[4741]: info: [RTL-SDR Radio] Updated metadata blocklist Apr 14 05:39:48 volumio volumio[4741]: info: [RTL-SDR Radio] Metadata module now has 21 phrases Apr 14 05:39:48 volumio volumio[4741]: info: [RTL-SDR Radio] Management server started on port 3456 Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 05:39:48 volumio volumio[4741]: info: [1776141588820] CoreMusicLibrary::Adding element FM/DAB Radio Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 05:39:48 volumio volumio[4741]: Cannot find translation for source YouTube Music Apr 14 05:39:48 volumio volumio[4741]: Cannot find translation for source Podcast Apr 14 05:39:48 volumio volumio[4741]: Cannot find translation for source FM/DAB Radio Apr 14 05:39:48 volumio volumio[4741]: info: [RTL-SDR Radio] Plugin started successfully Apr 14 05:39:48 volumio volumio[4741]: info: Discovery: adding 072f109f-54a2-4344-b8c4-538b45da7e51 Apr 14 05:39:48 volumio volumio[4741]: info: Discovery: Found device Volumio Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::volumioGetState Apr 14 05:39:48 volumio volumio[4741]: info: CorePlayQueue::getTrack 0 Apr 14 05:39:48 volumio volumio[4741]: info: Discovery: this is already registered, 072f109f-54a2-4344-b8c4-538b45da7e51 Apr 14 05:39:48 volumio volumio[4741]: info: Discovery: Found device Volumio Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::volumioGetState Apr 14 05:39:48 volumio volumio[4741]: info: CorePlayQueue::getTrack 0 Apr 14 05:39:48 volumio volumio[4741]: info: MPD Permissions set Apr 14 05:39:48 volumio volumio[4741]: info: MPD Permissions set Apr 14 05:39:48 volumio volumio[4741]: info: VolumeController:: Volume=36 Mute =true Apr 14 05:39:48 volumio volumio[4741]: info: CoreStateMachine::pushState Apr 14 05:39:48 volumio volumio[4741]: info: CorePlayQueue::getTrack 0 Apr 14 05:39:48 volumio go-librespot[4824]: time="2026-04-14T05:39:48+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::volumioPushState Apr 14 05:39:48 volumio volumio[4741]: info: Spotify config file written Apr 14 05:39:48 volumio sudo[4948]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 14 05:39:48 volumio sudo[4948]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:48 volumio go-librespot[4824]: time="2026-04-14T05:39:48+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:48 volumio go-librespot[4824]: time="2026-04-14T05:39:48+01:00" level=debug msg="completed challenge" Apr 14 05:39:48 volumio volumio[4741]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:48 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Apr 14 05:39:48 volumio systemd[1]: go-librespot-daemon.service: Killing process 4826 (go-librespot) with signal SIGKILL. Apr 14 05:39:48 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Apr 14 05:39:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 05:39:48 volumio volumio[4741]: info: No need to fix Spotify hosts Apr 14 05:39:48 volumio volumio[4741]: info: Starting Shairport Sync Apr 14 05:39:48 volumio volumio[4741]: info: Starting Shairport Sync Apr 14 05:39:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 05:39:48 volumio go-librespot[4955]: go-librespot daemon starting... Apr 14 05:39:48 volumio sudo[4948]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:48 volumio sudo[4962]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 05:39:48 volumio sudo[4962]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:48 volumio volumio[4741]: info: Starting Shairport Sync Apr 14 05:39:48 volumio go-librespot[4963]: time="2026-04-14T05:39:48+01:00" level=info msg="running go-librespot 0.6.2" Apr 14 05:39:48 volumio go-librespot[4963]: time="2026-04-14T05:39:48+01:00" level=debug msg="app state loaded" Apr 14 05:39:48 volumio go-librespot[4963]: time="2026-04-14T05:39:48+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 05:39:48 volumio sudo[4971]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 05:39:48 volumio sudo[4971]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:48 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 14 05:39:48 volumio sudo[4973]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 05:39:48 volumio sudo[4973]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:48 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 14 05:39:48 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 05:39:48 volumio systemd[1]: shairport-sync.service: Consumed 1.554s CPU time. Apr 14 05:39:48 volumio volumio[4741]: info: CoreCommandRouter::volumioGetState Apr 14 05:39:48 volumio volumio[4741]: info: CorePlayQueue::getTrack 0 Apr 14 05:39:48 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 05:39:48 volumio sudo[4962]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:48 volumio volumio[4741]: info: Shairport-Sync Started Apr 14 05:39:48 volumio volumio[4741]: Error adding Membership: Error: addMembership EINVAL Apr 14 05:39:48 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 14 05:39:48 volumio sudo[4971]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:48 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 14 05:39:48 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 05:39:48 volumio volumio[4741]: info: Shairport-Sync Started Apr 14 05:39:48 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 05:39:48 volumio sudo[4973]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:48 volumio volumio[4741]: info: Shairport-Sync Started Apr 14 05:39:49 volumio volumio[4741]: info: Volumio called home Apr 14 05:39:49 volumio mpd[4930]: 2026-04-14T05:39:49 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 14 05:39:49 volumio systemd[1]: Started mpd.service - Music Player Daemon. Apr 14 05:39:49 volumio sudo[4890]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:49 volumio sudo[4880]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:49 volumio volumio[4741]: info: Completed starting Core Plugins Apr 14 05:39:49 volumio volumio[4741]: info: ------------------------------------------- Apr 14 05:39:49 volumio volumio[4741]: info: ----- MyVolumio plugins startup ---- Apr 14 05:39:49 volumio volumio[4741]: info: ------------------------------------------- Apr 14 05:39:49 volumio volumio[4741]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 14 05:39:49 volumio volumio[4741]: error: MPD error: The expression evaluated to a falsy value: Apr 14 05:39:49 volumio volumio[4741]: assert.ok(self.idling) Apr 14 05:39:49 volumio volumio[4741]: error: The expression evaluated to a falsy value: Apr 14 05:39:49 volumio volumio[4741]: assert.ok(self.idling) Apr 14 05:39:49 volumio volumio[4741]: info: MPD running with PID4930 Apr 14 05:39:49 volumio volumio[4741]: ,establishing connection Apr 14 05:39:49 volumio volumio[4741]: error: updateQueue error: null Apr 14 05:39:49 volumio volumio[4741]: error: updateQueue error: null Apr 14 05:39:49 volumio go-librespot[4963]: time="2026-04-14T05:39:49+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 14 05:39:49 volumio go-librespot[4963]: time="2026-04-14T05:39:49+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Apr 14 05:39:49 volumio go-librespot[4963]: time="2026-04-14T05:39:49+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Apr 14 05:39:49 volumio volumio[4741]: info: An error occurred while refreshing Spotify Token Error: Bad Request Apr 14 05:39:49 volumio go-librespot[4963]: time="2026-04-14T05:39:49+01:00" level=info msg="zeroconf server listening on port 34435" Apr 14 05:39:49 volumio go-librespot[4963]: time="2026-04-14T05:39:49+01:00" level=debug msg="obtained new client token: AAAd3aNRkBGtGab+jSY/hTJ91enpXWoXzxMrObkH5dfqk8Gx5evZE259wLx2As3qjjFIeZRapSNS20qGesa4US4HvIpzw9EcKIJ6bElSxjxXvxU5S3wytV5nxGmDc75irMrqxv/FALSIbfu3mPVpHX127/ExlwxJVF2ZW96CTbvxdtk3tCkhlZVwDqZb/VFzQHL88WGxgXIAp62g1cRQ4FkyHnwZ85Olsv0UVrqwYDLFVK61oMW97OJBog==" Apr 14 05:39:49 volumio go-librespot[4963]: time="2026-04-14T05:39:49+01:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Apr 14 05:39:50 volumio go-librespot[4963]: time="2026-04-14T05:39:50+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 14 05:39:50 volumio go-librespot[4963]: time="2026-04-14T05:39:50+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:50 volumio go-librespot[4963]: time="2026-04-14T05:39:50+01:00" level=debug msg="completed challenge" Apr 14 05:39:50 volumio volumio-remote-updater[945]: [2026-04-14 05:39:50] [connect] Successful connection Apr 14 05:39:50 volumio volumio-remote-updater[945]: [2026-04-14 05:39:50] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1776141590 101 Apr 14 05:39:50 volumio volumio[4741]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 2 Apr 14 05:39:50 volumio go-librespot[4963]: time="2026-04-14T05:39:50+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:50 volumio sudo[4780]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:50 volumio go-librespot[4963]: time="2026-04-14T05:39:50+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 14 05:39:50 volumio go-librespot[4963]: time="2026-04-14T05:39:50+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:50 volumio go-librespot[4963]: time="2026-04-14T05:39:50+01:00" level=debug msg="completed challenge" Apr 14 05:39:50 volumio go-librespot[4963]: time="2026-04-14T05:39:50+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:51 volumio go-librespot[4963]: time="2026-04-14T05:39:51+01:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Apr 14 05:39:51 volumio go-librespot[4963]: time="2026-04-14T05:39:51+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:51 volumio go-librespot[4963]: time="2026-04-14T05:39:51+01:00" level=debug msg="completed challenge" Apr 14 05:39:51 volumio go-librespot[4963]: time="2026-04-14T05:39:51+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:51 volumio volumio[4741]: info: go-librespot daemon successfully initialized Apr 14 05:39:52 volumio go-librespot[4963]: time="2026-04-14T05:39:52+01:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.255.62:443: connect: connection refused" Apr 14 05:39:52 volumio go-librespot[4963]: time="2026-04-14T05:39:52+01:00" level=debug msg="connected to ap-gew4.spotify.com:80" Apr 14 05:39:52 volumio go-librespot[4963]: time="2026-04-14T05:39:52+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:52 volumio go-librespot[4963]: time="2026-04-14T05:39:52+01:00" level=debug msg="completed challenge" Apr 14 05:39:52 volumio go-librespot[4963]: time="2026-04-14T05:39:52+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:53 volumio go-librespot[4963]: time="2026-04-14T05:39:53+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 14 05:39:53 volumio go-librespot[4963]: time="2026-04-14T05:39:53+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:53 volumio go-librespot[4963]: time="2026-04-14T05:39:53+01:00" level=debug msg="completed challenge" Apr 14 05:39:53 volumio go-librespot[4963]: time="2026-04-14T05:39:53+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:53 volumio go-librespot[4963]: time="2026-04-14T05:39:53+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 14 05:39:53 volumio go-librespot[4963]: time="2026-04-14T05:39:53+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:53 volumio go-librespot[4963]: time="2026-04-14T05:39:53+01:00" level=debug msg="completed challenge" Apr 14 05:39:53 volumio go-librespot[4963]: time="2026-04-14T05:39:53+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:53 volumio go-librespot[4963]: time="2026-04-14T05:39:53+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 05:39:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 05:39:54 volumio volumio[4741]: info: Initializing connection to go-librespot Websocket Apr 14 05:39:54 volumio volumio[4741]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 14 05:39:56 volumio sudo[5015]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 05:39:56 volumio sudo[5015]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:56 volumio sudo[5015]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:56 volumio sudo[5017]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 05:39:56 volumio sudo[5017]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:56 volumio sudo[5017]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:56 volumio sudo[5021]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 14 05:39:56 volumio sudo[5021]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Apr 14 05:39:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 05:39:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 05:39:56 volumio go-librespot[5023]: go-librespot daemon starting... Apr 14 05:39:56 volumio sudo[5021]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:56 volumio volumio[4741]: info: Upmpdcli Daemon Started Apr 14 05:39:56 volumio go-librespot[5024]: time="2026-04-14T05:39:56+01:00" level=info msg="running go-librespot 0.6.2" Apr 14 05:39:56 volumio go-librespot[5024]: time="2026-04-14T05:39:56+01:00" level=debug msg="app state loaded" Apr 14 05:39:56 volumio go-librespot[5024]: time="2026-04-14T05:39:56+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 05:39:56 volumio go-librespot[5024]: time="2026-04-14T05:39:56+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 14 05:39:56 volumio go-librespot[5024]: time="2026-04-14T05:39:56+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 14 05:39:56 volumio go-librespot[5024]: time="2026-04-14T05:39:56+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 14 05:39:56 volumio go-librespot[5024]: time="2026-04-14T05:39:56+01:00" level=info msg="zeroconf server listening on port 46163" Apr 14 05:39:56 volumio go-librespot[5024]: time="2026-04-14T05:39:56+01:00" level=debug msg="obtained new client token: AADK72QRzJndcqmQQgeWZ0DUH424dqaIvFGEaE8HGb5IxDJ81/+tTTgJrkBVNy9CM2lWt62N9HhAVnpe0QXWSSBAxNPwWXesUmzJPqlnzgMpSC6OWKnkULLFG+/TRZPNcT0F6yf5/85ecqTIUKUPgrZf3kJV8E9f2luU+0dIN8/b2Ct4wNad/aM6mB2OprGiL5kAzrGCZtVznmziY9nmXcJMAN0KFiqNen/fwGKo0lQPpoKCo64cbbot1w==" Apr 14 05:39:56 volumio go-librespot[5024]: time="2026-04-14T05:39:56+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 14 05:39:56 volumio go-librespot[5024]: time="2026-04-14T05:39:56+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:56 volumio go-librespot[5024]: time="2026-04-14T05:39:56+01:00" level=debug msg="completed challenge" Apr 14 05:39:57 volumio go-librespot[5024]: time="2026-04-14T05:39:57+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:57 volumio go-librespot[5024]: time="2026-04-14T05:39:57+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 14 05:39:57 volumio volumio[4741]: info: Adding plugin bluetooth to MyMusic Plugins Apr 14 05:39:57 volumio volumio[4741]: info: Adding plugin multiroom to MyMusic Plugins Apr 14 05:39:57 volumio volumio[4741]: info: Adding plugin metavolumio to MyMusic Plugins Apr 14 05:39:57 volumio volumio[4741]: info: Adding plugin cd_controller to MyMusic Plugins Apr 14 05:39:57 volumio volumio[4741]: info: Adding plugin qobuzconnect to MyMusic Plugins Apr 14 05:39:57 volumio volumio[4741]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 14 05:39:57 volumio volumio[4741]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 14 05:39:57 volumio go-librespot[5024]: time="2026-04-14T05:39:57+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:57 volumio go-librespot[5024]: time="2026-04-14T05:39:57+01:00" level=debug msg="completed challenge" Apr 14 05:39:57 volumio go-librespot[5024]: time="2026-04-14T05:39:57+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 14 05:39:57 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:57 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:57 volumio volumio[4741]: info: Starting MyVolumio Remote Streaming Endpoints Apr 14 05:39:57 volumio volumio[4741]: info: MyVolumio login type: Token Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 14 05:39:57 volumio volumio[4741]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 14 05:39:58 volumio volumio[4741]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 14 05:39:58 volumio volumio[4741]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 14 05:39:58 volumio volumio[4741]: info: Streaming services startup Apr 14 05:39:58 volumio volumio[4741]: info: Starting Streaming Daemon Apr 14 05:39:58 volumio sudo[5035]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 14 05:39:58 volumio sudo[5035]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:58 volumio volumio[4741]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 14 05:39:58 volumio sudo[5035]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:58 volumio go-librespot[5024]: time="2026-04-14T05:39:58+01:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:80, retrying with a different AP" error="dial tcp 104.199.65.9:80: connect: connection refused" Apr 14 05:39:58 volumio volumio[4741]: info: Initializing connection to go-librespot Websocket Apr 14 05:39:58 volumio volumio[4741]: error: Cannot start Volumio Streaming Daemon Apr 14 05:39:58 volumio volumio[4741]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 14 05:39:58 volumio volumio[4741]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 14 05:39:58 volumio go-librespot[5024]: time="2026-04-14T05:39:58+01:00" level=debug msg="new websocket client" Apr 14 05:39:58 volumio volumio[4741]: info: Connection to go-librespot Websocket established Apr 14 05:39:58 volumio go-librespot[5024]: time="2026-04-14T05:39:58+01:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Apr 14 05:39:58 volumio go-librespot[5024]: time="2026-04-14T05:39:58+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:58 volumio go-librespot[5024]: time="2026-04-14T05:39:58+01:00" level=debug msg="completed challenge" Apr 14 05:39:58 volumio go-librespot[5024]: time="2026-04-14T05:39:58+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:58 volumio volumio[4741]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 14 05:39:58 volumio volumio[4741]: info: MyVolumio token set successfully Apr 14 05:39:58 volumio volumio[4741]: info: MYVOLUMIO: Adding device Apr 14 05:39:58 volumio volumio[4741]: info: MYVOLUMIO: Evaluating Server Apr 14 05:39:59 volumio go-librespot[5024]: time="2026-04-14T05:39:59+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Apr 14 05:39:59 volumio go-librespot[5024]: time="2026-04-14T05:39:59+01:00" level=debug msg="completed keyexchange" Apr 14 05:39:59 volumio go-librespot[5024]: time="2026-04-14T05:39:59+01:00" level=debug msg="completed challenge" Apr 14 05:39:59 volumio volumio[4741]: info: MyVolumio status changed Apr 14 05:39:59 volumio volumio[4741]: info: Streaming services startup Apr 14 05:39:59 volumio volumio[4741]: info: Starting Streaming Daemon Apr 14 05:39:59 volumio volumio[4741]: info: Removing browser output: myVolumio user plan is not superstar Apr 14 05:39:59 volumio volumio[4741]: info: Removing audio output: Apr 14 05:39:59 volumio volumio[4741]: info: Stoppping Tunnel 1 Apr 14 05:39:59 volumio sudo[5062]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 14 05:39:59 volumio sudo[5062]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:59 volumio sudo[5064]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Apr 14 05:39:59 volumio sudo[5064]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 05:39:59 volumio go-librespot[5024]: time="2026-04-14T05:39:59+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:39:59 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. Apr 14 05:39:59 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. Apr 14 05:39:59 volumio sudo[5062]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:59 volumio volumio[4741]: error: Cannot start Volumio Streaming Daemon Apr 14 05:39:59 volumio volumio[4741]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 14 05:39:59 volumio volumio[4741]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 14 05:39:59 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. Apr 14 05:39:59 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. Apr 14 05:39:59 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. Apr 14 05:39:59 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. Apr 14 05:39:59 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. Apr 14 05:39:59 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. Apr 14 05:39:59 volumio sudo[5064]: pam_unix(sudo:session): session closed for user root Apr 14 05:39:59 volumio volumio[4741]: info: Remote SSH Stopped Apr 14 05:39:59 volumio volumio[4741]: info: Setting Geolocation for MyVolumio to eu3 Apr 14 05:39:59 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:59 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:59 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:39:59 volumio go-librespot[5024]: time="2026-04-14T05:39:59+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 14 05:39:59 volumio volumio[4741]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Apr 14 05:40:00 volumio go-librespot[5024]: time="2026-04-14T05:40:00+01:00" level=debug msg="completed keyexchange" Apr 14 05:40:00 volumio go-librespot[5024]: time="2026-04-14T05:40:00+01:00" level=debug msg="completed challenge" Apr 14 05:40:00 volumio go-librespot[5024]: time="2026-04-14T05:40:00+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:40:00 volumio volumio[4741]: info: Updating MyVolumio device info Apr 14 05:40:00 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:40:00 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:40:00 volumio volumio[4741]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 05:40:00 volumio volumio[4741]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Apr 14 05:40:00 volumio go-librespot[5024]: time="2026-04-14T05:40:00+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 14 05:40:00 volumio go-librespot[5024]: time="2026-04-14T05:40:00+01:00" level=debug msg="completed keyexchange" Apr 14 05:40:00 volumio go-librespot[5024]: time="2026-04-14T05:40:00+01:00" level=debug msg="completed challenge" Apr 14 05:40:00 volumio go-librespot[5024]: time="2026-04-14T05:40:00+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:40:00 volumio go-librespot[5024]: time="2026-04-14T05:40:00+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Apr 14 05:40:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 05:40:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 05:40:00 volumio volumio[4741]: info: Connection to go-librespot Websocket closed Apr 14 05:40:01 volumio volumio[4741]: info: Getting Spotify volume Apr 14 05:40:01 volumio volumio[4741]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 05:40:01 volumio volumio[4741]: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 14 05:40:01 volumio volumio[4741]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Apr 14 05:40:01 volumio volumio[4741]: errno: -111, Apr 14 05:40:01 volumio volumio[4741]: code: 'ECONNREFUSED', Apr 14 05:40:01 volumio volumio[4741]: syscall: 'connect', Apr 14 05:40:01 volumio volumio[4741]: address: '127.0.0.1', Apr 14 05:40:01 volumio volumio[4741]: port: 9879, Apr 14 05:40:01 volumio volumio[4741]: response: undefined Apr 14 05:40:01 volumio volumio[4741]: } Apr 14 05:40:01 volumio volumio[4741]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 05:40:01 volumio sudo[5081]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-14 05:39' Apr 14 05:40:01 volumio sudo[5081]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"