Apr 14 21:12:00 volumio volumio-remote-updater[945]: [2026-04-14 21:12:00] [connect] Successful connection Apr 14 21:12:00 volumio volumio-remote-updater[945]: [2026-04-14 21:12:00] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1776197520 101 Apr 14 21:12:00 volumio volumio[13760]: 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 21:12:00 volumio sudo[13803]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:00 volumio go-librespot[13979]: time="2026-04-14T21:12:00+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 14 21:12:00 volumio go-librespot[13979]: time="2026-04-14T21:12:00+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:00 volumio go-librespot[13979]: time="2026-04-14T21:12:00+01:00" level=debug msg="completed challenge" Apr 14 21:12:00 volumio go-librespot[13979]: time="2026-04-14T21:12:00+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:00 volumio go-librespot[13979]: time="2026-04-14T21:12:00+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 14 21:12:01 volumio go-librespot[13979]: time="2026-04-14T21:12:01+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:01 volumio go-librespot[13979]: time="2026-04-14T21:12:01+01:00" level=debug msg="completed challenge" Apr 14 21:12:01 volumio go-librespot[13979]: time="2026-04-14T21:12:01+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:01 volumio volumio[13760]: info: go-librespot daemon successfully initialized Apr 14 21:12:01 volumio go-librespot[13979]: time="2026-04-14T21:12:01+01:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Apr 14 21:12:01 volumio go-librespot[13979]: time="2026-04-14T21:12:01+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:01 volumio go-librespot[13979]: time="2026-04-14T21:12:01+01:00" level=debug msg="completed challenge" Apr 14 21:12:01 volumio go-librespot[13979]: time="2026-04-14T21:12:01+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:02 volumio go-librespot[13979]: time="2026-04-14T21:12:02+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Apr 14 21:12:02 volumio go-librespot[13979]: time="2026-04-14T21:12:02+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:02 volumio go-librespot[13979]: time="2026-04-14T21:12:02+01:00" level=debug msg="completed challenge" Apr 14 21:12:02 volumio go-librespot[13979]: time="2026-04-14T21:12:02+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:03 volumio go-librespot[13979]: time="2026-04-14T21:12:03+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 14 21:12:03 volumio go-librespot[13979]: time="2026-04-14T21:12:03+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:03 volumio go-librespot[13979]: time="2026-04-14T21:12:03+01:00" level=debug msg="completed challenge" Apr 14 21:12:03 volumio go-librespot[13979]: time="2026-04-14T21:12:03+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:03 volumio go-librespot[13979]: time="2026-04-14T21:12:03+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 21:12:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 21:12:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 21:12:04 volumio volumio[13760]: info: Initializing connection to go-librespot Websocket Apr 14 21:12:04 volumio volumio[13760]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 14 21:12:06 volumio sudo[14032]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 21:12:06 volumio sudo[14032]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:06 volumio sudo[14034]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 21:12:06 volumio sudo[14032]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:06 volumio sudo[14034]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:06 volumio sudo[14034]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:06 volumio sudo[14038]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 14 21:12:06 volumio sudo[14038]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:06 volumio sudo[14038]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:06 volumio volumio[13760]: info: Upmpdcli Daemon Started Apr 14 21:12:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Apr 14 21:12:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 21:12:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 21:12:06 volumio go-librespot[14040]: go-librespot daemon starting... Apr 14 21:12:06 volumio go-librespot[14041]: time="2026-04-14T21:12:06+01:00" level=info msg="running go-librespot 0.6.2" Apr 14 21:12:06 volumio go-librespot[14041]: time="2026-04-14T21:12:06+01:00" level=debug msg="app state loaded" Apr 14 21:12:06 volumio go-librespot[14041]: time="2026-04-14T21:12:06+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 21:12:07 volumio go-librespot[14041]: time="2026-04-14T21:12: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-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 14 21:12:07 volumio go-librespot[14041]: time="2026-04-14T21:12:07+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 21:12:07 volumio go-librespot[14041]: time="2026-04-14T21:12:07+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 21:12:07 volumio go-librespot[14041]: time="2026-04-14T21:12:07+01:00" level=info msg="zeroconf server listening on port 40645" Apr 14 21:12:07 volumio go-librespot[14041]: time="2026-04-14T21:12:07+01:00" level=debug msg="obtained new client token: AABbhHGlgECsAmHmJci2ReeIBBnrjtoxdyKrA8gGsuuIVY+RHSYiez8WokGG3UvhozeL4Ktho8oq4oOurGj0oStleOnkJm8gMOiG7MAG4lB7oTonQexLgj+pNTaFQxT3npKAAhIheTp+QnDi2qPEcULD1gyVFcDdIbiJf9PJNzqz3H8kuOHmUd/fn6n1fxF1KIJA544bKZgJh9rvBrCGLI1KdxH+xbxzUAV2vJSiFX/6qHGUfFRPAus=" Apr 14 21:12:07 volumio go-librespot[14041]: time="2026-04-14T21:12:07+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 14 21:12:07 volumio go-librespot[14041]: time="2026-04-14T21:12:07+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:07 volumio go-librespot[14041]: time="2026-04-14T21:12:07+01:00" level=debug msg="completed challenge" Apr 14 21:12:07 volumio go-librespot[14041]: time="2026-04-14T21:12:07+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 14 21:12:07 volumio volumio[13760]: info: Adding plugin bluetooth to MyMusic Plugins Apr 14 21:12:07 volumio volumio[13760]: info: Adding plugin multiroom to MyMusic Plugins Apr 14 21:12:07 volumio volumio[13760]: info: Adding plugin metavolumio to MyMusic Plugins Apr 14 21:12:07 volumio volumio[13760]: info: Adding plugin cd_controller to MyMusic Plugins Apr 14 21:12:07 volumio volumio[13760]: info: Adding plugin qobuzconnect to MyMusic Plugins Apr 14 21:12:07 volumio volumio[13760]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 14 21:12:07 volumio volumio[13760]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 14 21:12:07 volumio volumio[13760]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:07 volumio volumio[13760]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:07 volumio volumio[13760]: info: Starting MyVolumio Remote Streaming Endpoints Apr 14 21:12:07 volumio volumio[13760]: info: MyVolumio login type: Token Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 14 21:12:07 volumio go-librespot[14041]: time="2026-04-14T21:12:07+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 14 21:12:07 volumio go-librespot[14041]: time="2026-04-14T21:12:07+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:07 volumio go-librespot[14041]: time="2026-04-14T21:12:07+01:00" level=debug msg="completed challenge" Apr 14 21:12:07 volumio go-librespot[14041]: time="2026-04-14T21:12:07+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 14 21:12:07 volumio volumio[13760]: info: Streaming services startup Apr 14 21:12:07 volumio volumio[13760]: info: Starting Streaming Daemon Apr 14 21:12:07 volumio sudo[14051]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 14 21:12:07 volumio sudo[14051]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:07 volumio volumio[13760]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 14 21:12:07 volumio sudo[14051]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:07 volumio volumio[13760]: info: Initializing connection to go-librespot Websocket Apr 14 21:12:07 volumio volumio[13760]: error: Cannot start Volumio Streaming Daemon Apr 14 21:12:07 volumio volumio[13760]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 14 21:12:07 volumio volumio[13760]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 14 21:12:07 volumio go-librespot[14041]: time="2026-04-14T21:12:07+01:00" level=debug msg="new websocket client" Apr 14 21:12:07 volumio volumio[13760]: info: Connection to go-librespot Websocket established Apr 14 21:12:08 volumio go-librespot[14041]: time="2026-04-14T21:12:08+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 21:12:08 volumio go-librespot[14041]: time="2026-04-14T21:12:08+01:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Apr 14 21:12:08 volumio volumio[13760]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 14 21:12:08 volumio go-librespot[14041]: time="2026-04-14T21:12:08+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:08 volumio go-librespot[14041]: time="2026-04-14T21:12:08+01:00" level=debug msg="completed challenge" Apr 14 21:12:08 volumio go-librespot[14041]: time="2026-04-14T21:12:08+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:08 volumio volumio[13760]: info: MyVolumio token set successfully Apr 14 21:12:08 volumio volumio[13760]: info: MYVOLUMIO: Adding device Apr 14 21:12:08 volumio volumio[13760]: info: MYVOLUMIO: Evaluating Server Apr 14 21:12:09 volumio volumio[13760]: info: MyVolumio status changed Apr 14 21:12:09 volumio volumio[13760]: info: Streaming services startup Apr 14 21:12:09 volumio volumio[13760]: info: Starting Streaming Daemon Apr 14 21:12:09 volumio volumio[13760]: info: Removing browser output: myVolumio user plan is not superstar Apr 14 21:12:09 volumio volumio[13760]: info: Removing audio output: Apr 14 21:12:09 volumio volumio[13760]: info: Stoppping Tunnel 1 Apr 14 21:12:09 volumio sudo[14078]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 14 21:12:09 volumio sudo[14078]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:09 volumio sudo[14080]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Apr 14 21:12:09 volumio sudo[14080]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:09 volumio sudo[14078]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:09 volumio volumio[13760]: error: Cannot start Volumio Streaming Daemon Apr 14 21:12:09 volumio volumio[13760]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 14 21:12:09 volumio volumio[13760]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 14 21:12: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 21:12: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 21:12: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 21:12: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 21:12: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 21:12: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 21:12: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 21:12: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 21:12:09 volumio sudo[14080]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:09 volumio volumio[13760]: info: Remote SSH Stopped Apr 14 21:12:09 volumio go-librespot[14041]: time="2026-04-14T21:12:09+01:00" level=debug msg="connected to ap-gue1.spotify.com:443" Apr 14 21:12:09 volumio volumio[13760]: info: Setting Geolocation for MyVolumio to eu3 Apr 14 21:12:09 volumio volumio[13760]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:09 volumio volumio[13760]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:09 volumio volumio[13760]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:09 volumio go-librespot[14041]: time="2026-04-14T21:12:09+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:09 volumio go-librespot[14041]: time="2026-04-14T21:12:09+01:00" level=debug msg="completed challenge" Apr 14 21:12:09 volumio go-librespot[14041]: time="2026-04-14T21:12:09+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:09 volumio volumio[13760]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Apr 14 21:12:10 volumio go-librespot[14041]: time="2026-04-14T21:12:10+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 14 21:12:10 volumio volumio[13760]: info: Updating MyVolumio device info Apr 14 21:12:10 volumio volumio[13760]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:10 volumio volumio[13760]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:10 volumio volumio[13760]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:10 volumio go-librespot[14041]: time="2026-04-14T21:12:10+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:10 volumio go-librespot[14041]: time="2026-04-14T21:12:10+01:00" level=debug msg="completed challenge" Apr 14 21:12:10 volumio go-librespot[14041]: time="2026-04-14T21:12:10+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:10 volumio volumio[13760]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Apr 14 21:12:10 volumio volumio[13760]: info: Getting Spotify volume Apr 14 21:12:10 volumio volumio[13760]: 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 21:12:10 volumio volumio[13760]: info: CoreCommandRouter::volumioGetState Apr 14 21:12:10 volumio volumio[13760]: info: CorePlayQueue::getTrack 0 Apr 14 21:12:10 volumio volumio[13760]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Apr 14 21:12:10 volumio volumio[13760]: SPOTIFY: SPOTIFY VOLUME undefined Apr 14 21:12:10 volumio volumio[13760]: SPOTIFY: VOLUMIO VOLUME 0 Apr 14 21:12:10 volumio volumio[13760]: info: Aligning Spotify Volume to Volumio Volume Apr 14 21:12:10 volumio volumio[13760]: info: CoreCommandRouter::volumioGetState Apr 14 21:12:10 volumio volumio[13760]: info: CorePlayQueue::getTrack 0 Apr 14 21:12:10 volumio volumio[13760]: info: Setting Spotify Volume from Volumio: 0 Apr 14 21:12:11 volumio go-librespot[14041]: time="2026-04-14T21:12:11+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 14 21:12:11 volumio go-librespot[14041]: time="2026-04-14T21:12:11+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:11 volumio go-librespot[14041]: time="2026-04-14T21:12:11+01:00" level=debug msg="completed challenge" Apr 14 21:12:11 volumio go-librespot[14041]: time="2026-04-14T21:12:11+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:11 volumio go-librespot[14041]: time="2026-04-14T21:12: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 21:12:11 volumio volumio[13760]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 21:12:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 21:12:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 21:12:11 volumio volumio[13760]: Error: socket hang up Apr 14 21:12:11 volumio volumio[13760]: at connResetException (node:internal/errors:720:14) Apr 14 21:12:11 volumio volumio[13760]: at Socket.socketOnEnd (node:_http_client:519:23) Apr 14 21:12:11 volumio volumio[13760]: at Socket.emit (node:events:526:35) Apr 14 21:12:11 volumio volumio[13760]: at endReadableNT (node:internal/streams/readable:1376:12) Apr 14 21:12:11 volumio volumio[13760]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Apr 14 21:12:11 volumio volumio[13760]: code: 'ECONNRESET', Apr 14 21:12:11 volumio volumio[13760]: response: undefined Apr 14 21:12:11 volumio volumio[13760]: } Apr 14 21:12:11 volumio volumio[13760]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 21:12:11 volumio sudo[14098]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-14 21:11' Apr 14 21:12:11 volumio sudo[14098]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:11 volumio sudo[14098]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:11 volumio volumio-remote-updater[945]: [2026-04-14 21:12:11] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Apr 14 21:12:11 volumio volumio-remote-updater[945]: [2026-04-14 21:12:11] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Apr 14 21:12:11 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Apr 14 21:12:11 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Apr 14 21:12:11 volumio systemd[1]: volumio.service: Consumed 8.913s CPU time. Apr 14 21:12:11 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 14 21:12:11 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 14 21:12:11 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 121132. Apr 14 21:12:11 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 14 21:12:11 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Apr 14 21:12:11 volumio systemd[1]: volumio.service: Consumed 8.913s CPU time. Apr 14 21:12:11 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Apr 14 21:12:11 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 14 21:12:12 volumio volumio[14112]: info: ------------------------------------------- Apr 14 21:12:12 volumio volumio[14112]: info: ----- Volumio3 ---- Apr 14 21:12:12 volumio volumio[14112]: info: ------------------------------------------- Apr 14 21:12:12 volumio volumio[14112]: info: ----- System startup ---- Apr 14 21:12:12 volumio volumio[14112]: info: ------------------------------------------- Apr 14 21:12:12 volumio volumio[14112]: info: MYVOLUMIO Environment detected Apr 14 21:12:12 volumio volumio[14112]: info: Plugin folders cleanup Apr 14 21:12:12 volumio volumio[14112]: info: Scanning into folder /volumio/app/plugins/ Apr 14 21:12:12 volumio volumio[14112]: info: Scanning category audio_interface Apr 14 21:12:12 volumio volumio[14112]: info: Scanning category miscellanea Apr 14 21:12:12 volumio volumio[14112]: info: Scanning category music_service Apr 14 21:12:12 volumio volumio[14112]: info: Scanning category plugins.json Apr 14 21:12:12 volumio volumio[14112]: info: Scanning category system_controller Apr 14 21:12:12 volumio volumio[14112]: info: Scanning category user_interface Apr 14 21:12:12 volumio volumio[14112]: info: Scanning into folder /data/plugins/ Apr 14 21:12:12 volumio volumio[14112]: info: Scanning category music_service Apr 14 21:12:12 volumio volumio[14112]: info: Plugin folders cleanup completed Apr 14 21:12:12 volumio volumio[14112]: info: ------------------------------------------- Apr 14 21:12:12 volumio volumio[14112]: info: ----- Core plugins startup ---- Apr 14 21:12:12 volumio volumio[14112]: info: ------------------------------------------- Apr 14 21:12:12 volumio volumio[14112]: info: Loading plugins from folder /volumio/app/plugins/ Apr 14 21:12:12 volumio volumio[14112]: info: Adding plugin upnp to MyMusic Plugins Apr 14 21:12:12 volumio volumio[14112]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 14 21:12:12 volumio volumio[14112]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 14 21:12:12 volumio volumio[14112]: info: Loading plugins from folder /data/plugins/ Apr 14 21:12:12 volumio volumio[14112]: info: Adding plugin rtlsdr_radio to MyMusic Plugins Apr 14 21:12:12 volumio volumio[14112]: info: Loading plugin "system"... Apr 14 21:12:12 volumio volumio[14112]: info: Loading plugin "appearance"... Apr 14 21:12:13 volumio volumio[14112]: info: Loading plugin "network"... Apr 14 21:12:13 volumio volumio[14112]: info: Refreshing Cached IP Addresses Apr 14 21:12:13 volumio sudo[14140]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 21:12:13 volumio sudo[14140]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:13 volumio sudo[14142]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 21:12:13 volumio sudo[14142]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:13 volumio sudo[14142]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:13 volumio sudo[14140]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:13 volumio volumio[14112]: info: Loading plugin "services"... Apr 14 21:12:13 volumio volumio[14112]: info: Loading plugin "alsa_controller"... Apr 14 21:12:13 volumio sudo[14146]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 14 21:12:13 volumio sudo[14146]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:13 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 21:12:13 volumio volumio[14112]: info: Loading plugin "wizard"... Apr 14 21:12:13 volumio volumio[14112]: info: Loading plugin "networkfs"... Apr 14 21:12:13 volumio volumio[14112]: info: Starting Udev Watcher for removable devices Apr 14 21:12:13 volumio volumio[14112]: info: Mounting Device 0ACB-A1DE Apr 14 21:12:13 volumio sudo[14179]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/0ACB-A1DE -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Apr 14 21:12:13 volumio sudo[14179]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:13 volumio sudo[14179]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:13 volumio volumio[14112]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Apr 14 21:12:13 volumio volumio[14112]: dmesg(1) may have more information after failed mount system call. Apr 14 21:12:13 volumio volumio[14112]: 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 21:12:13 volumio volumio[14112]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Apr 14 21:12:13 volumio volumio[14112]: dmesg(1) may have more information after failed mount system call. Apr 14 21:12:13 volumio volumio[14112]: info: Ignoring mount for partition: boot Apr 14 21:12:13 volumio volumio[14112]: info: Ignoring mount for partition: volumio Apr 14 21:12:13 volumio volumio[14112]: info: Ignoring mount for partition: volumio_data Apr 14 21:12:13 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 21:12:13 volumio volumio[14112]: info: Loading plugin "volumio_command_line_client"... Apr 14 21:12:13 volumio volumio[14112]: info: Loading plugin "upnp"... Apr 14 21:12:13 volumio volumio[14112]: info: [1776197533121] Starting Upmpd Daemon Apr 14 21:12:13 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 21:12:13 volumio volumio[14112]: info: Loading plugin "my_music"... Apr 14 21:12:13 volumio volumio[14112]: info: Loading plugin "mpd"... Apr 14 21:12:13 volumio volumio[14112]: info: Loading plugin "upnp_browser"... Apr 14 21:12:13 volumio volumio[14112]: info: Starting UPNP Browser Apr 14 21:12:13 volumio volumio[14112]: info: Loading plugin "alarm-clock"... Apr 14 21:12:13 volumio volumio[14112]: info: Loading plugin "airplay_emulation"... Apr 14 21:12:13 volumio volumio[14112]: info: Starting Shairport Sync Apr 14 21:12:13 volumio volumio[14112]: info: Loading plugin "last_100"... Apr 14 21:12:13 volumio volumio[14112]: info: Loading plugin "webradio"... Apr 14 21:12:13 volumio volumio[14112]: info: Loading plugin "i2s_dacs"... Apr 14 21:12:13 volumio volumio[14112]: info: Loading plugin "volumiodiscovery"... Apr 14 21:12:13 volumio volumio[14112]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 14 21:12:13 volumio volumio[14112]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 21:12:13 volumio volumio[14112]: *** WARNING *** For more information see Apr 14 21:12:13 volumio volumio[14112]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 14 21:12:13 volumio volumio[14112]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 21:12:13 volumio volumio[14112]: *** WARNING *** For more information see Apr 14 21:12:13 volumio node[14112]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 14 21:12:13 volumio node[14112]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 21:12:13 volumio node[14112]: *** WARNING *** For more information see Apr 14 21:12:13 volumio node[14112]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 14 21:12:13 volumio node[14112]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 21:12:13 volumio node[14112]: *** WARNING *** For more information see Apr 14 21:12:13 volumio volumio[14112]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 14 21:12:13 volumio volumio[14112]: info: Discovery: Started advertising with name: Volumio Apr 14 21:12:13 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 21:12:13 volumio volumio[14112]: info: Loading plugin "spop"... Apr 14 21:12:14 volumio volumio[14112]: info: Loading plugin "ytmusic"... Apr 14 21:12:14 volumio volumio[14112]: info: Loading plugin "outputs"... Apr 14 21:12:14 volumio volumio[14112]: info: Loading plugin "albumart"... Apr 14 21:12:14 volumio volumio[14112]: info: Plugin example_plugin is not enabled Apr 14 21:12:14 volumio volumio[14112]: info: Loading plugin "inputs"... Apr 14 21:12:14 volumio volumio[14112]: info: Loading plugin "updater_comm"... Apr 14 21:12:14 volumio volumio[14112]: info: Plugin mpdemulation is not enabled Apr 14 21:12:14 volumio volumio[14112]: info: Loading plugin "rest_api"... Apr 14 21:12:14 volumio volumio[14112]: info: Loading plugin "websocket"... Apr 14 21:12:14 volumio volumio[14112]: info: Starting Socket.io Server version 1.7.4 Apr 14 21:12:14 volumio volumio[14112]: info: Loading plugin "podcast"... Apr 14 21:12:14 volumio volumio[14112]: info: ControllerPodcast::constructor Apr 14 21:12:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Apr 14 21:12:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 21:12:14 volumio volumio[14112]: info: Loading plugin "rtlsdr_radio"... Apr 14 21:12:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 21:12:14 volumio go-librespot[14193]: go-librespot daemon starting... Apr 14 21:12:14 volumio go-librespot[14194]: time="2026-04-14T21:12:14+01:00" level=info msg="running go-librespot 0.6.2" Apr 14 21:12:14 volumio volumio[14183]: Forking 3 albumart workers Apr 14 21:12:14 volumio go-librespot[14194]: time="2026-04-14T21:12:14+01:00" level=debug msg="app state loaded" Apr 14 21:12:14 volumio go-librespot[14194]: time="2026-04-14T21:12:14+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 21:12:14 volumio volumio[14112]: info: Loading i18n strings for locale en Apr 14 21:12:14 volumio volumio[14112]: Updating browse sources language Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::initPlayerControls Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 21:12:14 volumio volumio[14112]: Express server listening on port 3000 Apr 14 21:12:14 volumio volumio[14112]: [Metrics] WebUI: 2s 347.60ms Apr 14 21:12:14 volumio volumio[14112]: info: CoreStateMachine::resetVolumioState Apr 14 21:12:14 volumio volumio[14112]: info: CoreStateMachine::getcurrentVolume Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::volumioRetrievevolume Apr 14 21:12:14 volumio volumio[14112]: info: Volumio Network Manager: Network status updated: 2 Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:14 volumio volumio[14112]: info: Reloading queue from file Apr 14 21:12:14 volumio volumio[14112]: info: VolumeController:: Volume=36 Mute =true Apr 14 21:12:14 volumio volumio[14112]: info: CoreStateMachine::pushState Apr 14 21:12:14 volumio volumio[14112]: info: CorePlayQueue::getTrack 0 Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::volumioPushState Apr 14 21:12:14 volumio volumio[14112]: info: CoreStateMachine::updateTrackBlock Apr 14 21:12:14 volumio volumio[14112]: info: CorePlayQueue::getTrackBlock Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::volumioRetrievevolume Apr 14 21:12:14 volumio volumio[14112]: info: CoreStateMachine::setRepeat null single undefined Apr 14 21:12:14 volumio volumio[14112]: info: CoreStateMachine::pushState Apr 14 21:12:14 volumio volumio[14112]: info: CorePlayQueue::getTrack 0 Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::volumioPushState Apr 14 21:12:14 volumio volumio[14112]: info: CoreStateMachine::setRandom true Apr 14 21:12:14 volumio volumio[14112]: info: CoreStateMachine::pushState Apr 14 21:12:14 volumio volumio[14112]: info: CorePlayQueue::getTrack 0 Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::volumioPushState Apr 14 21:12:14 volumio volumio[14112]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Apr 14 21:12:14 volumio volumio[14112]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04170 Apr 14 21:12:14 volumio volumio[14112]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Apr 14 21:12:14 volumio volumio[14112]: info: Setting Device type: Raspberry PI Apr 14 21:12:14 volumio volumio[14112]: info: Completed loading Core Plugins Apr 14 21:12:14 volumio volumio[14112]: info: Preparing to generate the ALSA configuration file Apr 14 21:12:14 volumio go-librespot[14194]: time="2026-04-14T21:12: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 14 21:12:14 volumio go-librespot[14194]: time="2026-04-14T21:12:14+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 21:12:14 volumio go-librespot[14194]: time="2026-04-14T21:12:14+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 21:12:14 volumio volumio[14201]: Starting albumart workers Apr 14 21:12:14 volumio go-librespot[14194]: time="2026-04-14T21:12:14+01:00" level=info msg="zeroconf server listening on port 43449" Apr 14 21:12:14 volumio volumio[14112]: info: Asound.conf file unchanged, so no further update is needed Apr 14 21:12:14 volumio volumio[14112]: info: Output device has changed, restarting MPD Apr 14 21:12:14 volumio volumio[14112]: info: Output device has changed, restarting Shairport Sync Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:14 volumio volumio[14112]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 21:12:14 volumio volumio[14112]: info: ___________ START PLUGINS ___________ Apr 14 21:12:14 volumio volumio[14202]: Starting albumart workers Apr 14 21:12:14 volumio volumio[14112]: info: ControllerMpd::onStart: Initializing MPD Apr 14 21:12:14 volumio sudo[14251]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 14 21:12:14 volumio sudo[14251]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:14 volumio volumio[14112]: info: Creating MPD Configuration file Apr 14 21:12:14 volumio sudo[14250]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 14 21:12:14 volumio sudo[14250]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:14 volumio sudo[14250]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 21:12:14 volumio sudo[14258]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 14 21:12:14 volumio sudo[14258]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 21:12:14 volumio volumio[14112]: info: [1776197534914] CoreMusicLibrary::Adding element Media Servers Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 21:12:14 volumio sudo[14258]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:14 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 14 21:12:14 volumio volumio[14112]: info: UPNP Browser: Client initialized successfully Apr 14 21:12:14 volumio sudo[14261]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 14 21:12:14 volumio sudo[14261]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:14 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 14 21:12:14 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 14 21:12:14 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 14 21:12:14 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 14 21:12:14 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 14 21:12:14 volumio volumio[14112]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:14 volumio volumio[14112]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 21:12:14 volumio volumio[14112]: info: [1776197534964] CoreMusicLibrary::Adding element Last_100 Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 21:12:14 volumio volumio[14112]: info: [1776197534971] CoreMusicLibrary::Adding element Webradio Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 21:12:14 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 14 21:12:14 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 21:12:14 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 14 21:12:14 volumio volumio[14112]: info: Initializing BBC Radios Apr 14 21:12:14 volumio volumio[14200]: Starting albumart workers Apr 14 21:12:14 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 14 21:12:15 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 14 21:12:15 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 14 21:12:15 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 14 21:12:15 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 14 21:12:15 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 14 21:12:15 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 14 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:15 volumio volumio[14112]: info: Creating Spotify config file Apr 14 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:15 volumio sudo[14283]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 14 21:12:15 volumio sudo[14283]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 14 21:12:15 volumio sudo[14283]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 21:12:15 volumio volumio[14112]: info: [1776197535180] CoreMusicLibrary::Adding element YouTube Music Apr 14 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 21:12:15 volumio volumio[14112]: Cannot find translation for source YouTube Music Apr 14 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 21:12:15 volumio volumio[14112]: info: [1776197535184] CoreMusicLibrary::Adding element Podcast Apr 14 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 21:12:15 volumio volumio[14112]: Cannot find translation for source YouTube Music Apr 14 21:12:15 volumio volumio[14112]: Cannot find translation for source Podcast Apr 14 21:12:15 volumio volumio[14112]: info: [RTL-SDR Radio] Starting plugin Apr 14 21:12:15 volumio go-librespot[14194]: time="2026-04-14T21:12:15+01:00" level=debug msg="obtained new client token: AAC8rCuyZ7sKm5u1Rlu9Cy259H9ZJXxcfIa9M2XtxpYIITfcxUzkOyYeP++3Hgf2DEc2zDPFNvGO/wI8DswQH1W8LlK0Cmqu1MJKkSFaMRE5rm3nNckuroXJYoUuI5+xIS3hGR1AEjIGL/2wloWxU7JEYQ5eBHDsTQ4gWRefDUZ0CqNX8wqSEhAof6DQDMT5Un6D+qiTzOMOvynx7y/Pstn46+5yHWX/0uQyrINbMywgMwocDU36ZC4=" Apr 14 21:12:15 volumio volumio[14112]: info: [RTL-SDR Radio] Loaded i18n strings for language: en Apr 14 21:12:15 volumio volumio[14112]: info: Volumio Calling Home Apr 14 21:12:15 volumio volumio[14112]: info: [RTL-SDR Radio] snd-aloop already loaded Apr 14 21:12:15 volumio volumio[14112]: info: [RTL-SDR Radio] No stations database found, creating v2 Apr 14 21:12:15 volumio volumio[14112]: info: [RTL-SDR Radio] Database loaded at: 2026-04-14T20:12:15.245Z Apr 14 21:12:15 volumio volumio[14112]: info: [RTL-SDR Radio] Loading blocklist from: /data/plugins/music_service/rtlsdr_radio/blocklist.json Apr 14 21:12:15 volumio volumio[14112]: info: [RTL-SDR Radio] Got 21 phrases from file Apr 14 21:12:15 volumio volumio[14112]: info: [RTL-SDR Radio] Updated metadata blocklist Apr 14 21:12:15 volumio volumio[14112]: info: [RTL-SDR Radio] Metadata module now has 21 phrases Apr 14 21:12:15 volumio volumio[14112]: info: [RTL-SDR Radio] Management server started on port 3456 Apr 14 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 21:12:15 volumio volumio[14112]: info: [1776197535284] CoreMusicLibrary::Adding element FM/DAB Radio Apr 14 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 21:12:15 volumio volumio[14112]: Cannot find translation for source YouTube Music Apr 14 21:12:15 volumio volumio[14112]: Cannot find translation for source Podcast Apr 14 21:12:15 volumio volumio[14112]: Cannot find translation for source FM/DAB Radio Apr 14 21:12:15 volumio volumio[14112]: info: [RTL-SDR Radio] Plugin started successfully Apr 14 21:12:15 volumio volumio[14112]: info: Discovery: adding 072f109f-54a2-4344-b8c4-538b45da7e51 Apr 14 21:12:15 volumio volumio[14112]: info: Discovery: Found device Volumio Apr 14 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::volumioGetState Apr 14 21:12:15 volumio volumio[14112]: info: CorePlayQueue::getTrack 0 Apr 14 21:12:15 volumio volumio[14112]: info: Discovery: this is already registered, 072f109f-54a2-4344-b8c4-538b45da7e51 Apr 14 21:12:15 volumio volumio[14112]: info: Discovery: Found device Volumio Apr 14 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::volumioGetState Apr 14 21:12:15 volumio volumio[14112]: info: CorePlayQueue::getTrack 0 Apr 14 21:12:15 volumio volumio[14112]: info: MPD Permissions set Apr 14 21:12:15 volumio volumio[14112]: info: MPD Permissions set Apr 14 21:12:15 volumio volumio[14112]: info: VolumeController:: Volume=36 Mute =true Apr 14 21:12:15 volumio volumio[14112]: info: CoreStateMachine::pushState Apr 14 21:12:15 volumio volumio[14112]: info: CorePlayQueue::getTrack 0 Apr 14 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::volumioPushState Apr 14 21:12:15 volumio volumio[14112]: info: Spotify config file written Apr 14 21:12:15 volumio sudo[14317]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 14 21:12:15 volumio sudo[14317]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:15 volumio volumio[14112]: 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 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:15 volumio go-librespot[14194]: time="2026-04-14T21:12:15+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 21:12:15 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Apr 14 21:12:15 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Apr 14 21:12:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:15 volumio volumio[14112]: info: No need to fix Spotify hosts Apr 14 21:12:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 21:12:15 volumio go-librespot[14324]: go-librespot daemon starting... Apr 14 21:12:15 volumio sudo[14317]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:15 volumio volumio[14112]: info: Starting Shairport Sync Apr 14 21:12:15 volumio volumio[14112]: info: Starting Shairport Sync Apr 14 21:12:15 volumio go-librespot[14330]: time="2026-04-14T21:12:15+01:00" level=info msg="running go-librespot 0.6.2" Apr 14 21:12:15 volumio go-librespot[14330]: time="2026-04-14T21:12:15+01:00" level=debug msg="app state loaded" Apr 14 21:12:15 volumio volumio[14112]: info: Starting Shairport Sync Apr 14 21:12:15 volumio go-librespot[14330]: time="2026-04-14T21:12:15+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 21:12:15 volumio sudo[14337]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 21:12:15 volumio sudo[14337]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:15 volumio sudo[14341]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 21:12:15 volumio sudo[14341]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:15 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 14 21:12:15 volumio sudo[14339]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 21:12:15 volumio sudo[14339]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:15 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 14 21:12:15 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 21:12:15 volumio systemd[1]: shairport-sync.service: Consumed 1.544s CPU time. Apr 14 21:12:15 volumio volumio[14112]: info: CoreCommandRouter::volumioGetState Apr 14 21:12:15 volumio volumio[14112]: info: CorePlayQueue::getTrack 0 Apr 14 21:12:15 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 21:12:15 volumio sudo[14337]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:15 volumio volumio[14112]: info: Shairport-Sync Started Apr 14 21:12:15 volumio volumio[14112]: Error adding Membership: Error: addMembership EINVAL Apr 14 21:12:15 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 14 21:12:15 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 14 21:12:15 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 21:12:15 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 21:12:15 volumio sudo[14341]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:15 volumio volumio[14112]: info: Shairport-Sync Started Apr 14 21:12:15 volumio sudo[14339]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:15 volumio volumio[14112]: info: Shairport-Sync Started Apr 14 21:12:15 volumio volumio[14112]: info: Volumio called home Apr 14 21:12:15 volumio mpd[14290]: 2026-04-14T21:12:15 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 14 21:12:15 volumio systemd[1]: Started mpd.service - Music Player Daemon. Apr 14 21:12:15 volumio sudo[14261]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:15 volumio sudo[14251]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:15 volumio volumio[14112]: info: Completed starting Core Plugins Apr 14 21:12:15 volumio volumio[14112]: info: ------------------------------------------- Apr 14 21:12:15 volumio volumio[14112]: info: ----- MyVolumio plugins startup ---- Apr 14 21:12:15 volumio volumio[14112]: info: ------------------------------------------- Apr 14 21:12:15 volumio volumio[14112]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 14 21:12:15 volumio go-librespot[14330]: time="2026-04-14T21:12: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 14 21:12:15 volumio go-librespot[14330]: time="2026-04-14T21:12:15+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 21:12:15 volumio go-librespot[14330]: time="2026-04-14T21:12:15+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 21:12:15 volumio volumio[14112]: error: MPD error: The expression evaluated to a falsy value: Apr 14 21:12:15 volumio volumio[14112]: assert.ok(self.idling) Apr 14 21:12:15 volumio volumio[14112]: error: The expression evaluated to a falsy value: Apr 14 21:12:15 volumio volumio[14112]: assert.ok(self.idling) Apr 14 21:12:15 volumio go-librespot[14330]: time="2026-04-14T21:12:15+01:00" level=info msg="zeroconf server listening on port 39453" Apr 14 21:12:15 volumio volumio[14112]: info: MPD running with PID14290 Apr 14 21:12:15 volumio volumio[14112]: ,establishing connection Apr 14 21:12:15 volumio volumio[14112]: error: updateQueue error: null Apr 14 21:12:15 volumio volumio[14112]: info: An error occurred while refreshing Spotify Token Error: Bad Request Apr 14 21:12:15 volumio volumio[14112]: error: updateQueue error: null Apr 14 21:12:16 volumio go-librespot[14330]: time="2026-04-14T21:12:16+01:00" level=debug msg="obtained new client token: AABoQuYZhAgzp+be+fAVlqB2kbtWy9rvKZJIeBImFbjZDs2NAwDLbgLm9LpsT+prqxZUYWC4KyXN+mExX1T78lK/efgdaEnqAFlDiCv7e4ZXBrNl2nNa8IsSNDjJGpMYFODbt2O6DDHfo44vofMkvFhvwiKzMtV7egFlgwSqIx5ZaIeR130bXwBxgy83FpMJWfRplNE4RY3Ekt+T60d1LC/MyjxkeDoVR7CTygpDb0+iX9AGcmsoVJw=" Apr 14 21:12:16 volumio go-librespot[14330]: time="2026-04-14T21:12:16+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 14 21:12:16 volumio go-librespot[14330]: time="2026-04-14T21:12:16+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:16 volumio go-librespot[14330]: time="2026-04-14T21:12:16+01:00" level=debug msg="completed challenge" Apr 14 21:12:16 volumio go-librespot[14330]: time="2026-04-14T21:12:16+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:16 volumio volumio-remote-updater[945]: [2026-04-14 21:12:16] [connect] Successful connection Apr 14 21:12:16 volumio volumio-remote-updater[945]: [2026-04-14 21:12:16] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1776197536 101 Apr 14 21:12:16 volumio volumio[14112]: 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 21:12:16 volumio sudo[14146]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:17 volumio go-librespot[14330]: time="2026-04-14T21:12:17+01:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.65.9:443: connect: connection refused" Apr 14 21:12:17 volumio go-librespot[14330]: time="2026-04-14T21:12:17+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 14 21:12:17 volumio go-librespot[14330]: time="2026-04-14T21:12:17+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:17 volumio go-librespot[14330]: time="2026-04-14T21:12:17+01:00" level=debug msg="completed challenge" Apr 14 21:12:17 volumio go-librespot[14330]: time="2026-04-14T21:12:17+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:17 volumio go-librespot[14330]: time="2026-04-14T21:12:17+01:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Apr 14 21:12:17 volumio go-librespot[14330]: time="2026-04-14T21:12:17+01:00" level=debug msg="connected to ap-gue1.spotify.com:443" Apr 14 21:12:18 volumio go-librespot[14330]: time="2026-04-14T21:12:18+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:18 volumio go-librespot[14330]: time="2026-04-14T21:12:18+01:00" level=debug msg="completed challenge" Apr 14 21:12:18 volumio go-librespot[14330]: time="2026-04-14T21:12:18+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:18 volumio volumio[14112]: info: go-librespot daemon successfully initialized Apr 14 21:12:18 volumio go-librespot[14330]: time="2026-04-14T21:12:18+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 14 21:12:19 volumio go-librespot[14330]: time="2026-04-14T21:12:19+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:19 volumio go-librespot[14330]: time="2026-04-14T21:12:19+01:00" level=debug msg="completed challenge" Apr 14 21:12:19 volumio go-librespot[14330]: time="2026-04-14T21:12:19+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:19 volumio go-librespot[14330]: time="2026-04-14T21:12:19+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 14 21:12:19 volumio go-librespot[14330]: time="2026-04-14T21:12:19+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:19 volumio go-librespot[14330]: time="2026-04-14T21:12:19+01:00" level=debug msg="completed challenge" Apr 14 21:12:19 volumio go-librespot[14330]: time="2026-04-14T21:12:19+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:20 volumio go-librespot[14330]: time="2026-04-14T21:12:20+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 14 21:12:20 volumio go-librespot[14330]: time="2026-04-14T21:12:20+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:20 volumio go-librespot[14330]: time="2026-04-14T21:12:20+01:00" level=debug msg="completed challenge" Apr 14 21:12:20 volumio go-librespot[14330]: time="2026-04-14T21:12:20+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:20 volumio go-librespot[14330]: time="2026-04-14T21:12: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 21:12:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 21:12:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 21:12:21 volumio volumio[14112]: info: Initializing connection to go-librespot Websocket Apr 14 21:12:21 volumio volumio[14112]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 14 21:12:23 volumio sudo[14384]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 21:12:23 volumio sudo[14384]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:23 volumio sudo[14386]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 21:12:23 volumio sudo[14384]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:23 volumio sudo[14386]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:23 volumio sudo[14386]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:23 volumio sudo[14390]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 14 21:12:23 volumio sudo[14390]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:23 volumio sudo[14390]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:23 volumio volumio[14112]: info: Upmpdcli Daemon Started Apr 14 21:12:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Apr 14 21:12:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 21:12:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 21:12:23 volumio go-librespot[14392]: go-librespot daemon starting... Apr 14 21:12:23 volumio go-librespot[14393]: time="2026-04-14T21:12:23+01:00" level=info msg="running go-librespot 0.6.2" Apr 14 21:12:23 volumio go-librespot[14393]: time="2026-04-14T21:12:23+01:00" level=debug msg="app state loaded" Apr 14 21:12:23 volumio go-librespot[14393]: time="2026-04-14T21:12:23+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 21:12:23 volumio go-librespot[14393]: time="2026-04-14T21:12:23+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 21:12:23 volumio go-librespot[14393]: time="2026-04-14T21:12:23+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 21:12:23 volumio go-librespot[14393]: time="2026-04-14T21:12:23+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 21:12:23 volumio go-librespot[14393]: time="2026-04-14T21:12:23+01:00" level=info msg="zeroconf server listening on port 42207" Apr 14 21:12:23 volumio go-librespot[14393]: time="2026-04-14T21:12:23+01:00" level=debug msg="obtained new client token: AACwg/rDc2/iMbYVQ9zieYT145Q6EQS55xnfaQJNax957AXsy5JXa9Ob3fQBE1YtMxcYEYI0RwabcaRaIQsleX/Ue/mxR6p3uvZYamDYGJ2CBC2pm2605rB3vdacjMWh813gJ5EJFm7uU4GiqtZciPJDyu9qJnvV/jnIyMonK3B6DDTfuDnGl+rMKnRcdv5GBf6A3WcVt+fMHQi3rZ8OETjZSuuzR2rmYB9ZnSgfNp9ozsx2Y8la+ArrRQ==" Apr 14 21:12:23 volumio go-librespot[14393]: time="2026-04-14T21:12:23+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 14 21:12:23 volumio go-librespot[14393]: time="2026-04-14T21:12:23+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:23 volumio go-librespot[14393]: time="2026-04-14T21:12:23+01:00" level=debug msg="completed challenge" Apr 14 21:12:23 volumio go-librespot[14393]: time="2026-04-14T21:12:23+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 14 21:12:24 volumio volumio[14112]: info: Adding plugin bluetooth to MyMusic Plugins Apr 14 21:12:24 volumio volumio[14112]: info: Adding plugin multiroom to MyMusic Plugins Apr 14 21:12:24 volumio volumio[14112]: info: Adding plugin metavolumio to MyMusic Plugins Apr 14 21:12:24 volumio volumio[14112]: info: Adding plugin cd_controller to MyMusic Plugins Apr 14 21:12:24 volumio volumio[14112]: info: Adding plugin qobuzconnect to MyMusic Plugins Apr 14 21:12:24 volumio volumio[14112]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 14 21:12:24 volumio volumio[14112]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 14 21:12:24 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:24 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:24 volumio volumio[14112]: info: Starting MyVolumio Remote Streaming Endpoints Apr 14 21:12:24 volumio volumio[14112]: info: MyVolumio login type: Token Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 14 21:12:24 volumio go-librespot[14393]: time="2026-04-14T21:12:24+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 14 21:12:24 volumio go-librespot[14393]: time="2026-04-14T21:12:24+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:24 volumio go-librespot[14393]: time="2026-04-14T21:12:24+01:00" level=debug msg="completed challenge" Apr 14 21:12:24 volumio go-librespot[14393]: time="2026-04-14T21:12:24+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 14 21:12:24 volumio volumio[14112]: info: Streaming services startup Apr 14 21:12:24 volumio volumio[14112]: info: Starting Streaming Daemon Apr 14 21:12:24 volumio sudo[14403]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 14 21:12:24 volumio sudo[14403]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:24 volumio volumio[14112]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 14 21:12:24 volumio sudo[14403]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:24 volumio volumio[14112]: info: Initializing connection to go-librespot Websocket Apr 14 21:12:24 volumio volumio[14112]: error: Cannot start Volumio Streaming Daemon Apr 14 21:12:24 volumio volumio[14112]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 14 21:12:24 volumio volumio[14112]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 14 21:12:24 volumio go-librespot[14393]: time="2026-04-14T21:12:24+01:00" level=debug msg="new websocket client" Apr 14 21:12:24 volumio volumio[14112]: info: Connection to go-librespot Websocket established Apr 14 21:12:25 volumio go-librespot[14393]: time="2026-04-14T21:12:25+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 14 21:12:25 volumio go-librespot[14393]: time="2026-04-14T21:12:25+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:25 volumio go-librespot[14393]: time="2026-04-14T21:12:25+01:00" level=debug msg="completed challenge" Apr 14 21:12:25 volumio go-librespot[14393]: time="2026-04-14T21:12:25+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:25 volumio volumio[14112]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 14 21:12:25 volumio go-librespot[14393]: time="2026-04-14T21:12:25+01:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Apr 14 21:12:25 volumio go-librespot[14393]: time="2026-04-14T21:12:25+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:25 volumio go-librespot[14393]: time="2026-04-14T21:12:25+01:00" level=debug msg="completed challenge" Apr 14 21:12:26 volumio go-librespot[14393]: time="2026-04-14T21:12:26+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:26 volumio go-librespot[14393]: time="2026-04-14T21:12:26+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 21:12:26 volumio go-librespot[14393]: time="2026-04-14T21:12:26+01:00" level=debug msg="connected to ap-gew4.spotify.com:80" Apr 14 21:12:26 volumio go-librespot[14393]: time="2026-04-14T21:12:26+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:26 volumio go-librespot[14393]: time="2026-04-14T21:12:26+01:00" level=debug msg="completed challenge" Apr 14 21:12:26 volumio go-librespot[14393]: time="2026-04-14T21:12:26+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:27 volumio volumio[14112]: info: MyVolumio token set successfully Apr 14 21:12:27 volumio volumio[14112]: info: MYVOLUMIO: Adding device Apr 14 21:12:27 volumio volumio[14112]: info: MYVOLUMIO: Evaluating Server Apr 14 21:12:27 volumio volumio[14112]: info: MyVolumio status changed Apr 14 21:12:27 volumio volumio[14112]: info: Streaming services startup Apr 14 21:12:27 volumio volumio[14112]: info: Starting Streaming Daemon Apr 14 21:12:27 volumio volumio[14112]: info: Removing browser output: myVolumio user plan is not superstar Apr 14 21:12:27 volumio volumio[14112]: info: Removing audio output: Apr 14 21:12:27 volumio volumio[14112]: info: Stoppping Tunnel 1 Apr 14 21:12:27 volumio sudo[14431]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 14 21:12:27 volumio sudo[14431]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:27 volumio sudo[14433]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Apr 14 21:12:27 volumio sudo[14433]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:27 volumio go-librespot[14393]: time="2026-04-14T21:12:27+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 14 21:12:27 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 21:12:27 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 21:12:27 volumio sudo[14431]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:27 volumio volumio[14112]: error: Cannot start Volumio Streaming Daemon Apr 14 21:12:27 volumio volumio[14112]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 14 21:12:27 volumio volumio[14112]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 14 21:12:27 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 21:12:27 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 21:12:27 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 21:12:27 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 21:12:27 volumio sudo[14433]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:27 volumio volumio[14112]: info: Remote SSH Stopped Apr 14 21:12:27 volumio go-librespot[14393]: time="2026-04-14T21:12:27+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:27 volumio go-librespot[14393]: time="2026-04-14T21:12:27+01:00" level=debug msg="completed challenge" Apr 14 21:12:27 volumio go-librespot[14393]: time="2026-04-14T21:12:27+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:27 volumio go-librespot[14393]: time="2026-04-14T21:12:27+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 21:12:27 volumio volumio[14112]: info: Connection to go-librespot Websocket closed Apr 14 21:12:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 21:12:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 21:12:27 volumio volumio[14112]: info: Setting Geolocation for MyVolumio to eu3 Apr 14 21:12:27 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:27 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:27 volumio volumio[14112]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:27 volumio volumio[14112]: info: Getting Spotify volume Apr 14 21:12:27 volumio volumio[14112]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 21:12:27 volumio volumio[14112]: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 14 21:12:27 volumio volumio[14112]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Apr 14 21:12:27 volumio volumio[14112]: errno: -111, Apr 14 21:12:27 volumio volumio[14112]: code: 'ECONNREFUSED', Apr 14 21:12:27 volumio volumio[14112]: syscall: 'connect', Apr 14 21:12:27 volumio volumio[14112]: address: '127.0.0.1', Apr 14 21:12:27 volumio volumio[14112]: port: 9879, Apr 14 21:12:27 volumio volumio[14112]: response: undefined Apr 14 21:12:27 volumio volumio[14112]: } Apr 14 21:12:27 volumio volumio[14112]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 21:12:27 volumio sudo[14450]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-14 21:11' Apr 14 21:12:27 volumio sudo[14450]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:28 volumio sudo[14450]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:28 volumio volumio-remote-updater[945]: [2026-04-14 21:12:28] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Apr 14 21:12:28 volumio volumio-remote-updater[945]: [2026-04-14 21:12:28] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Apr 14 21:12:28 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Apr 14 21:12:28 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Apr 14 21:12:28 volumio systemd[1]: volumio.service: Consumed 8.984s CPU time. Apr 14 21:12:28 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 14 21:12:28 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 14 21:12:28 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 121133. Apr 14 21:12:28 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 14 21:12:28 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Apr 14 21:12:28 volumio systemd[1]: volumio.service: Consumed 8.984s CPU time. Apr 14 21:12:28 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Apr 14 21:12:28 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 14 21:12:29 volumio volumio[14465]: info: ------------------------------------------- Apr 14 21:12:29 volumio volumio[14465]: info: ----- Volumio3 ---- Apr 14 21:12:29 volumio volumio[14465]: info: ------------------------------------------- Apr 14 21:12:29 volumio volumio[14465]: info: ----- System startup ---- Apr 14 21:12:29 volumio volumio[14465]: info: ------------------------------------------- Apr 14 21:12:29 volumio volumio[14465]: info: MYVOLUMIO Environment detected Apr 14 21:12:29 volumio volumio[14465]: info: Plugin folders cleanup Apr 14 21:12:29 volumio volumio[14465]: info: Scanning into folder /volumio/app/plugins/ Apr 14 21:12:29 volumio volumio[14465]: info: Scanning category audio_interface Apr 14 21:12:29 volumio volumio[14465]: info: Scanning category miscellanea Apr 14 21:12:29 volumio volumio[14465]: info: Scanning category music_service Apr 14 21:12:29 volumio volumio[14465]: info: Scanning category plugins.json Apr 14 21:12:29 volumio volumio[14465]: info: Scanning category system_controller Apr 14 21:12:29 volumio volumio[14465]: info: Scanning category user_interface Apr 14 21:12:29 volumio volumio[14465]: info: Scanning into folder /data/plugins/ Apr 14 21:12:29 volumio volumio[14465]: info: Scanning category music_service Apr 14 21:12:29 volumio volumio[14465]: info: Plugin folders cleanup completed Apr 14 21:12:29 volumio volumio[14465]: info: ------------------------------------------- Apr 14 21:12:29 volumio volumio[14465]: info: ----- Core plugins startup ---- Apr 14 21:12:29 volumio volumio[14465]: info: ------------------------------------------- Apr 14 21:12:29 volumio volumio[14465]: info: Loading plugins from folder /volumio/app/plugins/ Apr 14 21:12:29 volumio volumio[14465]: info: Adding plugin upnp to MyMusic Plugins Apr 14 21:12:29 volumio volumio[14465]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 14 21:12:29 volumio volumio[14465]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 14 21:12:29 volumio volumio[14465]: info: Loading plugins from folder /data/plugins/ Apr 14 21:12:29 volumio volumio[14465]: info: Adding plugin rtlsdr_radio to MyMusic Plugins Apr 14 21:12:29 volumio volumio[14465]: info: Loading plugin "system"... Apr 14 21:12:29 volumio volumio[14465]: info: Loading plugin "appearance"... Apr 14 21:12:29 volumio volumio[14465]: info: Loading plugin "network"... Apr 14 21:12:29 volumio volumio[14465]: info: Refreshing Cached IP Addresses Apr 14 21:12:29 volumio sudo[14494]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 21:12:29 volumio sudo[14494]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:29 volumio sudo[14496]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 21:12:29 volumio sudo[14496]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:29 volumio sudo[14494]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:29 volumio sudo[14496]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:29 volumio volumio[14465]: info: Loading plugin "services"... Apr 14 21:12:29 volumio volumio[14465]: info: Loading plugin "alsa_controller"... Apr 14 21:12:29 volumio sudo[14505]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 14 21:12:29 volumio sudo[14505]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:29 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 21:12:29 volumio volumio[14465]: info: Loading plugin "wizard"... Apr 14 21:12:29 volumio volumio[14465]: info: Loading plugin "networkfs"... Apr 14 21:12:29 volumio volumio[14465]: info: Starting Udev Watcher for removable devices Apr 14 21:12:29 volumio volumio[14465]: info: Mounting Device 0ACB-A1DE Apr 14 21:12:29 volumio sudo[14533]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/0ACB-A1DE -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Apr 14 21:12:29 volumio sudo[14533]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:29 volumio sudo[14533]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:29 volumio volumio[14465]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Apr 14 21:12:29 volumio volumio[14465]: dmesg(1) may have more information after failed mount system call. Apr 14 21:12:29 volumio volumio[14465]: 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 21:12:29 volumio volumio[14465]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Apr 14 21:12:29 volumio volumio[14465]: dmesg(1) may have more information after failed mount system call. Apr 14 21:12:29 volumio volumio[14465]: info: Ignoring mount for partition: boot Apr 14 21:12:29 volumio volumio[14465]: info: Ignoring mount for partition: volumio Apr 14 21:12:29 volumio volumio[14465]: info: Ignoring mount for partition: volumio_data Apr 14 21:12:29 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 21:12:29 volumio volumio[14465]: info: Loading plugin "volumio_command_line_client"... Apr 14 21:12:29 volumio volumio[14465]: info: Loading plugin "upnp"... Apr 14 21:12:29 volumio volumio[14465]: info: [1776197549872] Starting Upmpd Daemon Apr 14 21:12:29 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 21:12:29 volumio volumio[14465]: info: Loading plugin "my_music"... Apr 14 21:12:29 volumio volumio[14465]: info: Loading plugin "mpd"... Apr 14 21:12:29 volumio volumio[14465]: info: Loading plugin "upnp_browser"... Apr 14 21:12:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Apr 14 21:12:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 21:12:30 volumio volumio[14465]: info: Starting UPNP Browser Apr 14 21:12:30 volumio volumio[14465]: info: Loading plugin "alarm-clock"... Apr 14 21:12:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 21:12:30 volumio go-librespot[14535]: go-librespot daemon starting... Apr 14 21:12:30 volumio go-librespot[14536]: time="2026-04-14T21:12:30+01:00" level=info msg="running go-librespot 0.6.2" Apr 14 21:12:30 volumio go-librespot[14536]: time="2026-04-14T21:12:30+01:00" level=debug msg="app state loaded" Apr 14 21:12:30 volumio go-librespot[14536]: time="2026-04-14T21:12:30+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 21:12:30 volumio volumio[14465]: info: Loading plugin "airplay_emulation"... Apr 14 21:12:30 volumio volumio[14465]: info: Starting Shairport Sync Apr 14 21:12:30 volumio volumio[14465]: info: Loading plugin "last_100"... Apr 14 21:12:30 volumio volumio[14465]: info: Loading plugin "webradio"... Apr 14 21:12:30 volumio volumio[14465]: info: Loading plugin "i2s_dacs"... Apr 14 21:12:30 volumio volumio[14465]: info: Loading plugin "volumiodiscovery"... Apr 14 21:12:30 volumio volumio[14465]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 14 21:12:30 volumio volumio[14465]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 21:12:30 volumio volumio[14465]: *** WARNING *** For more information see Apr 14 21:12:30 volumio volumio[14465]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 14 21:12:30 volumio volumio[14465]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 21:12:30 volumio volumio[14465]: *** WARNING *** For more information see Apr 14 21:12:30 volumio volumio[14465]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 14 21:12:30 volumio node[14465]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 14 21:12:30 volumio node[14465]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 21:12:30 volumio node[14465]: *** WARNING *** For more information see Apr 14 21:12:30 volumio node[14465]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 14 21:12:30 volumio node[14465]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 21:12:30 volumio node[14465]: *** WARNING *** For more information see Apr 14 21:12:30 volumio volumio[14465]: info: Discovery: Started advertising with name: Volumio Apr 14 21:12:30 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 21:12:30 volumio volumio[14465]: info: Loading plugin "spop"... Apr 14 21:12:30 volumio go-librespot[14536]: time="2026-04-14T21:12:30+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 21:12:30 volumio go-librespot[14536]: time="2026-04-14T21:12:30+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 21:12:30 volumio go-librespot[14536]: time="2026-04-14T21:12:30+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 21:12:30 volumio go-librespot[14536]: time="2026-04-14T21:12:30+01:00" level=info msg="zeroconf server listening on port 38289" Apr 14 21:12:30 volumio volumio[14465]: info: Loading plugin "ytmusic"... Apr 14 21:12:31 volumio volumio[14465]: info: Loading plugin "outputs"... Apr 14 21:12:31 volumio volumio[14465]: info: Loading plugin "albumart"... Apr 14 21:12:31 volumio volumio[14465]: info: Plugin example_plugin is not enabled Apr 14 21:12:31 volumio volumio[14465]: info: Loading plugin "inputs"... Apr 14 21:12:31 volumio volumio[14465]: info: Loading plugin "updater_comm"... Apr 14 21:12:31 volumio go-librespot[14536]: time="2026-04-14T21:12:31+01:00" level=debug msg="obtained new client token: AADSIqf3Iqv2nhauo3MX7n6J1byySrh9dJ6Lft9CB4KYda/3VJ7pYJEU7c7sCgv9D1wN582I46eKn6hC7SMAne1fLRDzJqx9+PArGHfc94HF3eovNaZDRKUq72UKiqUR/p2iT5Qmb1MoLOLPRjxHTkc8meIDeGFWV5+DHbQLe5AbqG1ANBXRS+8rvs9bKbAKhpLyPGQ+EzyW+K8mjISHpbLMArMCyRS6cjRn8sxDMovp7s+rdpyn193siQ==" Apr 14 21:12:31 volumio volumio[14465]: info: Plugin mpdemulation is not enabled Apr 14 21:12:31 volumio volumio[14465]: info: Loading plugin "rest_api"... Apr 14 21:12:31 volumio volumio[14465]: info: Loading plugin "websocket"... Apr 14 21:12:31 volumio volumio[14465]: info: Starting Socket.io Server version 1.7.4 Apr 14 21:12:31 volumio volumio[14465]: info: Loading plugin "podcast"... Apr 14 21:12:31 volumio go-librespot[14536]: time="2026-04-14T21:12:31+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 14 21:12:31 volumio volumio[14465]: info: ControllerPodcast::constructor Apr 14 21:12:31 volumio volumio[14465]: info: Loading plugin "rtlsdr_radio"... Apr 14 21:12:31 volumio volumio[14548]: Forking 3 albumart workers Apr 14 21:12:31 volumio go-librespot[14536]: time="2026-04-14T21:12:31+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:31 volumio go-librespot[14536]: time="2026-04-14T21:12:31+01:00" level=debug msg="completed challenge" Apr 14 21:12:31 volumio go-librespot[14536]: time="2026-04-14T21:12:31+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:31 volumio volumio[14465]: info: Loading i18n strings for locale en Apr 14 21:12:31 volumio volumio[14465]: Updating browse sources language Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::initPlayerControls Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 21:12:31 volumio volumio[14465]: Express server listening on port 3000 Apr 14 21:12:31 volumio volumio[14465]: [Metrics] WebUI: 2s 314.83ms Apr 14 21:12:31 volumio volumio[14465]: info: CoreStateMachine::resetVolumioState Apr 14 21:12:31 volumio volumio[14465]: info: CoreStateMachine::getcurrentVolume Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::volumioRetrievevolume Apr 14 21:12:31 volumio volumio[14465]: info: Volumio Network Manager: Network status updated: 2 Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:31 volumio volumio[14465]: info: Reloading queue from file Apr 14 21:12:31 volumio volumio[14465]: info: CoreStateMachine::setRepeat null single undefined Apr 14 21:12:31 volumio volumio[14465]: info: CoreStateMachine::pushState Apr 14 21:12:31 volumio volumio[14465]: info: CorePlayQueue::getTrack 0 Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::volumioPushState Apr 14 21:12:31 volumio volumio[14465]: info: CoreStateMachine::setRandom true Apr 14 21:12:31 volumio volumio[14465]: info: CoreStateMachine::pushState Apr 14 21:12:31 volumio volumio[14465]: info: CorePlayQueue::getTrack 0 Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::volumioPushState Apr 14 21:12:31 volumio volumio[14465]: info: Setting Device type: Raspberry PI Apr 14 21:12:31 volumio volumio[14465]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Apr 14 21:12:31 volumio volumio[14465]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04170 Apr 14 21:12:31 volumio volumio[14465]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Apr 14 21:12:31 volumio volumio[14465]: info: Completed loading Core Plugins Apr 14 21:12:31 volumio volumio[14465]: info: Preparing to generate the ALSA configuration file Apr 14 21:12:31 volumio volumio[14465]: info: VolumeController:: Volume=36 Mute =true Apr 14 21:12:31 volumio volumio[14465]: info: CoreStateMachine::pushState Apr 14 21:12:31 volumio volumio[14465]: info: CorePlayQueue::getTrack 0 Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::volumioPushState Apr 14 21:12:31 volumio volumio[14465]: info: CoreStateMachine::updateTrackBlock Apr 14 21:12:31 volumio volumio[14465]: info: CorePlayQueue::getTrackBlock Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::volumioRetrievevolume Apr 14 21:12:31 volumio volumio[14465]: info: Asound.conf file unchanged, so no further update is needed Apr 14 21:12:31 volumio volumio[14465]: info: Output device has changed, restarting MPD Apr 14 21:12:31 volumio volumio[14465]: info: Output device has changed, restarting Shairport Sync Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:31 volumio sudo[14605]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 14 21:12:31 volumio sudo[14605]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:31 volumio volumio[14465]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 21:12:31 volumio volumio[14465]: info: ___________ START PLUGINS ___________ Apr 14 21:12:31 volumio sudo[14605]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:31 volumio sudo[14606]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 14 21:12:31 volumio sudo[14606]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:31 volumio volumio[14465]: info: ControllerMpd::onStart: Initializing MPD Apr 14 21:12:31 volumio volumio[14465]: info: Creating MPD Configuration file Apr 14 21:12:31 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 21:12:31 volumio volumio[14465]: info: [1776197551599] CoreMusicLibrary::Adding element Media Servers Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 21:12:31 volumio sudo[14614]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 14 21:12:31 volumio sudo[14614]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:31 volumio volumio[14465]: info: UPNP Browser: Client initialized successfully Apr 14 21:12:31 volumio sudo[14614]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:31 volumio sudo[14616]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 14 21:12:31 volumio sudo[14616]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:31 volumio volumio[14559]: Starting albumart workers Apr 14 21:12:31 volumio volumio[14465]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:31 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 14 21:12:31 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 14 21:12:31 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 14 21:12:31 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 14 21:12:31 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 14 21:12:31 volumio volumio[14558]: Starting albumart workers Apr 14 21:12:31 volumio volumio[14465]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 21:12:31 volumio volumio[14465]: info: [1776197551654] CoreMusicLibrary::Adding element Last_100 Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 21:12:31 volumio volumio[14465]: info: [1776197551655] CoreMusicLibrary::Adding element Webradio Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 21:12:31 volumio volumio[14465]: info: Initializing BBC Radios Apr 14 21:12:31 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 14 21:12:31 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 14 21:12:31 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 14 21:12:31 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 14 21:12:31 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 14 21:12:31 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 14 21:12:31 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 14 21:12:31 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 14 21:12:31 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 14 21:12:31 volumio volumio[14560]: Starting albumart workers Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:31 volumio volumio[14465]: info: Creating Spotify config file Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:31 volumio sudo[14633]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 14 21:12:31 volumio sudo[14633]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 14 21:12:31 volumio sudo[14633]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:31 volumio go-librespot[14536]: time="2026-04-14T21:12:31+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 21:12:31 volumio volumio[14465]: info: [1776197551928] CoreMusicLibrary::Adding element YouTube Music Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 21:12:31 volumio volumio[14465]: Cannot find translation for source YouTube Music Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 21:12:31 volumio volumio[14465]: info: [1776197551936] CoreMusicLibrary::Adding element Podcast Apr 14 21:12:31 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 21:12:31 volumio volumio[14465]: Cannot find translation for source YouTube Music Apr 14 21:12:31 volumio volumio[14465]: Cannot find translation for source Podcast Apr 14 21:12:31 volumio volumio[14465]: info: [RTL-SDR Radio] Starting plugin Apr 14 21:12:31 volumio volumio[14465]: info: [RTL-SDR Radio] Loaded i18n strings for language: en Apr 14 21:12:31 volumio go-librespot[14536]: time="2026-04-14T21:12:31+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:31 volumio volumio[14465]: info: Volumio Calling Home Apr 14 21:12:31 volumio go-librespot[14536]: time="2026-04-14T21:12:31+01:00" level=debug msg="completed challenge" Apr 14 21:12:31 volumio volumio[14465]: info: [RTL-SDR Radio] snd-aloop already loaded Apr 14 21:12:31 volumio volumio[14465]: info: [RTL-SDR Radio] No stations database found, creating v2 Apr 14 21:12:31 volumio volumio[14465]: info: [RTL-SDR Radio] Database loaded at: 2026-04-14T20:12:31.985Z Apr 14 21:12:31 volumio volumio[14465]: info: [RTL-SDR Radio] Loading blocklist from: /data/plugins/music_service/rtlsdr_radio/blocklist.json Apr 14 21:12:31 volumio volumio[14465]: info: [RTL-SDR Radio] Got 21 phrases from file Apr 14 21:12:31 volumio volumio[14465]: info: [RTL-SDR Radio] Updated metadata blocklist Apr 14 21:12:31 volumio volumio[14465]: info: [RTL-SDR Radio] Metadata module now has 21 phrases Apr 14 21:12:32 volumio volumio[14465]: info: [RTL-SDR Radio] Management server started on port 3456 Apr 14 21:12:32 volumio volumio[14465]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 21:12:32 volumio volumio[14465]: info: [1776197552018] CoreMusicLibrary::Adding element FM/DAB Radio Apr 14 21:12:32 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 21:12:32 volumio volumio[14465]: Cannot find translation for source YouTube Music Apr 14 21:12:32 volumio volumio[14465]: Cannot find translation for source Podcast Apr 14 21:12:32 volumio volumio[14465]: Cannot find translation for source FM/DAB Radio Apr 14 21:12:32 volumio volumio[14465]: info: [RTL-SDR Radio] Plugin started successfully Apr 14 21:12:32 volumio volumio[14465]: info: Discovery: adding 072f109f-54a2-4344-b8c4-538b45da7e51 Apr 14 21:12:32 volumio volumio[14465]: info: Discovery: Found device Volumio Apr 14 21:12:32 volumio volumio[14465]: info: CoreCommandRouter::volumioGetState Apr 14 21:12:32 volumio volumio[14465]: info: CorePlayQueue::getTrack 0 Apr 14 21:12:32 volumio volumio[14465]: info: Discovery: this is already registered, 072f109f-54a2-4344-b8c4-538b45da7e51 Apr 14 21:12:32 volumio volumio[14465]: info: Discovery: Found device Volumio Apr 14 21:12:32 volumio volumio[14465]: info: CoreCommandRouter::volumioGetState Apr 14 21:12:32 volumio volumio[14465]: info: CorePlayQueue::getTrack 0 Apr 14 21:12:32 volumio volumio[14465]: info: MPD Permissions set Apr 14 21:12:32 volumio volumio[14465]: info: MPD Permissions set Apr 14 21:12:32 volumio volumio[14465]: info: Spotify config file written Apr 14 21:12:32 volumio sudo[14674]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 14 21:12:32 volumio sudo[14674]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:32 volumio volumio[14465]: 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 21:12:32 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:32 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:32 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:32 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:32 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:32 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:32 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:32 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:32 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Apr 14 21:12:32 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:32 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:32 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:32 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:32 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:32 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:32 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:32 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:32 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Apr 14 21:12:32 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:32 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 21:12:32 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:32 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:32 volumio volumio[14465]: info: No need to fix Spotify hosts Apr 14 21:12:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 21:12:32 volumio go-librespot[14683]: go-librespot daemon starting... Apr 14 21:12:32 volumio sudo[14674]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:32 volumio volumio[14465]: info: VolumeController:: Volume=36 Mute =true Apr 14 21:12:32 volumio volumio[14465]: info: CoreStateMachine::pushState Apr 14 21:12:32 volumio volumio[14465]: info: CorePlayQueue::getTrack 0 Apr 14 21:12:32 volumio volumio[14465]: info: CoreCommandRouter::volumioPushState Apr 14 21:12:32 volumio volumio[14465]: info: Starting Shairport Sync Apr 14 21:12:32 volumio go-librespot[14687]: time="2026-04-14T21:12:32+01:00" level=info msg="running go-librespot 0.6.2" Apr 14 21:12:32 volumio go-librespot[14687]: time="2026-04-14T21:12:32+01:00" level=debug msg="app state loaded" Apr 14 21:12:32 volumio go-librespot[14687]: time="2026-04-14T21:12:32+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 21:12:32 volumio volumio[14465]: info: Starting Shairport Sync Apr 14 21:12:32 volumio volumio[14465]: info: Starting Shairport Sync Apr 14 21:12:32 volumio sudo[14694]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 21:12:32 volumio sudo[14694]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:32 volumio sudo[14698]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 21:12:32 volumio sudo[14696]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 21:12:32 volumio sudo[14698]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:32 volumio sudo[14696]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:32 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 14 21:12:32 volumio volumio[14465]: info: CoreCommandRouter::volumioGetState Apr 14 21:12:32 volumio volumio[14465]: info: CorePlayQueue::getTrack 0 Apr 14 21:12:32 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 14 21:12:32 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 21:12:32 volumio systemd[1]: shairport-sync.service: Consumed 1.555s CPU time. Apr 14 21:12:32 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 21:12:32 volumio sudo[14694]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:32 volumio sudo[14698]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:32 volumio sudo[14696]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:32 volumio volumio[14465]: info: Shairport-Sync Started Apr 14 21:12:32 volumio volumio[14465]: Error adding Membership: Error: addMembership EINVAL Apr 14 21:12:32 volumio volumio[14465]: info: Shairport-Sync Started Apr 14 21:12:32 volumio volumio[14465]: info: Shairport-Sync Started Apr 14 21:12:32 volumio volumio[14465]: info: Volumio called home Apr 14 21:12:32 volumio go-librespot[14687]: time="2026-04-14T21:12: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 14 21:12:32 volumio go-librespot[14687]: time="2026-04-14T21:12:32+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 21:12:32 volumio go-librespot[14687]: time="2026-04-14T21:12:32+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 21:12:32 volumio volumio[14465]: info: An error occurred while refreshing Spotify Token Error: Bad Request Apr 14 21:12:32 volumio go-librespot[14687]: time="2026-04-14T21:12:32+01:00" level=info msg="zeroconf server listening on port 36369" Apr 14 21:12:32 volumio mpd[14646]: 2026-04-14T21:12:32 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 14 21:12:32 volumio systemd[1]: Started mpd.service - Music Player Daemon. Apr 14 21:12:32 volumio sudo[14616]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:32 volumio sudo[14606]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:32 volumio volumio[14465]: info: Completed starting Core Plugins Apr 14 21:12:32 volumio volumio[14465]: info: ------------------------------------------- Apr 14 21:12:32 volumio volumio[14465]: info: ----- MyVolumio plugins startup ---- Apr 14 21:12:32 volumio volumio[14465]: info: ------------------------------------------- Apr 14 21:12:32 volumio volumio[14465]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 14 21:12:32 volumio volumio[14465]: error: MPD error: The expression evaluated to a falsy value: Apr 14 21:12:32 volumio volumio[14465]: assert.ok(self.idling) Apr 14 21:12:32 volumio volumio[14465]: error: The expression evaluated to a falsy value: Apr 14 21:12:32 volumio volumio[14465]: assert.ok(self.idling) Apr 14 21:12:32 volumio volumio[14465]: info: MPD running with PID14646 Apr 14 21:12:32 volumio volumio[14465]: ,establishing connection Apr 14 21:12:32 volumio volumio[14465]: error: updateQueue error: null Apr 14 21:12:32 volumio volumio[14465]: error: updateQueue error: null Apr 14 21:12:33 volumio go-librespot[14687]: time="2026-04-14T21:12:33+01:00" level=debug msg="obtained new client token: AAB4e2Hmvajxrkz+GEhzPK4hgEL2k6X8SUBg/JnLPL0nRs5yPz2aEr0+hQTTdUOALuG99CIxM1lWVNmAvEvhMoTSGWB+pqFPF41uv91H610qaJHxV/gOoZEnup4FRhXpmallwfu1ZxyugdSQ9FMulzcwyJp3+LJvi4rQ4g3YTYU7wAC/HS4YBd+B7mdjNP+mYF1yI6T+zz/ZfbPMxruosK8owFeaQeozJHqQ0HtQkZo/oVQ4oVUXPE0WpA==" Apr 14 21:12:33 volumio go-librespot[14687]: time="2026-04-14T21:12:33+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 14 21:12:33 volumio go-librespot[14687]: time="2026-04-14T21:12:33+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:33 volumio go-librespot[14687]: time="2026-04-14T21:12:33+01:00" level=debug msg="completed challenge" Apr 14 21:12:33 volumio volumio-remote-updater[945]: [2026-04-14 21:12:33] [connect] Successful connection Apr 14 21:12:33 volumio volumio-remote-updater[945]: [2026-04-14 21:12:33] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1776197553 101 Apr 14 21:12:33 volumio volumio[14465]: 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 21:12:33 volumio go-librespot[14687]: time="2026-04-14T21:12:33+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:33 volumio sudo[14505]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:34 volumio go-librespot[14687]: time="2026-04-14T21:12:34+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 14 21:12:34 volumio go-librespot[14687]: time="2026-04-14T21:12:34+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:34 volumio go-librespot[14687]: time="2026-04-14T21:12:34+01:00" level=debug msg="completed challenge" Apr 14 21:12:34 volumio go-librespot[14687]: time="2026-04-14T21:12:34+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:34 volumio go-librespot[14687]: time="2026-04-14T21:12:34+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 14 21:12:34 volumio go-librespot[14687]: time="2026-04-14T21:12:34+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:34 volumio go-librespot[14687]: time="2026-04-14T21:12:34+01:00" level=debug msg="completed challenge" Apr 14 21:12:34 volumio go-librespot[14687]: time="2026-04-14T21:12:34+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:35 volumio volumio[14465]: info: go-librespot daemon successfully initialized Apr 14 21:12:35 volumio go-librespot[14687]: time="2026-04-14T21:12:35+01:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Apr 14 21:12:35 volumio go-librespot[14687]: time="2026-04-14T21:12:35+01:00" level=debug msg="connected to ap-gue1.spotify.com:443" Apr 14 21:12:35 volumio go-librespot[14687]: time="2026-04-14T21:12:35+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:35 volumio go-librespot[14687]: time="2026-04-14T21:12:35+01:00" level=debug msg="completed challenge" Apr 14 21:12:35 volumio go-librespot[14687]: time="2026-04-14T21:12:35+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:36 volumio go-librespot[14687]: time="2026-04-14T21:12:36+01:00" level=debug msg="connected to ap-gew4.spotify.com:80" Apr 14 21:12:36 volumio go-librespot[14687]: time="2026-04-14T21:12:36+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:36 volumio go-librespot[14687]: time="2026-04-14T21:12:36+01:00" level=debug msg="completed challenge" Apr 14 21:12:36 volumio go-librespot[14687]: time="2026-04-14T21:12:36+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:36 volumio go-librespot[14687]: time="2026-04-14T21:12:36+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 14 21:12:36 volumio go-librespot[14687]: time="2026-04-14T21:12:36+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:36 volumio go-librespot[14687]: time="2026-04-14T21:12:36+01:00" level=debug msg="completed challenge" Apr 14 21:12:36 volumio go-librespot[14687]: time="2026-04-14T21:12:36+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:36 volumio go-librespot[14687]: time="2026-04-14T21:12:36+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 21:12:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 21:12:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 21:12:38 volumio volumio[14465]: info: Initializing connection to go-librespot Websocket Apr 14 21:12:38 volumio volumio[14465]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 14 21:12:39 volumio sudo[14740]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 21:12:39 volumio sudo[14740]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:39 volumio sudo[14742]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 21:12:39 volumio sudo[14742]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:39 volumio sudo[14740]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:39 volumio sudo[14742]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:39 volumio sudo[14746]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 14 21:12:39 volumio sudo[14746]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Apr 14 21:12:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 21:12:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 21:12:39 volumio go-librespot[14748]: go-librespot daemon starting... Apr 14 21:12:39 volumio sudo[14746]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:39 volumio volumio[14465]: info: Upmpdcli Daemon Started Apr 14 21:12:39 volumio go-librespot[14749]: time="2026-04-14T21:12:39+01:00" level=info msg="running go-librespot 0.6.2" Apr 14 21:12:39 volumio go-librespot[14749]: time="2026-04-14T21:12:39+01:00" level=debug msg="app state loaded" Apr 14 21:12:39 volumio go-librespot[14749]: time="2026-04-14T21:12:39+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 21:12:40 volumio go-librespot[14749]: time="2026-04-14T21:12: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-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 14 21:12:40 volumio go-librespot[14749]: time="2026-04-14T21:12:40+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 21:12:40 volumio go-librespot[14749]: time="2026-04-14T21:12:40+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 21:12:40 volumio go-librespot[14749]: time="2026-04-14T21:12:40+01:00" level=info msg="zeroconf server listening on port 43753" Apr 14 21:12:40 volumio go-librespot[14749]: time="2026-04-14T21:12:40+01:00" level=debug msg="obtained new client token: AAC3qG4iHy9/xfYyrXcOZbW/asRtgQ1C4o9c5fYbbWKRELsh4KsqcDKhJdr1iObFoEV+UoLzDrFyObNyPA8OJyZ10gd69d9Cktr8UjpbQxKhImASEBO3DsMb5B1kvDhv8lf5lykSZ+TuoaGcQELqFmKrtl2anWpOs62ErsXsuIsx7uVF8EC63vZpPU3LExG0VaJGcHdh6tkmoQeuSC4/PZFG9Tp9V4rB7xDAtxYdRctdaG2/l0y8TYU=" Apr 14 21:12:40 volumio go-librespot[14749]: time="2026-04-14T21:12:40+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 14 21:12:40 volumio go-librespot[14749]: time="2026-04-14T21:12:40+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:40 volumio go-librespot[14749]: time="2026-04-14T21:12:40+01:00" level=debug msg="completed challenge" Apr 14 21:12:40 volumio go-librespot[14749]: time="2026-04-14T21:12:40+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:40 volumio go-librespot[14749]: time="2026-04-14T21:12:40+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 14 21:12:40 volumio go-librespot[14749]: time="2026-04-14T21:12:40+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:40 volumio go-librespot[14749]: time="2026-04-14T21:12:40+01:00" level=debug msg="completed challenge" Apr 14 21:12:40 volumio go-librespot[14749]: time="2026-04-14T21:12:40+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 14 21:12:41 volumio volumio[14465]: info: Adding plugin bluetooth to MyMusic Plugins Apr 14 21:12:41 volumio volumio[14465]: info: Adding plugin multiroom to MyMusic Plugins Apr 14 21:12:41 volumio volumio[14465]: info: Adding plugin metavolumio to MyMusic Plugins Apr 14 21:12:41 volumio volumio[14465]: info: Adding plugin cd_controller to MyMusic Plugins Apr 14 21:12:41 volumio volumio[14465]: info: Adding plugin qobuzconnect to MyMusic Plugins Apr 14 21:12:41 volumio volumio[14465]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 14 21:12:41 volumio volumio[14465]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 14 21:12:41 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:41 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:41 volumio volumio[14465]: info: Starting MyVolumio Remote Streaming Endpoints Apr 14 21:12:41 volumio volumio[14465]: info: MyVolumio login type: Token Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 14 21:12:41 volumio go-librespot[14749]: time="2026-04-14T21:12:41+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 14 21:12:41 volumio go-librespot[14749]: time="2026-04-14T21:12:41+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:41 volumio go-librespot[14749]: time="2026-04-14T21:12:41+01:00" level=debug msg="completed challenge" Apr 14 21:12:41 volumio go-librespot[14749]: time="2026-04-14T21:12:41+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 14 21:12:41 volumio volumio[14465]: info: Streaming services startup Apr 14 21:12:41 volumio volumio[14465]: info: Starting Streaming Daemon Apr 14 21:12:41 volumio sudo[14759]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 14 21:12:41 volumio sudo[14759]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:41 volumio volumio[14465]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 14 21:12:41 volumio sudo[14759]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:41 volumio volumio[14465]: info: Initializing connection to go-librespot Websocket Apr 14 21:12:41 volumio volumio[14465]: error: Cannot start Volumio Streaming Daemon Apr 14 21:12:41 volumio volumio[14465]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 14 21:12:41 volumio volumio[14465]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 14 21:12:41 volumio go-librespot[14749]: time="2026-04-14T21:12:41+01:00" level=debug msg="new websocket client" Apr 14 21:12:41 volumio volumio[14465]: info: Connection to go-librespot Websocket established Apr 14 21:12:42 volumio volumio[14465]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 14 21:12:42 volumio go-librespot[14749]: time="2026-04-14T21:12:42+01:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Apr 14 21:12:42 volumio go-librespot[14749]: time="2026-04-14T21:12:42+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:42 volumio go-librespot[14749]: time="2026-04-14T21:12:42+01:00" level=debug msg="completed challenge" Apr 14 21:12:42 volumio go-librespot[14749]: time="2026-04-14T21:12:42+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:42 volumio go-librespot[14749]: time="2026-04-14T21:12:42+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Apr 14 21:12:42 volumio volumio[14465]: info: MyVolumio token set successfully Apr 14 21:12:42 volumio volumio[14465]: info: MYVOLUMIO: Adding device Apr 14 21:12:42 volumio volumio[14465]: info: MYVOLUMIO: Evaluating Server Apr 14 21:12:42 volumio go-librespot[14749]: time="2026-04-14T21:12:42+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:42 volumio go-librespot[14749]: time="2026-04-14T21:12:42+01:00" level=debug msg="completed challenge" Apr 14 21:12:42 volumio go-librespot[14749]: time="2026-04-14T21:12:42+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:43 volumio volumio[14465]: info: MyVolumio status changed Apr 14 21:12:43 volumio volumio[14465]: info: Streaming services startup Apr 14 21:12:43 volumio volumio[14465]: info: Starting Streaming Daemon Apr 14 21:12:43 volumio volumio[14465]: info: Removing browser output: myVolumio user plan is not superstar Apr 14 21:12:43 volumio volumio[14465]: info: Removing audio output: Apr 14 21:12:43 volumio volumio[14465]: info: Stoppping Tunnel 1 Apr 14 21:12:43 volumio sudo[14786]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 14 21:12:43 volumio sudo[14786]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:43 volumio sudo[14788]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Apr 14 21:12:43 volumio sudo[14788]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:43 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 21:12:43 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 21:12:43 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 21:12:43 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 21:12:43 volumio sudo[14786]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:43 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 21:12:43 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 21:12:43 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 21:12:43 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 21:12:43 volumio sudo[14788]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:43 volumio volumio[14465]: error: Cannot start Volumio Streaming Daemon Apr 14 21:12:43 volumio volumio[14465]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 14 21:12:43 volumio volumio[14465]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 14 21:12:43 volumio volumio[14465]: info: Remote SSH Stopped Apr 14 21:12:43 volumio volumio[14465]: info: Setting Geolocation for MyVolumio to eu3 Apr 14 21:12:43 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:43 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:43 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:43 volumio go-librespot[14749]: time="2026-04-14T21:12:43+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 14 21:12:43 volumio volumio[14465]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Apr 14 21:12:43 volumio go-librespot[14749]: time="2026-04-14T21:12:43+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:43 volumio go-librespot[14749]: time="2026-04-14T21:12:43+01:00" level=debug msg="completed challenge" Apr 14 21:12:44 volumio go-librespot[14749]: time="2026-04-14T21:12:44+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:44 volumio go-librespot[14749]: time="2026-04-14T21:12: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 21:12:44 volumio volumio[14465]: info: Connection to go-librespot Websocket closed Apr 14 21:12:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 21:12:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 21:12:44 volumio volumio[14465]: info: Updating MyVolumio device info Apr 14 21:12:44 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:44 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:44 volumio volumio[14465]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:44 volumio volumio[14465]: info: Getting Spotify volume Apr 14 21:12:44 volumio volumio[14465]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 21:12:44 volumio volumio[14465]: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 14 21:12:44 volumio volumio[14465]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Apr 14 21:12:44 volumio volumio[14465]: errno: -111, Apr 14 21:12:44 volumio volumio[14465]: code: 'ECONNREFUSED', Apr 14 21:12:44 volumio volumio[14465]: syscall: 'connect', Apr 14 21:12:44 volumio volumio[14465]: address: '127.0.0.1', Apr 14 21:12:44 volumio volumio[14465]: port: 9879, Apr 14 21:12:44 volumio volumio[14465]: response: undefined Apr 14 21:12:44 volumio volumio[14465]: } Apr 14 21:12:44 volumio volumio[14465]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 21:12:44 volumio sudo[14805]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-14 21:11' Apr 14 21:12:44 volumio sudo[14805]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:44 volumio sudo[14805]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:44 volumio volumio-remote-updater[945]: [2026-04-14 21:12:44] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Apr 14 21:12:44 volumio volumio-remote-updater[945]: [2026-04-14 21:12:44] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Apr 14 21:12:44 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Apr 14 21:12:44 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Apr 14 21:12:44 volumio systemd[1]: volumio.service: Consumed 8.937s CPU time. Apr 14 21:12:45 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 14 21:12:45 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 14 21:12:45 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 121134. Apr 14 21:12:45 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 14 21:12:45 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Apr 14 21:12:45 volumio systemd[1]: volumio.service: Consumed 8.937s CPU time. Apr 14 21:12:45 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Apr 14 21:12:45 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 14 21:12:45 volumio volumio[14817]: info: ------------------------------------------- Apr 14 21:12:45 volumio volumio[14817]: info: ----- Volumio3 ---- Apr 14 21:12:45 volumio volumio[14817]: info: ------------------------------------------- Apr 14 21:12:45 volumio volumio[14817]: info: ----- System startup ---- Apr 14 21:12:45 volumio volumio[14817]: info: ------------------------------------------- Apr 14 21:12:45 volumio volumio[14817]: info: MYVOLUMIO Environment detected Apr 14 21:12:45 volumio volumio[14817]: info: Plugin folders cleanup Apr 14 21:12:45 volumio volumio[14817]: info: Scanning into folder /volumio/app/plugins/ Apr 14 21:12:45 volumio volumio[14817]: info: Scanning category audio_interface Apr 14 21:12:45 volumio volumio[14817]: info: Scanning category miscellanea Apr 14 21:12:45 volumio volumio[14817]: info: Scanning category music_service Apr 14 21:12:45 volumio volumio[14817]: info: Scanning category plugins.json Apr 14 21:12:45 volumio volumio[14817]: info: Scanning category system_controller Apr 14 21:12:45 volumio volumio[14817]: info: Scanning category user_interface Apr 14 21:12:45 volumio volumio[14817]: info: Scanning into folder /data/plugins/ Apr 14 21:12:45 volumio volumio[14817]: info: Scanning category music_service Apr 14 21:12:45 volumio volumio[14817]: info: Plugin folders cleanup completed Apr 14 21:12:45 volumio volumio[14817]: info: ------------------------------------------- Apr 14 21:12:45 volumio volumio[14817]: info: ----- Core plugins startup ---- Apr 14 21:12:45 volumio volumio[14817]: info: ------------------------------------------- Apr 14 21:12:45 volumio volumio[14817]: info: Loading plugins from folder /volumio/app/plugins/ Apr 14 21:12:45 volumio volumio[14817]: info: Adding plugin upnp to MyMusic Plugins Apr 14 21:12:45 volumio volumio[14817]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 14 21:12:45 volumio volumio[14817]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 14 21:12:45 volumio volumio[14817]: info: Loading plugins from folder /data/plugins/ Apr 14 21:12:45 volumio volumio[14817]: info: Adding plugin rtlsdr_radio to MyMusic Plugins Apr 14 21:12:45 volumio volumio[14817]: info: Loading plugin "system"... Apr 14 21:12:45 volumio volumio[14817]: info: Loading plugin "appearance"... Apr 14 21:12:46 volumio volumio[14817]: info: Loading plugin "network"... Apr 14 21:12:46 volumio volumio[14817]: info: Refreshing Cached IP Addresses Apr 14 21:12:46 volumio sudo[14845]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 21:12:46 volumio sudo[14845]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:46 volumio sudo[14847]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 21:12:46 volumio sudo[14847]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:46 volumio sudo[14845]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:46 volumio sudo[14847]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:46 volumio volumio[14817]: info: Loading plugin "services"... Apr 14 21:12:46 volumio volumio[14817]: info: Loading plugin "alsa_controller"... Apr 14 21:12:46 volumio sudo[14860]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 14 21:12:46 volumio sudo[14860]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:46 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 21:12:46 volumio volumio[14817]: info: Loading plugin "wizard"... Apr 14 21:12:46 volumio volumio[14817]: info: Loading plugin "networkfs"... Apr 14 21:12:46 volumio volumio[14817]: info: Starting Udev Watcher for removable devices Apr 14 21:12:46 volumio volumio[14817]: info: Mounting Device 0ACB-A1DE Apr 14 21:12:46 volumio sudo[14884]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/0ACB-A1DE -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Apr 14 21:12:46 volumio sudo[14884]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:46 volumio sudo[14884]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:46 volumio volumio[14817]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Apr 14 21:12:46 volumio volumio[14817]: dmesg(1) may have more information after failed mount system call. Apr 14 21:12:46 volumio volumio[14817]: 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 21:12:46 volumio volumio[14817]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Apr 14 21:12:46 volumio volumio[14817]: dmesg(1) may have more information after failed mount system call. Apr 14 21:12:46 volumio volumio[14817]: info: Ignoring mount for partition: boot Apr 14 21:12:46 volumio volumio[14817]: info: Ignoring mount for partition: volumio Apr 14 21:12:46 volumio volumio[14817]: info: Ignoring mount for partition: volumio_data Apr 14 21:12:46 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 21:12:46 volumio volumio[14817]: info: Loading plugin "volumio_command_line_client"... Apr 14 21:12:46 volumio volumio[14817]: info: Loading plugin "upnp"... Apr 14 21:12:46 volumio volumio[14817]: info: [1776197566352] Starting Upmpd Daemon Apr 14 21:12:46 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 21:12:46 volumio volumio[14817]: info: Loading plugin "my_music"... Apr 14 21:12:46 volumio volumio[14817]: info: Loading plugin "mpd"... Apr 14 21:12:46 volumio volumio[14817]: info: Loading plugin "upnp_browser"... Apr 14 21:12:46 volumio volumio[14817]: info: Starting UPNP Browser Apr 14 21:12:46 volumio volumio[14817]: info: Loading plugin "alarm-clock"... Apr 14 21:12:46 volumio volumio[14817]: info: Loading plugin "airplay_emulation"... Apr 14 21:12:46 volumio volumio[14817]: info: Starting Shairport Sync Apr 14 21:12:46 volumio volumio[14817]: info: Loading plugin "last_100"... Apr 14 21:12:46 volumio volumio[14817]: info: Loading plugin "webradio"... Apr 14 21:12:46 volumio volumio[14817]: info: Loading plugin "i2s_dacs"... Apr 14 21:12:46 volumio volumio[14817]: info: Loading plugin "volumiodiscovery"... Apr 14 21:12:46 volumio volumio[14817]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 14 21:12:46 volumio node[14817]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 14 21:12:46 volumio volumio[14817]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 21:12:46 volumio node[14817]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 21:12:46 volumio volumio[14817]: *** WARNING *** For more information see Apr 14 21:12:46 volumio volumio[14817]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 14 21:12:46 volumio volumio[14817]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 21:12:46 volumio volumio[14817]: *** WARNING *** For more information see Apr 14 21:12:46 volumio node[14817]: *** WARNING *** For more information see Apr 14 21:12:46 volumio node[14817]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 14 21:12:46 volumio node[14817]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 21:12:46 volumio node[14817]: *** WARNING *** For more information see Apr 14 21:12:46 volumio volumio[14817]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 14 21:12:47 volumio volumio[14817]: info: Discovery: Started advertising with name: Volumio Apr 14 21:12:47 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 21:12:47 volumio volumio[14817]: info: Loading plugin "spop"... Apr 14 21:12:47 volumio volumio[14817]: info: Loading plugin "ytmusic"... Apr 14 21:12:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Apr 14 21:12:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 21:12:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 21:12:47 volumio go-librespot[14888]: go-librespot daemon starting... Apr 14 21:12:47 volumio go-librespot[14889]: time="2026-04-14T21:12:47+01:00" level=info msg="running go-librespot 0.6.2" Apr 14 21:12:47 volumio go-librespot[14889]: time="2026-04-14T21:12:47+01:00" level=debug msg="app state loaded" Apr 14 21:12:47 volumio go-librespot[14889]: time="2026-04-14T21:12:47+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 21:12:47 volumio volumio[14817]: info: Loading plugin "outputs"... Apr 14 21:12:47 volumio volumio[14817]: info: Loading plugin "albumart"... Apr 14 21:12:47 volumio volumio[14817]: info: Plugin example_plugin is not enabled Apr 14 21:12:47 volumio volumio[14817]: info: Loading plugin "inputs"... Apr 14 21:12:47 volumio volumio[14817]: info: Loading plugin "updater_comm"... Apr 14 21:12:47 volumio volumio[14817]: info: Plugin mpdemulation is not enabled Apr 14 21:12:47 volumio volumio[14817]: info: Loading plugin "rest_api"... Apr 14 21:12:47 volumio volumio[14817]: info: Loading plugin "websocket"... Apr 14 21:12:47 volumio volumio[14817]: info: Starting Socket.io Server version 1.7.4 Apr 14 21:12:47 volumio volumio[14817]: info: Loading plugin "podcast"... Apr 14 21:12:47 volumio volumio[14817]: info: ControllerPodcast::constructor Apr 14 21:12:47 volumio volumio[14817]: info: Loading plugin "rtlsdr_radio"... Apr 14 21:12:47 volumio volumio[14895]: Forking 3 albumart workers Apr 14 21:12:47 volumio volumio[14817]: info: Loading i18n strings for locale en Apr 14 21:12:47 volumio volumio[14817]: Updating browse sources language Apr 14 21:12:47 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 21:12:47 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 21:12:47 volumio volumio[14817]: info: CoreCommandRouter::initPlayerControls Apr 14 21:12:47 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:47 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:47 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:47 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:47 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:47 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:47 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:47 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:47 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 21:12:47 volumio volumio[14817]: Express server listening on port 3000 Apr 14 21:12:47 volumio volumio[14817]: [Metrics] WebUI: 2s 307.47ms Apr 14 21:12:47 volumio go-librespot[14889]: time="2026-04-14T21:12:47+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 21:12:47 volumio go-librespot[14889]: time="2026-04-14T21:12:47+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 21:12:47 volumio go-librespot[14889]: time="2026-04-14T21:12:47+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 21:12:47 volumio volumio[14817]: info: CoreStateMachine::resetVolumioState Apr 14 21:12:47 volumio volumio[14817]: info: CoreStateMachine::getcurrentVolume Apr 14 21:12:47 volumio volumio[14817]: info: CoreCommandRouter::volumioRetrievevolume Apr 14 21:12:47 volumio go-librespot[14889]: time="2026-04-14T21:12:47+01:00" level=info msg="zeroconf server listening on port 38711" Apr 14 21:12:47 volumio volumio[14817]: info: Volumio Network Manager: Network status updated: 2 Apr 14 21:12:47 volumio volumio[14817]: info: VolumeController:: Volume=36 Mute =true Apr 14 21:12:47 volumio volumio[14817]: info: CoreStateMachine::pushState Apr 14 21:12:47 volumio volumio[14817]: info: CorePlayQueue::getTrack 0 Apr 14 21:12:47 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 21:12:47 volumio volumio[14817]: info: CoreCommandRouter::volumioPushState Apr 14 21:12:47 volumio volumio[14817]: info: CoreStateMachine::updateTrackBlock Apr 14 21:12:47 volumio volumio[14817]: info: CorePlayQueue::getTrackBlock Apr 14 21:12:47 volumio volumio[14817]: info: CoreCommandRouter::volumioRetrievevolume Apr 14 21:12:47 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:47 volumio volumio[14817]: info: Reloading queue from file Apr 14 21:12:48 volumio volumio[14817]: info: CoreStateMachine::setRepeat null single undefined Apr 14 21:12:48 volumio volumio[14817]: info: CoreStateMachine::pushState Apr 14 21:12:48 volumio volumio[14817]: info: CorePlayQueue::getTrack 0 Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::volumioPushState Apr 14 21:12:48 volumio volumio[14817]: info: CoreStateMachine::setRandom true Apr 14 21:12:48 volumio volumio[14817]: info: CoreStateMachine::pushState Apr 14 21:12:48 volumio volumio[14817]: info: CorePlayQueue::getTrack 0 Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::volumioPushState Apr 14 21:12:48 volumio volumio[14817]: info: Setting Device type: Raspberry PI Apr 14 21:12:48 volumio volumio[14817]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Apr 14 21:12:48 volumio volumio[14817]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04170 Apr 14 21:12:48 volumio volumio[14817]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Apr 14 21:12:48 volumio volumio[14817]: info: Completed loading Core Plugins Apr 14 21:12:48 volumio volumio[14817]: info: Preparing to generate the ALSA configuration file Apr 14 21:12:48 volumio volumio[14817]: info: VolumeController:: Volume=36 Mute =true Apr 14 21:12:48 volumio volumio[14817]: info: CoreStateMachine::pushState Apr 14 21:12:48 volumio volumio[14817]: info: CorePlayQueue::getTrack 0 Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::volumioPushState Apr 14 21:12:48 volumio volumio[14817]: info: Asound.conf file unchanged, so no further update is needed Apr 14 21:12:48 volumio volumio[14817]: info: Output device has changed, restarting MPD Apr 14 21:12:48 volumio volumio[14817]: info: Output device has changed, restarting Shairport Sync Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:48 volumio sudo[14955]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 14 21:12:48 volumio sudo[14955]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:48 volumio volumio[14906]: Starting albumart workers Apr 14 21:12:48 volumio sudo[14955]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:48 volumio sudo[14957]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 14 21:12:48 volumio sudo[14957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:48 volumio volumio[14817]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 21:12:48 volumio volumio[14817]: info: ___________ START PLUGINS ___________ Apr 14 21:12:48 volumio volumio[14817]: info: ControllerMpd::onStart: Initializing MPD Apr 14 21:12:48 volumio volumio[14817]: info: Creating MPD Configuration file Apr 14 21:12:48 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 14 21:12:48 volumio volumio[14907]: Starting albumart workers Apr 14 21:12:48 volumio volumio[14905]: Starting albumart workers Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 21:12:48 volumio sudo[14965]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 21:12:48 volumio volumio[14817]: info: [1776197568171] CoreMusicLibrary::Adding element Media Servers Apr 14 21:12:48 volumio sudo[14965]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 21:12:48 volumio sudo[14965]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:48 volumio sudo[14967]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 14 21:12:48 volumio sudo[14967]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:48 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 14 21:12:48 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 14 21:12:48 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 14 21:12:48 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 14 21:12:48 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 14 21:12:48 volumio volumio[14817]: info: UPNP Browser: Client initialized successfully Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:48 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 14 21:12:48 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 14 21:12:48 volumio volumio[14817]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:48 volumio volumio[14817]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 21:12:48 volumio volumio[14817]: info: [1776197568231] CoreMusicLibrary::Adding element Last_100 Apr 14 21:12:48 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 21:12:48 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 14 21:12:48 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 14 21:12:48 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 14 21:12:48 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 21:12:48 volumio volumio[14817]: info: [1776197568236] CoreMusicLibrary::Adding element Webradio Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 21:12:48 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 14 21:12:48 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 21:12:48 volumio volumio[14817]: info: Initializing BBC Radios Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:48 volumio volumio[14817]: info: Creating Spotify config file Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:48 volumio sudo[14981]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 14 21:12:48 volumio sudo[14981]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 14 21:12:48 volumio sudo[14981]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:48 volumio go-librespot[14889]: time="2026-04-14T21:12:48+01:00" level=debug msg="obtained new client token: AAALaphxGgPPSeLfiqg7wyDIIkghJ+Q8vv3bzqFaJsZW/+GpzpLZH+J8Ng1F139o55t70WIWmCeDNjyAjjJtv8GS5320nrPLn07RK520wBl++XcOJa+NdcuF6l/3m4JWwi/TABUFfIshrDN4oeCsD725IjqUQ4+VDIAUcOrdNlWzzoo4LZcJEPPR3gLsNPRbEQZ21mJqHkLZ9jT3w4nsSFhXLzxvKapywtsA69mPIDFpjigVCxDwTss=" Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 21:12:48 volumio volumio[14817]: info: [1776197568430] CoreMusicLibrary::Adding element YouTube Music Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 21:12:48 volumio volumio[14817]: Cannot find translation for source YouTube Music Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 21:12:48 volumio volumio[14817]: info: [1776197568437] CoreMusicLibrary::Adding element Podcast Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 21:12:48 volumio volumio[14817]: Cannot find translation for source YouTube Music Apr 14 21:12:48 volumio volumio[14817]: Cannot find translation for source Podcast Apr 14 21:12:48 volumio volumio[14817]: info: [RTL-SDR Radio] Starting plugin Apr 14 21:12:48 volumio volumio[14817]: info: [RTL-SDR Radio] Loaded i18n strings for language: en Apr 14 21:12:48 volumio volumio[14817]: info: Volumio Calling Home Apr 14 21:12:48 volumio volumio[14817]: info: [RTL-SDR Radio] snd-aloop already loaded Apr 14 21:12:48 volumio volumio[14817]: info: [RTL-SDR Radio] No stations database found, creating v2 Apr 14 21:12:48 volumio volumio[14817]: info: [RTL-SDR Radio] Database loaded at: 2026-04-14T20:12:48.493Z Apr 14 21:12:48 volumio volumio[14817]: info: [RTL-SDR Radio] Loading blocklist from: /data/plugins/music_service/rtlsdr_radio/blocklist.json Apr 14 21:12:48 volumio volumio[14817]: info: [RTL-SDR Radio] Got 21 phrases from file Apr 14 21:12:48 volumio volumio[14817]: info: [RTL-SDR Radio] Updated metadata blocklist Apr 14 21:12:48 volumio volumio[14817]: info: [RTL-SDR Radio] Metadata module now has 21 phrases Apr 14 21:12:48 volumio volumio[14817]: info: [RTL-SDR Radio] Management server started on port 3456 Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 21:12:48 volumio volumio[14817]: info: [1776197568528] CoreMusicLibrary::Adding element FM/DAB Radio Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 21:12:48 volumio volumio[14817]: Cannot find translation for source YouTube Music Apr 14 21:12:48 volumio volumio[14817]: Cannot find translation for source Podcast Apr 14 21:12:48 volumio volumio[14817]: Cannot find translation for source FM/DAB Radio Apr 14 21:12:48 volumio volumio[14817]: info: [RTL-SDR Radio] Plugin started successfully Apr 14 21:12:48 volumio volumio[14817]: info: Discovery: adding 072f109f-54a2-4344-b8c4-538b45da7e51 Apr 14 21:12:48 volumio volumio[14817]: info: Discovery: Found device Volumio Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::volumioGetState Apr 14 21:12:48 volumio volumio[14817]: info: CorePlayQueue::getTrack 0 Apr 14 21:12:48 volumio volumio[14817]: info: Discovery: this is already registered, 072f109f-54a2-4344-b8c4-538b45da7e51 Apr 14 21:12:48 volumio volumio[14817]: info: Discovery: Found device Volumio Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::volumioGetState Apr 14 21:12:48 volumio volumio[14817]: info: CorePlayQueue::getTrack 0 Apr 14 21:12:48 volumio volumio[14817]: info: MPD Permissions set Apr 14 21:12:48 volumio volumio[14817]: info: MPD Permissions set Apr 14 21:12:48 volumio volumio[14817]: info: Spotify config file written Apr 14 21:12:48 volumio sudo[15023]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 14 21:12:48 volumio sudo[15023]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:48 volumio go-librespot[14889]: time="2026-04-14T21:12:48+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 14 21:12:48 volumio volumio[14817]: 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 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:48 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Apr 14 21:12:48 volumio systemd[1]: go-librespot-daemon.service: Killing process 14934 (go-librespot) with signal SIGKILL. Apr 14 21:12:48 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Apr 14 21:12:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:12:48 volumio volumio[14817]: info: No need to fix Spotify hosts Apr 14 21:12:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 21:12:48 volumio go-librespot[15030]: go-librespot daemon starting... Apr 14 21:12:48 volumio sudo[15023]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:48 volumio go-librespot[15036]: time="2026-04-14T21:12:48+01:00" level=info msg="running go-librespot 0.6.2" Apr 14 21:12:48 volumio go-librespot[15036]: time="2026-04-14T21:12:48+01:00" level=debug msg="app state loaded" Apr 14 21:12:48 volumio go-librespot[15036]: time="2026-04-14T21:12:48+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 21:12:48 volumio volumio[14817]: info: Starting Shairport Sync Apr 14 21:12:48 volumio volumio[14817]: info: Starting Shairport Sync Apr 14 21:12:48 volumio volumio[14817]: info: Starting Shairport Sync Apr 14 21:12:48 volumio sudo[15043]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 21:12:48 volumio sudo[15043]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:48 volumio sudo[15046]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 21:12:48 volumio sudo[15048]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 21:12:48 volumio sudo[15048]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:48 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 14 21:12:48 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 14 21:12:48 volumio sudo[15046]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:48 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 21:12:48 volumio systemd[1]: shairport-sync.service: Consumed 1.542s CPU time. Apr 14 21:12:48 volumio volumio[14817]: info: CoreCommandRouter::volumioGetState Apr 14 21:12:48 volumio volumio[14817]: info: CorePlayQueue::getTrack 0 Apr 14 21:12:48 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 21:12:48 volumio sudo[15043]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:48 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 14 21:12:48 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 14 21:12:48 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 21:12:48 volumio volumio[14817]: info: Shairport-Sync Started Apr 14 21:12:48 volumio volumio[14817]: Error adding Membership: Error: addMembership EINVAL Apr 14 21:12:48 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 21:12:48 volumio sudo[15046]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:48 volumio sudo[15048]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:48 volumio volumio[14817]: info: Shairport-Sync Started Apr 14 21:12:48 volumio volumio[14817]: info: Shairport-Sync Started Apr 14 21:12:49 volumio mpd[14996]: 2026-04-14T21:12:49 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 14 21:12:49 volumio systemd[1]: Started mpd.service - Music Player Daemon. Apr 14 21:12:49 volumio sudo[14957]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:49 volumio sudo[14967]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:49 volumio volumio[14817]: info: Completed starting Core Plugins Apr 14 21:12:49 volumio volumio[14817]: info: ------------------------------------------- Apr 14 21:12:49 volumio volumio[14817]: info: ----- MyVolumio plugins startup ---- Apr 14 21:12:49 volumio volumio[14817]: info: ------------------------------------------- Apr 14 21:12:49 volumio volumio[14817]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 14 21:12:49 volumio volumio[14817]: error: MPD error: The expression evaluated to a falsy value: Apr 14 21:12:49 volumio volumio[14817]: assert.ok(self.idling) Apr 14 21:12:49 volumio volumio[14817]: error: The expression evaluated to a falsy value: Apr 14 21:12:49 volumio volumio[14817]: assert.ok(self.idling) Apr 14 21:12:49 volumio volumio[14817]: info: MPD running with PID14996 Apr 14 21:12:49 volumio volumio[14817]: ,establishing connection Apr 14 21:12:49 volumio volumio[14817]: error: updateQueue error: null Apr 14 21:12:49 volumio volumio[14817]: error: updateQueue error: null Apr 14 21:12:49 volumio volumio[14817]: info: An error occurred while refreshing Spotify Token Error: Bad Request Apr 14 21:12:49 volumio volumio[14817]: info: Volumio called home Apr 14 21:12:49 volumio go-librespot[15036]: time="2026-04-14T21:12: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 21:12:49 volumio go-librespot[15036]: time="2026-04-14T21:12: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 21:12:49 volumio go-librespot[15036]: time="2026-04-14T21:12: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 21:12:49 volumio go-librespot[15036]: time="2026-04-14T21:12:49+01:00" level=info msg="zeroconf server listening on port 37687" Apr 14 21:12:49 volumio kernel: hwmon hwmon3: Undervoltage detected! Apr 14 21:12:49 volumio go-librespot[15036]: time="2026-04-14T21:12:49+01:00" level=debug msg="obtained new client token: AABBo8g0txlm5BW966B4kU9CpWslmtpEEJQS6pVX07ve44VUU/zKA2p/rfebKOXJGVcKMPh8+JD3hNZGAQoR1wFi9GKy40ywt3+G1yZQpaxYHM450XnHnryZvJR/rzzLdoZgoNu56gqDgKK6+VHtreY5Fshy7P+pgNL4nCNJHbQ91hgv8e/JmiCwTpoiKlODI7uCSu4vGkh3gXKhyrzi+Y1gfU0NZPkcCjzq+BCLgkww0jMMEUE6b2OvDA==" Apr 14 21:12:49 volumio go-librespot[15036]: time="2026-04-14T21:12:49+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 14 21:12:49 volumio go-librespot[15036]: time="2026-04-14T21:12:49+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:49 volumio go-librespot[15036]: time="2026-04-14T21:12:49+01:00" level=debug msg="completed challenge" Apr 14 21:12:49 volumio volumio-remote-updater[945]: [2026-04-14 21:12:49] [connect] Successful connection Apr 14 21:12:49 volumio volumio-remote-updater[945]: [2026-04-14 21:12:49] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1776197569 101 Apr 14 21:12:49 volumio volumio[14817]: 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 21:12:49 volumio go-librespot[15036]: time="2026-04-14T21:12:49+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:50 volumio sudo[14860]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:50 volumio go-librespot[15036]: time="2026-04-14T21:12:50+01:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.65.9:443: connect: connection refused" Apr 14 21:12:50 volumio go-librespot[15036]: time="2026-04-14T21:12:50+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 21:12:50 volumio go-librespot[15036]: time="2026-04-14T21:12:50+01:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Apr 14 21:12:50 volumio go-librespot[15036]: time="2026-04-14T21:12:50+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:50 volumio go-librespot[15036]: time="2026-04-14T21:12:50+01:00" level=debug msg="completed challenge" Apr 14 21:12:50 volumio go-librespot[15036]: time="2026-04-14T21:12:50+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:51 volumio go-librespot[15036]: time="2026-04-14T21:12:51+01:00" level=debug msg="connected to ap-gue1.spotify.com:443" Apr 14 21:12:51 volumio kernel: hwmon hwmon3: Voltage normalised Apr 14 21:12:51 volumio volumio[14817]: info: go-librespot daemon successfully initialized Apr 14 21:12:51 volumio go-librespot[15036]: time="2026-04-14T21:12:51+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:51 volumio go-librespot[15036]: time="2026-04-14T21:12:51+01:00" level=debug msg="completed challenge" Apr 14 21:12:51 volumio go-librespot[15036]: time="2026-04-14T21:12:51+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:52 volumio go-librespot[15036]: time="2026-04-14T21:12:52+01:00" level=debug msg="connected to ap-gew4.spotify.com:80" Apr 14 21:12:52 volumio go-librespot[15036]: time="2026-04-14T21:12:52+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:52 volumio go-librespot[15036]: time="2026-04-14T21:12:52+01:00" level=debug msg="completed challenge" Apr 14 21:12:52 volumio go-librespot[15036]: time="2026-04-14T21:12:52+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:52 volumio go-librespot[15036]: time="2026-04-14T21:12:52+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 14 21:12:52 volumio go-librespot[15036]: time="2026-04-14T21:12:52+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:52 volumio go-librespot[15036]: time="2026-04-14T21:12:52+01:00" level=debug msg="completed challenge" Apr 14 21:12:52 volumio go-librespot[15036]: time="2026-04-14T21:12:52+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:53 volumio go-librespot[15036]: time="2026-04-14T21:12:53+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 14 21:12:53 volumio go-librespot[15036]: time="2026-04-14T21:12:53+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:53 volumio go-librespot[15036]: time="2026-04-14T21:12:53+01:00" level=debug msg="completed challenge" Apr 14 21:12:53 volumio go-librespot[15036]: time="2026-04-14T21:12:53+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:53 volumio go-librespot[15036]: time="2026-04-14T21:12: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 21:12:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 21:12:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 21:12:54 volumio volumio[14817]: info: Initializing connection to go-librespot Websocket Apr 14 21:12:54 volumio volumio[14817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 14 21:12:56 volumio sudo[15092]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 21:12:56 volumio sudo[15092]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:56 volumio sudo[15094]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 21:12:56 volumio sudo[15094]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:56 volumio sudo[15092]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:56 volumio sudo[15094]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:56 volumio sudo[15097]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 14 21:12:56 volumio sudo[15097]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:56 volumio sudo[15097]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:56 volumio volumio[14817]: info: Upmpdcli Daemon Started Apr 14 21:12:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Apr 14 21:12:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 21:12:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 21:12:56 volumio go-librespot[15100]: go-librespot daemon starting... Apr 14 21:12:56 volumio go-librespot[15101]: time="2026-04-14T21:12:56+01:00" level=info msg="running go-librespot 0.6.2" Apr 14 21:12:56 volumio go-librespot[15101]: time="2026-04-14T21:12:56+01:00" level=debug msg="app state loaded" Apr 14 21:12:56 volumio go-librespot[15101]: time="2026-04-14T21:12:56+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 21:12:56 volumio go-librespot[15101]: time="2026-04-14T21:12: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 14 21:12:56 volumio go-librespot[15101]: time="2026-04-14T21:12:56+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 21:12:56 volumio go-librespot[15101]: time="2026-04-14T21:12:56+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 21:12:56 volumio go-librespot[15101]: time="2026-04-14T21:12:56+01:00" level=info msg="zeroconf server listening on port 35063" Apr 14 21:12:56 volumio go-librespot[15101]: time="2026-04-14T21:12:56+01:00" level=debug msg="obtained new client token: AAAXBd2VV8hpfY1gvcRyzIwOJLfrLIADTCFD77hvN5xPmxRhjSP2VLTlJadqyYLMCcPyhSxGQlP6+OTA/RuhFEcmJWL4QaaixfAOPupjnjSK+m5//WRg0JQ1mEOgqdGifGyp0msjoMa3osXM1Vk+nIFYi63PpPyWK7JrmvqebgkHf79LVSi891DASrVYZakk2f3gJbCI1f7RKh04Iz7n+HnnslIx4fKxZwVZpwiEKyozgklR+NqWvk/7lg==" Apr 14 21:12:56 volumio go-librespot[15101]: time="2026-04-14T21:12:56+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 14 21:12:56 volumio go-librespot[15101]: time="2026-04-14T21:12:56+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:56 volumio go-librespot[15101]: time="2026-04-14T21:12:56+01:00" level=debug msg="completed challenge" Apr 14 21:12:56 volumio go-librespot[15101]: time="2026-04-14T21:12:56+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 14 21:12:57 volumio volumio[14817]: info: Adding plugin bluetooth to MyMusic Plugins Apr 14 21:12:57 volumio volumio[14817]: info: Adding plugin multiroom to MyMusic Plugins Apr 14 21:12:57 volumio volumio[14817]: info: Adding plugin metavolumio to MyMusic Plugins Apr 14 21:12:57 volumio volumio[14817]: info: Adding plugin cd_controller to MyMusic Plugins Apr 14 21:12:57 volumio volumio[14817]: info: Adding plugin qobuzconnect to MyMusic Plugins Apr 14 21:12:57 volumio volumio[14817]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 14 21:12:57 volumio volumio[14817]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 14 21:12:57 volumio go-librespot[15101]: time="2026-04-14T21:12:57+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 14 21:12:57 volumio go-librespot[15101]: time="2026-04-14T21:12:57+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:57 volumio go-librespot[15101]: time="2026-04-14T21:12:57+01:00" level=debug msg="completed challenge" Apr 14 21:12:57 volumio go-librespot[15101]: time="2026-04-14T21:12:57+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 14 21:12:57 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:57 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:12:57 volumio volumio[14817]: info: Starting MyVolumio Remote Streaming Endpoints Apr 14 21:12:57 volumio volumio[14817]: info: MyVolumio login type: Token Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 14 21:12:57 volumio volumio[14817]: info: Streaming services startup Apr 14 21:12:57 volumio volumio[14817]: info: Starting Streaming Daemon Apr 14 21:12:57 volumio sudo[15111]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 14 21:12:57 volumio sudo[15111]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:57 volumio volumio[14817]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 14 21:12:57 volumio sudo[15111]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:57 volumio volumio[14817]: info: Initializing connection to go-librespot Websocket Apr 14 21:12:57 volumio volumio[14817]: error: Cannot start Volumio Streaming Daemon Apr 14 21:12:57 volumio volumio[14817]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 14 21:12:57 volumio volumio[14817]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 14 21:12:57 volumio go-librespot[15101]: time="2026-04-14T21:12:57+01:00" level=debug msg="new websocket client" Apr 14 21:12:57 volumio volumio[14817]: info: Connection to go-librespot Websocket established Apr 14 21:12:58 volumio go-librespot[15101]: time="2026-04-14T21:12:58+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 14 21:12:58 volumio go-librespot[15101]: time="2026-04-14T21:12:58+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:58 volumio go-librespot[15101]: time="2026-04-14T21:12:58+01:00" level=debug msg="completed challenge" Apr 14 21:12:58 volumio go-librespot[15101]: time="2026-04-14T21:12:58+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:58 volumio volumio[14817]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 14 21:12:58 volumio go-librespot[15101]: time="2026-04-14T21:12:58+01:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Apr 14 21:12:58 volumio volumio[14817]: info: MyVolumio token set successfully Apr 14 21:12:58 volumio volumio[14817]: info: MYVOLUMIO: Adding device Apr 14 21:12:58 volumio volumio[14817]: info: MYVOLUMIO: Evaluating Server Apr 14 21:12:58 volumio go-librespot[15101]: time="2026-04-14T21:12:58+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:58 volumio go-librespot[15101]: time="2026-04-14T21:12:58+01:00" level=debug msg="completed challenge" Apr 14 21:12:59 volumio volumio[14817]: info: MyVolumio status changed Apr 14 21:12:59 volumio volumio[14817]: info: Streaming services startup Apr 14 21:12:59 volumio volumio[14817]: info: Starting Streaming Daemon Apr 14 21:12:59 volumio volumio[14817]: info: Removing browser output: myVolumio user plan is not superstar Apr 14 21:12:59 volumio volumio[14817]: info: Removing audio output: Apr 14 21:12:59 volumio volumio[14817]: info: Stoppping Tunnel 1 Apr 14 21:12:59 volumio sudo[15139]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 14 21:12:59 volumio sudo[15139]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:59 volumio sudo[15141]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Apr 14 21:12:59 volumio sudo[15141]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:12:59 volumio sudo[15139]: pam_unix(sudo:session): session closed for user root Apr 14 21:12: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 21:12: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 21:12:59 volumio volumio[14817]: error: Cannot start Volumio Streaming Daemon Apr 14 21:12:59 volumio volumio[14817]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 14 21:12:59 volumio volumio[14817]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 14 21:12: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 21:12: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 21:12: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 21:12: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 21:12: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 21:12: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 21:12:59 volumio sudo[15141]: pam_unix(sudo:session): session closed for user root Apr 14 21:12:59 volumio volumio[14817]: info: Remote SSH Stopped Apr 14 21:12:59 volumio go-librespot[15101]: time="2026-04-14T21:12:59+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:12:59 volumio go-librespot[15101]: time="2026-04-14T21:12:59+01:00" level=debug msg="connected to ap-gue1.spotify.com:443" Apr 14 21:12:59 volumio go-librespot[15101]: time="2026-04-14T21:12:59+01:00" level=debug msg="completed keyexchange" Apr 14 21:12:59 volumio go-librespot[15101]: time="2026-04-14T21:12:59+01:00" level=debug msg="completed challenge" Apr 14 21:12:59 volumio go-librespot[15101]: time="2026-04-14T21:12:59+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:13:00 volumio volumio[14817]: info: Setting Geolocation for MyVolumio to eu3 Apr 14 21:13:00 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:13:00 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:13:00 volumio volumio[14817]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:13:00 volumio go-librespot[15101]: time="2026-04-14T21:13:00+01:00" level=debug msg="connected to ap-gew4.spotify.com:80" Apr 14 21:13:00 volumio go-librespot[15101]: time="2026-04-14T21:13:00+01:00" level=debug msg="completed keyexchange" Apr 14 21:13:00 volumio go-librespot[15101]: time="2026-04-14T21:13:00+01:00" level=debug msg="completed challenge" Apr 14 21:13:00 volumio go-librespot[15101]: time="2026-04-14T21:13:00+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:13:00 volumio go-librespot[15101]: time="2026-04-14T21:13: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 21:13:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 21:13:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 21:13:00 volumio volumio[14817]: info: Connection to go-librespot Websocket closed Apr 14 21:13:01 volumio volumio[14817]: info: Getting Spotify volume Apr 14 21:13:01 volumio volumio[14817]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 21:13:01 volumio volumio[14817]: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 14 21:13:01 volumio volumio[14817]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Apr 14 21:13:01 volumio volumio[14817]: errno: -111, Apr 14 21:13:01 volumio volumio[14817]: code: 'ECONNREFUSED', Apr 14 21:13:01 volumio volumio[14817]: syscall: 'connect', Apr 14 21:13:01 volumio volumio[14817]: address: '127.0.0.1', Apr 14 21:13:01 volumio volumio[14817]: port: 9879, Apr 14 21:13:01 volumio volumio[14817]: response: undefined Apr 14 21:13:01 volumio volumio[14817]: } Apr 14 21:13:01 volumio volumio[14817]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 21:13:01 volumio sudo[15158]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-14 21:12' Apr 14 21:13:01 volumio sudo[15158]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:13:01 volumio sudo[15158]: pam_unix(sudo:session): session closed for user root Apr 14 21:13:01 volumio volumio-remote-updater[945]: [2026-04-14 21:13:01] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Apr 14 21:13:01 volumio volumio-remote-updater[945]: [2026-04-14 21:13:01] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Apr 14 21:13:01 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Apr 14 21:13:01 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Apr 14 21:13:01 volumio systemd[1]: volumio.service: Consumed 8.984s CPU time. Apr 14 21:13:01 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 14 21:13:01 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 14 21:13:01 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 121135. Apr 14 21:13:01 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 14 21:13:01 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Apr 14 21:13:01 volumio systemd[1]: volumio.service: Consumed 8.984s CPU time. Apr 14 21:13:01 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Apr 14 21:13:01 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 14 21:13:02 volumio volumio[15170]: info: ------------------------------------------- Apr 14 21:13:02 volumio volumio[15170]: info: ----- Volumio3 ---- Apr 14 21:13:02 volumio volumio[15170]: info: ------------------------------------------- Apr 14 21:13:02 volumio volumio[15170]: info: ----- System startup ---- Apr 14 21:13:02 volumio volumio[15170]: info: ------------------------------------------- Apr 14 21:13:02 volumio volumio[15170]: info: MYVOLUMIO Environment detected Apr 14 21:13:02 volumio volumio[15170]: info: Plugin folders cleanup Apr 14 21:13:02 volumio volumio[15170]: info: Scanning into folder /volumio/app/plugins/ Apr 14 21:13:02 volumio volumio[15170]: info: Scanning category audio_interface Apr 14 21:13:02 volumio volumio[15170]: info: Scanning category miscellanea Apr 14 21:13:02 volumio volumio[15170]: info: Scanning category music_service Apr 14 21:13:02 volumio volumio[15170]: info: Scanning category plugins.json Apr 14 21:13:02 volumio volumio[15170]: info: Scanning category system_controller Apr 14 21:13:02 volumio volumio[15170]: info: Scanning category user_interface Apr 14 21:13:02 volumio volumio[15170]: info: Scanning into folder /data/plugins/ Apr 14 21:13:02 volumio volumio[15170]: info: Scanning category music_service Apr 14 21:13:02 volumio volumio[15170]: info: Plugin folders cleanup completed Apr 14 21:13:02 volumio volumio[15170]: info: ------------------------------------------- Apr 14 21:13:02 volumio volumio[15170]: info: ----- Core plugins startup ---- Apr 14 21:13:02 volumio volumio[15170]: info: ------------------------------------------- Apr 14 21:13:02 volumio volumio[15170]: info: Loading plugins from folder /volumio/app/plugins/ Apr 14 21:13:02 volumio volumio[15170]: info: Adding plugin upnp to MyMusic Plugins Apr 14 21:13:02 volumio volumio[15170]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 14 21:13:02 volumio volumio[15170]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 14 21:13:02 volumio volumio[15170]: info: Loading plugins from folder /data/plugins/ Apr 14 21:13:02 volumio volumio[15170]: info: Adding plugin rtlsdr_radio to MyMusic Plugins Apr 14 21:13:02 volumio volumio[15170]: info: Loading plugin "system"... Apr 14 21:13:02 volumio volumio[15170]: info: Loading plugin "appearance"... Apr 14 21:13:02 volumio volumio[15170]: info: Loading plugin "network"... Apr 14 21:13:02 volumio volumio[15170]: info: Refreshing Cached IP Addresses Apr 14 21:13:02 volumio sudo[15198]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 21:13:02 volumio sudo[15198]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:13:02 volumio sudo[15200]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 21:13:02 volumio sudo[15200]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:13:02 volumio sudo[15198]: pam_unix(sudo:session): session closed for user root Apr 14 21:13:02 volumio sudo[15200]: pam_unix(sudo:session): session closed for user root Apr 14 21:13:02 volumio volumio[15170]: info: Loading plugin "services"... Apr 14 21:13:02 volumio volumio[15170]: info: Loading plugin "alsa_controller"... Apr 14 21:13:02 volumio sudo[15209]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 14 21:13:02 volumio sudo[15209]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:13:02 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 21:13:02 volumio volumio[15170]: info: Loading plugin "wizard"... Apr 14 21:13:02 volumio volumio[15170]: info: Loading plugin "networkfs"... Apr 14 21:13:02 volumio volumio[15170]: info: Starting Udev Watcher for removable devices Apr 14 21:13:02 volumio volumio[15170]: info: Mounting Device 0ACB-A1DE Apr 14 21:13:02 volumio sudo[15237]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/0ACB-A1DE -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Apr 14 21:13:02 volumio sudo[15237]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:13:02 volumio sudo[15237]: pam_unix(sudo:session): session closed for user root Apr 14 21:13:02 volumio volumio[15170]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Apr 14 21:13:02 volumio volumio[15170]: dmesg(1) may have more information after failed mount system call. Apr 14 21:13:02 volumio volumio[15170]: 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 21:13:02 volumio volumio[15170]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Apr 14 21:13:02 volumio volumio[15170]: dmesg(1) may have more information after failed mount system call. Apr 14 21:13:02 volumio volumio[15170]: info: Ignoring mount for partition: boot Apr 14 21:13:02 volumio volumio[15170]: info: Ignoring mount for partition: volumio Apr 14 21:13:02 volumio volumio[15170]: info: Ignoring mount for partition: volumio_data Apr 14 21:13:02 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 21:13:02 volumio volumio[15170]: info: Loading plugin "volumio_command_line_client"... Apr 14 21:13:02 volumio volumio[15170]: info: Loading plugin "upnp"... Apr 14 21:13:02 volumio volumio[15170]: info: [1776197582864] Starting Upmpd Daemon Apr 14 21:13:02 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 21:13:02 volumio volumio[15170]: info: Loading plugin "my_music"... Apr 14 21:13:02 volumio volumio[15170]: info: Loading plugin "mpd"... Apr 14 21:13:02 volumio volumio[15170]: info: Loading plugin "upnp_browser"... Apr 14 21:13:03 volumio volumio[15170]: info: Starting UPNP Browser Apr 14 21:13:03 volumio volumio[15170]: info: Loading plugin "alarm-clock"... Apr 14 21:13:03 volumio volumio[15170]: info: Loading plugin "airplay_emulation"... Apr 14 21:13:03 volumio volumio[15170]: info: Starting Shairport Sync Apr 14 21:13:03 volumio volumio[15170]: info: Loading plugin "last_100"... Apr 14 21:13:03 volumio volumio[15170]: info: Loading plugin "webradio"... Apr 14 21:13:03 volumio volumio[15170]: info: Loading plugin "i2s_dacs"... Apr 14 21:13:03 volumio volumio[15170]: info: Loading plugin "volumiodiscovery"... Apr 14 21:13:03 volumio volumio[15170]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 14 21:13:03 volumio volumio[15170]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 21:13:03 volumio volumio[15170]: *** WARNING *** For more information see Apr 14 21:13:03 volumio volumio[15170]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 14 21:13:03 volumio volumio[15170]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 21:13:03 volumio volumio[15170]: *** WARNING *** For more information see Apr 14 21:13:03 volumio node[15170]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 14 21:13:03 volumio volumio[15170]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 14 21:13:03 volumio node[15170]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 21:13:03 volumio node[15170]: *** WARNING *** For more information see Apr 14 21:13:03 volumio node[15170]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 14 21:13:03 volumio node[15170]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 21:13:03 volumio node[15170]: *** WARNING *** For more information see Apr 14 21:13:03 volumio volumio[15170]: info: Discovery: Started advertising with name: Volumio Apr 14 21:13:03 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 21:13:03 volumio volumio[15170]: info: Loading plugin "spop"... Apr 14 21:13:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Apr 14 21:13:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 21:13:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 21:13:03 volumio go-librespot[15241]: go-librespot daemon starting... Apr 14 21:13:03 volumio go-librespot[15242]: time="2026-04-14T21:13:03+01:00" level=info msg="running go-librespot 0.6.2" Apr 14 21:13:03 volumio go-librespot[15242]: time="2026-04-14T21:13:03+01:00" level=debug msg="app state loaded" Apr 14 21:13:03 volumio go-librespot[15242]: time="2026-04-14T21:13:03+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 21:13:03 volumio volumio[15170]: info: Loading plugin "ytmusic"... Apr 14 21:13:04 volumio volumio[15170]: info: Loading plugin "outputs"... Apr 14 21:13:04 volumio volumio[15170]: info: Loading plugin "albumart"... Apr 14 21:13:04 volumio volumio[15170]: info: Plugin example_plugin is not enabled Apr 14 21:13:04 volumio volumio[15170]: info: Loading plugin "inputs"... Apr 14 21:13:04 volumio volumio[15170]: info: Loading plugin "updater_comm"... Apr 14 21:13:04 volumio go-librespot[15242]: time="2026-04-14T21:13:04+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 21:13:04 volumio go-librespot[15242]: time="2026-04-14T21:13:04+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 21:13:04 volumio go-librespot[15242]: time="2026-04-14T21:13:04+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 21:13:04 volumio volumio[15170]: info: Plugin mpdemulation is not enabled Apr 14 21:13:04 volumio volumio[15170]: info: Loading plugin "rest_api"... Apr 14 21:13:04 volumio volumio[15170]: info: Loading plugin "websocket"... Apr 14 21:13:04 volumio volumio[15170]: info: Starting Socket.io Server version 1.7.4 Apr 14 21:13:04 volumio volumio[15170]: info: Loading plugin "podcast"... Apr 14 21:13:04 volumio go-librespot[15242]: time="2026-04-14T21:13:04+01:00" level=info msg="zeroconf server listening on port 41481" Apr 14 21:13:04 volumio volumio[15170]: info: ControllerPodcast::constructor Apr 14 21:13:04 volumio volumio[15170]: info: Loading plugin "rtlsdr_radio"... Apr 14 21:13:04 volumio volumio[15248]: Forking 3 albumart workers Apr 14 21:13:04 volumio volumio[15170]: info: Loading i18n strings for locale en Apr 14 21:13:04 volumio volumio[15170]: Updating browse sources language Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::initPlayerControls Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:13:04 volumio go-librespot[15242]: time="2026-04-14T21:13:04+01:00" level=debug msg="obtained new client token: AAA4OSt6+E8p5INOWFowt8XsZScIXzLED7K3zd56Cyx5khc1hqR4nEP3gV+pIONncx6HwAhDgd8OxNfWAqtnJql51zw/1C/c1QYRkdqXqd5j0e3XR23bqN+fzoqhITEoP1zhbIhRBecMZXHuZ/TYQlT8txpx3d+JqkZ7ZYtx5oSrHfdeeYY6+AE573d5iw0pNReRb/gWJgeDc0eCvVTebozwlmDd9d+TNm68SkIGV3Gi5vCvwg9Qcuc=" Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 21:13:04 volumio volumio[15170]: Express server listening on port 3000 Apr 14 21:13:04 volumio volumio[15170]: [Metrics] WebUI: 2s 314.10ms Apr 14 21:13:04 volumio volumio[15170]: info: CoreStateMachine::resetVolumioState Apr 14 21:13:04 volumio volumio[15170]: info: CoreStateMachine::getcurrentVolume Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::volumioRetrievevolume Apr 14 21:13:04 volumio go-librespot[15242]: time="2026-04-14T21:13:04+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 14 21:13:04 volumio volumio[15170]: info: Volumio Network Manager: Network status updated: 2 Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:13:04 volumio volumio[15170]: info: Reloading queue from file Apr 14 21:13:04 volumio volumio[15170]: info: VolumeController:: Volume=36 Mute =true Apr 14 21:13:04 volumio volumio[15170]: info: CoreStateMachine::pushState Apr 14 21:13:04 volumio volumio[15170]: info: CorePlayQueue::getTrack 0 Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::volumioPushState Apr 14 21:13:04 volumio volumio[15170]: info: CoreStateMachine::updateTrackBlock Apr 14 21:13:04 volumio volumio[15170]: info: CorePlayQueue::getTrackBlock Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::volumioRetrievevolume Apr 14 21:13:04 volumio volumio[15170]: info: CoreStateMachine::setRepeat null single undefined Apr 14 21:13:04 volumio volumio[15170]: info: CoreStateMachine::pushState Apr 14 21:13:04 volumio volumio[15170]: info: CorePlayQueue::getTrack 0 Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::volumioPushState Apr 14 21:13:04 volumio volumio[15170]: info: CoreStateMachine::setRandom true Apr 14 21:13:04 volumio volumio[15170]: info: CoreStateMachine::pushState Apr 14 21:13:04 volumio volumio[15170]: info: CorePlayQueue::getTrack 0 Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::volumioPushState Apr 14 21:13:04 volumio volumio[15170]: info: Setting Device type: Raspberry PI Apr 14 21:13:04 volumio volumio[15170]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Apr 14 21:13:04 volumio volumio[15170]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04170 Apr 14 21:13:04 volumio volumio[15170]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Apr 14 21:13:04 volumio volumio[15170]: info: Completed loading Core Plugins Apr 14 21:13:04 volumio volumio[15170]: info: Preparing to generate the ALSA configuration file Apr 14 21:13:04 volumio volumio[15170]: info: VolumeController:: Volume=36 Mute =true Apr 14 21:13:04 volumio volumio[15170]: info: CoreStateMachine::pushState Apr 14 21:13:04 volumio volumio[15170]: info: CorePlayQueue::getTrack 0 Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::volumioPushState Apr 14 21:13:04 volumio volumio[15170]: info: Asound.conf file unchanged, so no further update is needed Apr 14 21:13:04 volumio volumio[15170]: info: Output device has changed, restarting MPD Apr 14 21:13:04 volumio volumio[15170]: info: Output device has changed, restarting Shairport Sync Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:13:04 volumio go-librespot[15242]: time="2026-04-14T21:13:04+01:00" level=debug msg="completed keyexchange" Apr 14 21:13:04 volumio go-librespot[15242]: time="2026-04-14T21:13:04+01:00" level=debug msg="completed challenge" Apr 14 21:13:04 volumio sudo[15308]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 14 21:13:04 volumio sudo[15310]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 14 21:13:04 volumio sudo[15308]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:13:04 volumio sudo[15308]: pam_unix(sudo:session): session closed for user root Apr 14 21:13:04 volumio volumio[15170]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 21:13:04 volumio volumio[15170]: info: ___________ START PLUGINS ___________ Apr 14 21:13:04 volumio sudo[15310]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:13:04 volumio volumio[15170]: info: ControllerMpd::onStart: Initializing MPD Apr 14 21:13:04 volumio volumio[15170]: info: Creating MPD Configuration file Apr 14 21:13:04 volumio go-librespot[15242]: time="2026-04-14T21:13:04+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 21:13:04 volumio volumio[15170]: info: [1776197584601] CoreMusicLibrary::Adding element Media Servers Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 21:13:04 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 14 21:13:04 volumio sudo[15318]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 14 21:13:04 volumio sudo[15318]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:13:04 volumio volumio[15170]: info: UPNP Browser: Client initialized successfully Apr 14 21:13:04 volumio sudo[15318]: pam_unix(sudo:session): session closed for user root Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:13:04 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 14 21:13:04 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 14 21:13:04 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 14 21:13:04 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 14 21:13:04 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 14 21:13:04 volumio volumio[15262]: Starting albumart workers Apr 14 21:13:04 volumio sudo[15320]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 14 21:13:04 volumio volumio[15170]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:13:04 volumio sudo[15320]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:13:04 volumio volumio[15263]: Starting albumart workers Apr 14 21:13:04 volumio volumio[15170]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 21:13:04 volumio volumio[15170]: info: [1776197584654] CoreMusicLibrary::Adding element Last_100 Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 21:13:04 volumio volumio[15170]: info: [1776197584658] CoreMusicLibrary::Adding element Webradio Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 21:13:04 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 14 21:13:04 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 14 21:13:04 volumio volumio[15170]: info: Initializing BBC Radios Apr 14 21:13:04 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 14 21:13:04 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 14 21:13:04 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 14 21:13:04 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 14 21:13:04 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 14 21:13:04 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 14 21:13:04 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 14 21:13:04 volumio volumio[15261]: Starting albumart workers Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:13:04 volumio volumio[15170]: info: Creating Spotify config file Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:13:04 volumio sudo[15342]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 14 21:13:04 volumio sudo[15342]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 14 21:13:04 volumio sudo[15342]: pam_unix(sudo:session): session closed for user root Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 21:13:04 volumio volumio[15170]: info: [1776197584851] CoreMusicLibrary::Adding element YouTube Music Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 21:13:04 volumio volumio[15170]: Cannot find translation for source YouTube Music Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 21:13:04 volumio volumio[15170]: info: [1776197584856] CoreMusicLibrary::Adding element Podcast Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 21:13:04 volumio volumio[15170]: Cannot find translation for source YouTube Music Apr 14 21:13:04 volumio volumio[15170]: Cannot find translation for source Podcast Apr 14 21:13:04 volumio volumio[15170]: info: [RTL-SDR Radio] Starting plugin Apr 14 21:13:04 volumio volumio[15170]: info: [RTL-SDR Radio] Loaded i18n strings for language: en Apr 14 21:13:04 volumio volumio[15170]: info: Volumio Calling Home Apr 14 21:13:04 volumio volumio[15170]: info: [RTL-SDR Radio] snd-aloop already loaded Apr 14 21:13:04 volumio volumio[15170]: info: [RTL-SDR Radio] No stations database found, creating v2 Apr 14 21:13:04 volumio volumio[15170]: info: [RTL-SDR Radio] Database loaded at: 2026-04-14T20:13:04.944Z Apr 14 21:13:04 volumio volumio[15170]: info: [RTL-SDR Radio] Loading blocklist from: /data/plugins/music_service/rtlsdr_radio/blocklist.json Apr 14 21:13:04 volumio volumio[15170]: info: [RTL-SDR Radio] Got 21 phrases from file Apr 14 21:13:04 volumio volumio[15170]: info: [RTL-SDR Radio] Updated metadata blocklist Apr 14 21:13:04 volumio volumio[15170]: info: [RTL-SDR Radio] Metadata module now has 21 phrases Apr 14 21:13:04 volumio volumio[15170]: info: [RTL-SDR Radio] Management server started on port 3456 Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 21:13:04 volumio volumio[15170]: info: [1776197584992] CoreMusicLibrary::Adding element FM/DAB Radio Apr 14 21:13:04 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 21:13:04 volumio volumio[15170]: Cannot find translation for source YouTube Music Apr 14 21:13:04 volumio volumio[15170]: Cannot find translation for source Podcast Apr 14 21:13:04 volumio volumio[15170]: Cannot find translation for source FM/DAB Radio Apr 14 21:13:04 volumio volumio[15170]: info: [RTL-SDR Radio] Plugin started successfully Apr 14 21:13:05 volumio volumio[15170]: info: MPD Permissions set Apr 14 21:13:05 volumio volumio[15170]: info: MPD Permissions set Apr 14 21:13:05 volumio volumio[15170]: info: Spotify config file written Apr 14 21:13:05 volumio sudo[15376]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 14 21:13:05 volumio sudo[15376]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:13:05 volumio volumio[15170]: 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 21:13:05 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:13:05 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:13:05 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:13:05 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:13:05 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:13:05 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:13:05 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:13:05 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:13:05 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Apr 14 21:13:05 volumio systemd[1]: go-librespot-daemon.service: Killing process 15247 (go-librespot) with signal SIGKILL. Apr 14 21:13:05 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Apr 14 21:13:05 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:13:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 21:13:05 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:13:05 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:13:05 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:13:05 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:13:05 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:13:05 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:13:05 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:13:05 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:13:05 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:13:05 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:13:05 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 21:13:05 volumio volumio[15170]: info: No need to fix Spotify hosts Apr 14 21:13:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 21:13:05 volumio go-librespot[15384]: go-librespot daemon starting... Apr 14 21:13:05 volumio sudo[15376]: pam_unix(sudo:session): session closed for user root Apr 14 21:13:05 volumio volumio[15170]: info: Volumio called home Apr 14 21:13:05 volumio volumio[15170]: info: Starting Shairport Sync Apr 14 21:13:05 volumio volumio[15170]: info: Starting Shairport Sync Apr 14 21:13:05 volumio go-librespot[15389]: time="2026-04-14T21:13:05+01:00" level=info msg="running go-librespot 0.6.2" Apr 14 21:13:05 volumio go-librespot[15389]: time="2026-04-14T21:13:05+01:00" level=debug msg="app state loaded" Apr 14 21:13:05 volumio go-librespot[15389]: time="2026-04-14T21:13:05+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 21:13:05 volumio volumio[15170]: info: Starting Shairport Sync Apr 14 21:13:05 volumio sudo[15396]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 21:13:05 volumio sudo[15396]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:13:05 volumio sudo[15398]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 21:13:05 volumio sudo[15398]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:13:05 volumio sudo[15400]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 21:13:05 volumio sudo[15400]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:13:05 volumio volumio[15170]: info: Discovery: adding 072f109f-54a2-4344-b8c4-538b45da7e51 Apr 14 21:13:05 volumio volumio[15170]: info: Discovery: Found device Volumio Apr 14 21:13:05 volumio volumio[15170]: info: CoreCommandRouter::volumioGetState Apr 14 21:13:05 volumio volumio[15170]: info: CorePlayQueue::getTrack 0 Apr 14 21:13:05 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 14 21:13:05 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 14 21:13:05 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 21:13:05 volumio systemd[1]: shairport-sync.service: Consumed 1.545s CPU time. Apr 14 21:13:05 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 21:13:05 volumio sudo[15396]: pam_unix(sudo:session): session closed for user root Apr 14 21:13:05 volumio volumio[15170]: info: Shairport-Sync Started Apr 14 21:13:05 volumio volumio[15170]: Error adding Membership: Error: addMembership EINVAL Apr 14 21:13:05 volumio sudo[15400]: pam_unix(sudo:session): session closed for user root Apr 14 21:13:05 volumio sudo[15398]: pam_unix(sudo:session): session closed for user root Apr 14 21:13:05 volumio volumio[15170]: info: Shairport-Sync Started Apr 14 21:13:05 volumio volumio[15170]: info: Shairport-Sync Started Apr 14 21:13:05 volumio volumio[15170]: info: Discovery: this is already registered, 072f109f-54a2-4344-b8c4-538b45da7e51 Apr 14 21:13:05 volumio volumio[15170]: info: Discovery: Found device Volumio Apr 14 21:13:05 volumio volumio[15170]: info: CoreCommandRouter::volumioGetState Apr 14 21:13:05 volumio volumio[15170]: info: CorePlayQueue::getTrack 0 Apr 14 21:13:05 volumio volumio[15170]: info: CoreCommandRouter::volumioGetState Apr 14 21:13:05 volumio volumio[15170]: info: CorePlayQueue::getTrack 0 Apr 14 21:13:05 volumio go-librespot[15389]: time="2026-04-14T21:13:05+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 21:13:05 volumio go-librespot[15389]: time="2026-04-14T21:13:05+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 21:13:05 volumio go-librespot[15389]: time="2026-04-14T21:13:05+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 21:13:05 volumio volumio[15170]: info: An error occurred while refreshing Spotify Token Error: Bad Request Apr 14 21:13:05 volumio go-librespot[15389]: time="2026-04-14T21:13:05+01:00" level=info msg="zeroconf server listening on port 43873" Apr 14 21:13:05 volumio mpd[15349]: 2026-04-14T21:13:05 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 14 21:13:05 volumio systemd[1]: Started mpd.service - Music Player Daemon. Apr 14 21:13:05 volumio sudo[15310]: pam_unix(sudo:session): session closed for user root Apr 14 21:13:05 volumio sudo[15320]: pam_unix(sudo:session): session closed for user root Apr 14 21:13:05 volumio volumio[15170]: info: Completed starting Core Plugins Apr 14 21:13:05 volumio volumio[15170]: info: ------------------------------------------- Apr 14 21:13:05 volumio volumio[15170]: info: ----- MyVolumio plugins startup ---- Apr 14 21:13:05 volumio volumio[15170]: info: ------------------------------------------- Apr 14 21:13:05 volumio volumio[15170]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 14 21:13:05 volumio volumio[15170]: error: MPD error: The expression evaluated to a falsy value: Apr 14 21:13:05 volumio volumio[15170]: assert.ok(self.idling) Apr 14 21:13:05 volumio volumio[15170]: error: The expression evaluated to a falsy value: Apr 14 21:13:05 volumio volumio[15170]: assert.ok(self.idling) Apr 14 21:13:05 volumio volumio[15170]: info: MPD running with PID15349 Apr 14 21:13:05 volumio volumio[15170]: ,establishing connection Apr 14 21:13:05 volumio volumio[15170]: error: updateQueue error: null Apr 14 21:13:05 volumio volumio[15170]: error: updateQueue error: null Apr 14 21:13:05 volumio go-librespot[15389]: time="2026-04-14T21:13:05+01:00" level=debug msg="obtained new client token: AACQ0UD0gqIPVxCdKogZeedogRvEYZoKbA/BTE9o5p/utDKtlkaBHNJv/KSKdtlyrdRV8NE4cM8vTuNkOaA/umGCSx3IPQ1BosgoJXl0w51a+NcAVirRrXLEJWA7m2TpUe7arkyA5qSobtP2xC+AmlQQoQosVW4JFnu31cI3R9N3MZXs7X64mcYwDarm7k48b+SKMnN7R95EOww8IZBTsY9h8h6NxDbTgJlBp7XfYrrvNgwTvR394dtAxw==" Apr 14 21:13:06 volumio go-librespot[15389]: time="2026-04-14T21:13:06+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 14 21:13:06 volumio go-librespot[15389]: time="2026-04-14T21:13:06+01:00" level=debug msg="completed keyexchange" Apr 14 21:13:06 volumio go-librespot[15389]: time="2026-04-14T21:13:06+01:00" level=debug msg="completed challenge" Apr 14 21:13:06 volumio go-librespot[15389]: time="2026-04-14T21:13:06+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:13:06 volumio volumio-remote-updater[945]: [2026-04-14 21:13:06] [connect] Successful connection Apr 14 21:13:06 volumio volumio-remote-updater[945]: [2026-04-14 21:13:06] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1776197586 101 Apr 14 21:13:06 volumio volumio[15170]: 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 21:13:06 volumio sudo[15209]: pam_unix(sudo:session): session closed for user root Apr 14 21:13:06 volumio go-librespot[15389]: time="2026-04-14T21:13:06+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 14 21:13:06 volumio go-librespot[15389]: time="2026-04-14T21:13:06+01:00" level=debug msg="completed keyexchange" Apr 14 21:13:06 volumio go-librespot[15389]: time="2026-04-14T21:13:06+01:00" level=debug msg="completed challenge" Apr 14 21:13:06 volumio go-librespot[15389]: time="2026-04-14T21:13:06+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:13:07 volumio go-librespot[15389]: time="2026-04-14T21:13:07+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 21:13:07 volumio go-librespot[15389]: time="2026-04-14T21:13:07+01:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Apr 14 21:13:07 volumio go-librespot[15389]: time="2026-04-14T21:13:07+01:00" level=debug msg="completed keyexchange" Apr 14 21:13:07 volumio go-librespot[15389]: time="2026-04-14T21:13:07+01:00" level=debug msg="completed challenge" Apr 14 21:13:07 volumio go-librespot[15389]: time="2026-04-14T21:13:07+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:13:08 volumio volumio[15170]: info: go-librespot daemon successfully initialized Apr 14 21:13:08 volumio go-librespot[15389]: time="2026-04-14T21:13:08+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Apr 14 21:13:08 volumio go-librespot[15389]: time="2026-04-14T21:13:08+01:00" level=debug msg="completed keyexchange" Apr 14 21:13:08 volumio go-librespot[15389]: time="2026-04-14T21:13:08+01:00" level=debug msg="completed challenge" Apr 14 21:13:08 volumio go-librespot[15389]: time="2026-04-14T21:13:08+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:13:09 volumio go-librespot[15389]: time="2026-04-14T21:13:09+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 14 21:13:09 volumio go-librespot[15389]: time="2026-04-14T21:13:09+01:00" level=debug msg="completed keyexchange" Apr 14 21:13:09 volumio go-librespot[15389]: time="2026-04-14T21:13:09+01:00" level=debug msg="completed challenge" Apr 14 21:13:09 volumio go-librespot[15389]: time="2026-04-14T21:13:09+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:13:10 volumio go-librespot[15389]: time="2026-04-14T21:13:10+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 14 21:13:10 volumio go-librespot[15389]: time="2026-04-14T21:13:10+01:00" level=debug msg="completed keyexchange" Apr 14 21:13:10 volumio go-librespot[15389]: time="2026-04-14T21:13:10+01:00" level=debug msg="completed challenge" Apr 14 21:13:10 volumio go-librespot[15389]: time="2026-04-14T21:13:10+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:13:10 volumio go-librespot[15389]: time="2026-04-14T21:13:10+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 21:13:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 21:13:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 21:13:11 volumio volumio[15170]: info: Initializing connection to go-librespot Websocket Apr 14 21:13:11 volumio volumio[15170]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 14 21:13:12 volumio sudo[15445]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 21:13:12 volumio sudo[15445]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:13:12 volumio sudo[15447]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 21:13:12 volumio sudo[15447]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:13:12 volumio sudo[15445]: pam_unix(sudo:session): session closed for user root Apr 14 21:13:12 volumio sudo[15447]: pam_unix(sudo:session): session closed for user root Apr 14 21:13:12 volumio sudo[15451]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 14 21:13:12 volumio sudo[15451]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:13:12 volumio sudo[15451]: pam_unix(sudo:session): session closed for user root Apr 14 21:13:12 volumio volumio[15170]: info: Upmpdcli Daemon Started Apr 14 21:13:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Apr 14 21:13:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 21:13:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 21:13:13 volumio go-librespot[15453]: go-librespot daemon starting... Apr 14 21:13:13 volumio go-librespot[15454]: time="2026-04-14T21:13:13+01:00" level=info msg="running go-librespot 0.6.2" Apr 14 21:13:13 volumio go-librespot[15454]: time="2026-04-14T21:13:13+01:00" level=debug msg="app state loaded" Apr 14 21:13:13 volumio go-librespot[15454]: time="2026-04-14T21:13:13+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 21:13:13 volumio go-librespot[15454]: time="2026-04-14T21:13:13+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 21:13:13 volumio go-librespot[15454]: time="2026-04-14T21:13:13+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 21:13:13 volumio go-librespot[15454]: time="2026-04-14T21:13:13+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 21:13:13 volumio go-librespot[15454]: time="2026-04-14T21:13:13+01:00" level=info msg="zeroconf server listening on port 41859" Apr 14 21:13:13 volumio go-librespot[15454]: time="2026-04-14T21:13:13+01:00" level=debug msg="obtained new client token: AADI5WU8xxVwQwYWZ7dDjBppVtuQE0NE/GIH90dn98JWdRXcc8xmgQQF3mwbZVIMYwB+te0jvfb4CDiKQrFuOEvvNTG9Lnx4/skE4Qx5YNbbg3vRo4vLR6LiVRI8V+R2+XGuZ1hwVq10oIFeM1dq0JrFakTtx7ffvrzgyiDPAuWKJJrzEiFh/lhd6hkC5XP4rXxNQdxIBsS3pW+MifHzK9oswKhbzEz2ar4dVK9Np86z5wUs3KsTAxLaXw==" Apr 14 21:13:13 volumio go-librespot[15454]: time="2026-04-14T21:13:13+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 21:13:13 volumio go-librespot[15454]: time="2026-04-14T21:13:13+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 14 21:13:13 volumio go-librespot[15454]: time="2026-04-14T21:13:13+01:00" level=debug msg="completed keyexchange" Apr 14 21:13:13 volumio go-librespot[15454]: time="2026-04-14T21:13:13+01:00" level=debug msg="completed challenge" Apr 14 21:13:13 volumio go-librespot[15454]: time="2026-04-14T21:13:13+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:13:14 volumio volumio[15170]: info: Initializing connection to go-librespot Websocket Apr 14 21:13:14 volumio go-librespot[15454]: time="2026-04-14T21:13:14+01:00" level=debug msg="new websocket client" Apr 14 21:13:14 volumio volumio[15170]: info: Connection to go-librespot Websocket established Apr 14 21:13:14 volumio go-librespot[15454]: time="2026-04-14T21:13:14+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 14 21:13:14 volumio go-librespot[15454]: time="2026-04-14T21:13:14+01:00" level=debug msg="completed keyexchange" Apr 14 21:13:14 volumio go-librespot[15454]: time="2026-04-14T21:13:14+01:00" level=debug msg="completed challenge" Apr 14 21:13:14 volumio go-librespot[15454]: time="2026-04-14T21:13:14+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:13:14 volumio volumio[15170]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 14 21:13:14 volumio volumio[15170]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 14 21:13:14 volumio volumio[15170]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 14 21:13:14 volumio volumio[15170]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 14 21:13:14 volumio volumio[15170]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 14 21:13:14 volumio volumio[15170]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 14 21:13:14 volumio volumio[15170]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 14 21:13:14 volumio volumio[15170]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 14 21:13:14 volumio volumio[15170]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 14 21:13:14 volumio volumio[15170]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 14 21:13:14 volumio volumio[15170]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Apr 14 21:13:14 volumio volumio[15170]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 14 21:13:14 volumio volumio[15170]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 14 21:13:14 volumio volumio[15170]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 14 21:13:14 volumio volumio[15170]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 14 21:13:14 volumio volumio[15170]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 14 21:13:14 volumio volumio[15170]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 14 21:13:14 volumio volumio[15170]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 14 21:13:14 volumio volumio[15170]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 14 21:13:14 volumio volumio[15170]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 14 21:13:14 volumio volumio[15170]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 14 21:13:14 volumio volumio[15170]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Apr 14 21:13:14 volumio volumio[15170]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 14 21:13:14 volumio volumio[15170]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 14 21:13:14 volumio volumio[15170]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 14 21:13:14 volumio volumio[15170]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 14 21:13:14 volumio volumio[15170]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 14 21:13:14 volumio volumio[15170]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 14 21:13:14 volumio volumio[15170]: info: Adding plugin bluetooth to MyMusic Plugins Apr 14 21:13:14 volumio volumio[15170]: info: Adding plugin multiroom to MyMusic Plugins Apr 14 21:13:14 volumio volumio[15170]: info: Adding plugin metavolumio to MyMusic Plugins Apr 14 21:13:14 volumio volumio[15170]: info: Adding plugin cd_controller to MyMusic Plugins Apr 14 21:13:14 volumio volumio[15170]: info: Adding plugin qobuzconnect to MyMusic Plugins Apr 14 21:13:14 volumio volumio[15170]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 14 21:13:14 volumio volumio[15170]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 14 21:13:14 volumio volumio[15170]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 14 21:13:15 volumio go-librespot[15454]: time="2026-04-14T21:13:15+01:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Apr 14 21:13:15 volumio go-librespot[15454]: time="2026-04-14T21:13:15+01:00" level=debug msg="completed keyexchange" Apr 14 21:13:15 volumio go-librespot[15454]: time="2026-04-14T21:13:15+01:00" level=debug msg="completed challenge" Apr 14 21:13:15 volumio volumio[15170]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 14 21:13:15 volumio volumio[15170]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 14 21:13:15 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:13:15 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:13:15 volumio volumio[15170]: info: Starting MyVolumio Remote Streaming Endpoints Apr 14 21:13:15 volumio volumio[15170]: info: MyVolumio login type: Token Apr 14 21:13:15 volumio volumio[15170]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 14 21:13:15 volumio volumio[15170]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 14 21:13:15 volumio go-librespot[15454]: time="2026-04-14T21:13:15+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:13:15 volumio volumio[15170]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 14 21:13:15 volumio volumio[15170]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 14 21:13:15 volumio volumio[15170]: info: Streaming services startup Apr 14 21:13:15 volumio volumio[15170]: info: Starting Streaming Daemon Apr 14 21:13:15 volumio sudo[15464]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 14 21:13:15 volumio sudo[15464]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:13:15 volumio volumio[15170]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 14 21:13:15 volumio sudo[15464]: pam_unix(sudo:session): session closed for user root Apr 14 21:13:15 volumio volumio[15170]: error: Cannot start Volumio Streaming Daemon Apr 14 21:13:15 volumio volumio[15170]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 14 21:13:15 volumio volumio[15170]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 14 21:13:15 volumio go-librespot[15454]: time="2026-04-14T21:13:15+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Apr 14 21:13:15 volumio go-librespot[15454]: time="2026-04-14T21:13:15+01:00" level=debug msg="completed keyexchange" Apr 14 21:13:15 volumio go-librespot[15454]: time="2026-04-14T21:13:15+01:00" level=debug msg="completed challenge" Apr 14 21:13:15 volumio go-librespot[15454]: time="2026-04-14T21:13:15+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:13:16 volumio volumio[15170]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 14 21:13:16 volumio go-librespot[15454]: time="2026-04-14T21:13:16+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 14 21:13:16 volumio volumio[15170]: info: MyVolumio token set successfully Apr 14 21:13:16 volumio volumio[15170]: info: MYVOLUMIO: Adding device Apr 14 21:13:16 volumio volumio[15170]: info: MYVOLUMIO: Evaluating Server Apr 14 21:13:16 volumio volumio[15170]: info: MyVolumio status changed Apr 14 21:13:16 volumio volumio[15170]: info: Streaming services startup Apr 14 21:13:16 volumio volumio[15170]: info: Starting Streaming Daemon Apr 14 21:13:16 volumio volumio[15170]: info: Removing browser output: myVolumio user plan is not superstar Apr 14 21:13:16 volumio volumio[15170]: info: Removing audio output: Apr 14 21:13:16 volumio volumio[15170]: info: Stoppping Tunnel 1 Apr 14 21:13:16 volumio sudo[15491]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 14 21:13:16 volumio sudo[15491]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:13:16 volumio go-librespot[15454]: time="2026-04-14T21:13:16+01:00" level=debug msg="completed keyexchange" Apr 14 21:13:16 volumio go-librespot[15454]: time="2026-04-14T21:13:16+01:00" level=debug msg="completed challenge" Apr 14 21:13:16 volumio sudo[15493]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Apr 14 21:13:16 volumio sudo[15493]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 21:13:16 volumio sudo[15491]: pam_unix(sudo:session): session closed for user root Apr 14 21:13:16 volumio volumio[15170]: error: Cannot start Volumio Streaming Daemon Apr 14 21:13:16 volumio volumio[15170]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 14 21:13:16 volumio volumio[15170]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 14 21:13:16 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 21:13:16 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 21:13:16 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 21:13:16 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 21:13:16 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 21:13:16 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 21:13:16 volumio sudo[15493]: pam_unix(sudo:session): session closed for user root Apr 14 21:13:16 volumio volumio[15170]: info: Remote SSH Stopped Apr 14 21:13:17 volumio volumio[15170]: info: Getting Spotify volume Apr 14 21:13:17 volumio volumio[15170]: 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 21:13:17 volumio go-librespot[15454]: time="2026-04-14T21:13:17+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:13:17 volumio volumio[15170]: info: Setting Geolocation for MyVolumio to eu12 Apr 14 21:13:17 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:13:17 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:13:17 volumio volumio[15170]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 21:13:17 volumio volumio[15170]: info: CoreCommandRouter::volumioGetState Apr 14 21:13:17 volumio volumio[15170]: info: CorePlayQueue::getTrack 0 Apr 14 21:13:17 volumio volumio[15170]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Apr 14 21:13:17 volumio volumio[15170]: SPOTIFY: SPOTIFY VOLUME undefined Apr 14 21:13:17 volumio volumio[15170]: SPOTIFY: VOLUMIO VOLUME 0 Apr 14 21:13:17 volumio volumio[15170]: info: Aligning Spotify Volume to Volumio Volume Apr 14 21:13:17 volumio volumio[15170]: info: CoreCommandRouter::volumioGetState Apr 14 21:13:17 volumio volumio[15170]: info: CorePlayQueue::getTrack 0 Apr 14 21:13:17 volumio volumio[15170]: info: Setting Spotify Volume from Volumio: 0 Apr 14 21:13:17 volumio volumio[15170]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Apr 14 21:13:17 volumio go-librespot[15454]: time="2026-04-14T21:13:17+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 14 21:13:17 volumio go-librespot[15454]: time="2026-04-14T21:13:17+01:00" level=debug msg="completed keyexchange" Apr 14 21:13:17 volumio go-librespot[15454]: time="2026-04-14T21:13:17+01:00" level=debug msg="completed challenge" Apr 14 21:13:17 volumio go-librespot[15454]: time="2026-04-14T21:13:17+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 21:13:17 volumio go-librespot[15454]: time="2026-04-14T21:13:17+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 21:13:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 21:13:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 21:13:17 volumio volumio[15170]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 21:13:17 volumio volumio[15170]: Error: socket hang up Apr 14 21:13:17 volumio volumio[15170]: at connResetException (node:internal/errors:720:14) Apr 14 21:13:17 volumio volumio[15170]: at Socket.socketOnEnd (node:_http_client:519:23) Apr 14 21:13:17 volumio volumio[15170]: at Socket.emit (node:events:526:35) Apr 14 21:13:17 volumio volumio[15170]: at endReadableNT (node:internal/streams/readable:1376:12) Apr 14 21:13:17 volumio volumio[15170]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Apr 14 21:13:17 volumio volumio[15170]: code: 'ECONNRESET', Apr 14 21:13:17 volumio volumio[15170]: response: undefined Apr 14 21:13:17 volumio volumio[15170]: } Apr 14 21:13:17 volumio volumio[15170]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 21:13:17 volumio sudo[15510]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-14 21:12' Apr 14 21:13:17 volumio sudo[15510]: 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"