Apr 15 06:01:00 volumio mpd[13624]: 2026-04-15T06:01:00 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 15 06:01:00 volumio systemd[1]: Started mpd.service - Music Player Daemon. Apr 15 06:01:00 volumio sudo[13595]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:00 volumio sudo[13586]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:00 volumio volumio[13456]: info: Completed starting Core Plugins Apr 15 06:01:00 volumio volumio[13456]: info: ------------------------------------------- Apr 15 06:01:00 volumio volumio[13456]: info: ----- MyVolumio plugins startup ---- Apr 15 06:01:00 volumio volumio[13456]: info: ------------------------------------------- Apr 15 06:01:00 volumio volumio[13456]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 15 06:01:00 volumio volumio[13456]: error: MPD error: The expression evaluated to a falsy value: Apr 15 06:01:00 volumio volumio[13456]: assert.ok(self.idling) Apr 15 06:01:00 volumio volumio[13456]: error: The expression evaluated to a falsy value: Apr 15 06:01:00 volumio volumio[13456]: assert.ok(self.idling) Apr 15 06:01:00 volumio volumio[13456]: info: MPD running with PID13624 Apr 15 06:01:00 volumio volumio[13456]: ,establishing connection Apr 15 06:01:00 volumio volumio[13456]: error: updateQueue error: null Apr 15 06:01:00 volumio volumio[13456]: error: updateQueue error: null Apr 15 06:01:00 volumio volumio[13456]: info: An error occurred while refreshing Spotify Token Error: Bad Request Apr 15 06:01:00 volumio go-librespot[13665]: time="2026-04-15T06:01:00+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 15 06:01:00 volumio go-librespot[13665]: time="2026-04-15T06:01:00+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 15 06:01:00 volumio go-librespot[13665]: time="2026-04-15T06:01:00+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 15 06:01:00 volumio go-librespot[13665]: time="2026-04-15T06:01:00+01:00" level=info msg="zeroconf server listening on port 46361" Apr 15 06:01:00 volumio go-librespot[13665]: time="2026-04-15T06:01:00+01:00" level=debug msg="obtained new client token: AAC/e+3GTRLgbns1/RoTsIizZMHU12d76wHYV+IduwVbTqSxPs2E5UtViUQlmfFXkMYkfyjj8ybk66P3fXWdwT/X8atfZv/EZATkfufxqpSvHXVyjof6KSZbGgtyM+UyU7hOf976+SJbLa5q92zaSsNmw/XIqXkogdgPVfAkTQOQAPa/ZTYJfpyq7yT49R52IrfMp93pYyVyWrxBrq86dkEcfUI6Scv8c0847NNQwIxQNaQQQyMsCEJ2Cg==" Apr 15 06:01:00 volumio go-librespot[13665]: time="2026-04-15T06:01:00+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 06:01:00 volumio volumio-remote-updater[945]: [2026-04-15 06:01:00] [connect] Successful connection Apr 15 06:01:00 volumio volumio-remote-updater[945]: [2026-04-15 06:01:00] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1776229260 101 Apr 15 06:01:00 volumio volumio[13456]: 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 15 06:01:00 volumio go-librespot[13665]: time="2026-04-15T06:01:00+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:00 volumio go-librespot[13665]: time="2026-04-15T06:01:00+01:00" level=debug msg="completed challenge" Apr 15 06:01:01 volumio go-librespot[13665]: time="2026-04-15T06:01:01+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:01 volumio sudo[13490]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:01 volumio go-librespot[13665]: time="2026-04-15T06:01:01+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 15 06:01:01 volumio go-librespot[13665]: time="2026-04-15T06:01:01+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:01 volumio go-librespot[13665]: time="2026-04-15T06:01:01+01:00" level=debug msg="completed challenge" Apr 15 06:01:01 volumio go-librespot[13665]: time="2026-04-15T06:01:01+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:02 volumio go-librespot[13665]: time="2026-04-15T06:01:02+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 15 06:01:02 volumio go-librespot[13665]: time="2026-04-15T06:01:02+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:02 volumio go-librespot[13665]: time="2026-04-15T06:01:02+01:00" level=debug msg="completed challenge" Apr 15 06:01:02 volumio go-librespot[13665]: time="2026-04-15T06:01:02+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:02 volumio volumio[13456]: info: go-librespot daemon successfully initialized Apr 15 06:01:02 volumio go-librespot[13665]: time="2026-04-15T06:01:02+01:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Apr 15 06:01:02 volumio go-librespot[13665]: time="2026-04-15T06:01:02+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:02 volumio go-librespot[13665]: time="2026-04-15T06:01:02+01:00" level=debug msg="completed challenge" Apr 15 06:01:03 volumio go-librespot[13665]: time="2026-04-15T06:01:03+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:03 volumio go-librespot[13665]: time="2026-04-15T06:01:03+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Apr 15 06:01:03 volumio go-librespot[13665]: time="2026-04-15T06:01:03+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:03 volumio go-librespot[13665]: time="2026-04-15T06:01:03+01:00" level=debug msg="completed challenge" Apr 15 06:01:03 volumio go-librespot[13665]: time="2026-04-15T06:01:03+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:04 volumio go-librespot[13665]: time="2026-04-15T06:01:04+01:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:80, retrying with a different AP" error="dial tcp 104.199.241.202:80: connect: connection refused" Apr 15 06:01:04 volumio go-librespot[13665]: time="2026-04-15T06:01:04+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 06:01:04 volumio go-librespot[13665]: time="2026-04-15T06:01:04+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:04 volumio go-librespot[13665]: time="2026-04-15T06:01:04+01:00" level=debug msg="completed challenge" Apr 15 06:01:04 volumio go-librespot[13665]: time="2026-04-15T06:01:04+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:04 volumio go-librespot[13665]: time="2026-04-15T06:01:04+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 06:01:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 06:01:05 volumio volumio[13456]: info: Initializing connection to go-librespot Websocket Apr 15 06:01:05 volumio volumio[13456]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 06:01:07 volumio sudo[13719]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 15 06:01:07 volumio sudo[13719]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:07 volumio sudo[13721]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 15 06:01:07 volumio sudo[13721]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:07 volumio sudo[13719]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:07 volumio sudo[13721]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:07 volumio sudo[13723]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 15 06:01:07 volumio sudo[13723]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:07 volumio sudo[13723]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:07 volumio volumio[13456]: info: Upmpdcli Daemon Started Apr 15 06:01:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Apr 15 06:01:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 15 06:01:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 15 06:01:07 volumio go-librespot[13727]: go-librespot daemon starting... Apr 15 06:01:07 volumio go-librespot[13728]: time="2026-04-15T06:01:07+01:00" level=info msg="running go-librespot 0.6.2" Apr 15 06:01:07 volumio go-librespot[13728]: time="2026-04-15T06:01:07+01:00" level=debug msg="app state loaded" Apr 15 06:01:07 volumio go-librespot[13728]: time="2026-04-15T06:01:07+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 06:01:07 volumio go-librespot[13728]: time="2026-04-15T06:01: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 15 06:01:07 volumio go-librespot[13728]: time="2026-04-15T06:01: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 15 06:01:07 volumio go-librespot[13728]: time="2026-04-15T06:01: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 15 06:01:07 volumio go-librespot[13728]: time="2026-04-15T06:01:07+01:00" level=info msg="zeroconf server listening on port 34319" Apr 15 06:01:07 volumio go-librespot[13728]: time="2026-04-15T06:01:07+01:00" level=debug msg="obtained new client token: AADkOAuZp8H4dio80m3DO6OP7EmUydjLovRDQXr5dWsPLj3SSbWMEnvu2DIMvBpJ+XA8/BQaYBq8quoZNDZccmO016UD8hOMhFuk3fJmzfUduxUqKYWQE0O3DeNM1OrofYlFNM3Oj5oH1EwrQZpCx4IHqX5u+E+RNmXCPcXKOtKO4HX5fbNrpqykFSZxduSUVM71buFZ2M2AsSSyuQDsqdjqhLcZtkAgFZ7ujrSWms4uJ23sIs0C8FDjJQ==" Apr 15 06:01:07 volumio go-librespot[13728]: time="2026-04-15T06:01:07+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 06:01:07 volumio go-librespot[13728]: time="2026-04-15T06:01:07+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:07 volumio go-librespot[13728]: time="2026-04-15T06:01:07+01:00" level=debug msg="completed challenge" Apr 15 06:01:08 volumio go-librespot[13728]: time="2026-04-15T06:01:08+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 15 06:01:08 volumio volumio[13456]: info: Adding plugin bluetooth to MyMusic Plugins Apr 15 06:01:08 volumio volumio[13456]: info: Adding plugin multiroom to MyMusic Plugins Apr 15 06:01:08 volumio volumio[13456]: info: Adding plugin metavolumio to MyMusic Plugins Apr 15 06:01:08 volumio volumio[13456]: info: Adding plugin cd_controller to MyMusic Plugins Apr 15 06:01:08 volumio volumio[13456]: info: Adding plugin qobuzconnect to MyMusic Plugins Apr 15 06:01:08 volumio volumio[13456]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 15 06:01:08 volumio volumio[13456]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 15 06:01:08 volumio go-librespot[13728]: time="2026-04-15T06:01:08+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 15 06:01:08 volumio go-librespot[13728]: time="2026-04-15T06:01:08+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:08 volumio go-librespot[13728]: time="2026-04-15T06:01:08+01:00" level=debug msg="completed challenge" Apr 15 06:01:08 volumio go-librespot[13728]: time="2026-04-15T06:01:08+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 15 06:01:08 volumio volumio[13456]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:08 volumio volumio[13456]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:08 volumio volumio[13456]: info: Starting MyVolumio Remote Streaming Endpoints Apr 15 06:01:08 volumio volumio[13456]: info: MyVolumio login type: Token Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 15 06:01:08 volumio volumio[13456]: info: Streaming services startup Apr 15 06:01:08 volumio volumio[13456]: info: Starting Streaming Daemon Apr 15 06:01:08 volumio sudo[13738]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 15 06:01:08 volumio sudo[13738]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:08 volumio volumio[13456]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 15 06:01:08 volumio sudo[13738]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:08 volumio volumio[13456]: info: Initializing connection to go-librespot Websocket Apr 15 06:01:08 volumio volumio[13456]: error: Cannot start Volumio Streaming Daemon Apr 15 06:01:08 volumio volumio[13456]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 15 06:01:08 volumio volumio[13456]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 15 06:01:08 volumio go-librespot[13728]: time="2026-04-15T06:01:08+01:00" level=debug msg="new websocket client" Apr 15 06:01:08 volumio volumio[13456]: info: Connection to go-librespot Websocket established Apr 15 06:01:09 volumio go-librespot[13728]: time="2026-04-15T06:01:09+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 15 06:01:09 volumio go-librespot[13728]: time="2026-04-15T06:01:09+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:09 volumio go-librespot[13728]: time="2026-04-15T06:01:09+01:00" level=debug msg="completed challenge" Apr 15 06:01:09 volumio go-librespot[13728]: time="2026-04-15T06:01:09+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:09 volumio volumio[13456]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 15 06:01:09 volumio volumio[13456]: info: MyVolumio token set successfully Apr 15 06:01:09 volumio volumio[13456]: info: MYVOLUMIO: Adding device Apr 15 06:01:09 volumio volumio[13456]: info: MYVOLUMIO: Evaluating Server Apr 15 06:01:09 volumio go-librespot[13728]: time="2026-04-15T06:01:09+01:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Apr 15 06:01:09 volumio volumio[13456]: info: MyVolumio status changed Apr 15 06:01:09 volumio volumio[13456]: info: Streaming services startup Apr 15 06:01:09 volumio volumio[13456]: info: Starting Streaming Daemon Apr 15 06:01:09 volumio volumio[13456]: info: Removing browser output: myVolumio user plan is not superstar Apr 15 06:01:09 volumio volumio[13456]: info: Removing audio output: Apr 15 06:01:09 volumio volumio[13456]: info: Stoppping Tunnel 1 Apr 15 06:01:09 volumio sudo[13765]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 15 06:01:09 volumio sudo[13765]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:09 volumio sudo[13767]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Apr 15 06:01:09 volumio sudo[13767]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:09 volumio go-librespot[13728]: time="2026-04-15T06:01:09+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:09 volumio go-librespot[13728]: time="2026-04-15T06:01:09+01:00" level=debug msg="completed challenge" Apr 15 06:01:09 volumio sudo[13765]: pam_unix(sudo:session): session closed for user root Apr 15 06:01: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 15 06:01: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 15 06:01:09 volumio volumio[13456]: error: Cannot start Volumio Streaming Daemon Apr 15 06:01:09 volumio volumio[13456]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 15 06:01:09 volumio volumio[13456]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 15 06:01: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 15 06:01: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 15 06:01: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 15 06:01: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 15 06:01:09 volumio sudo[13767]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:09 volumio volumio[13456]: info: Remote SSH Stopped Apr 15 06:01:10 volumio go-librespot[13728]: time="2026-04-15T06:01:10+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:10 volumio volumio[13456]: info: Setting Geolocation for MyVolumio to eu3 Apr 15 06:01:10 volumio volumio[13456]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:10 volumio volumio[13456]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:10 volumio volumio[13456]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:10 volumio volumio[13456]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Apr 15 06:01:10 volumio go-librespot[13728]: time="2026-04-15T06:01:10+01:00" level=debug msg="connected to ap-gue1.spotify.com:443" Apr 15 06:01:10 volumio go-librespot[13728]: time="2026-04-15T06:01:10+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:10 volumio go-librespot[13728]: time="2026-04-15T06:01:10+01:00" level=debug msg="completed challenge" Apr 15 06:01:10 volumio go-librespot[13728]: time="2026-04-15T06:01:10+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:11 volumio volumio[13456]: info: Updating MyVolumio device info Apr 15 06:01:11 volumio volumio[13456]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:11 volumio volumio[13456]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:11 volumio volumio[13456]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:11 volumio volumio[13456]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Apr 15 06:01:11 volumio go-librespot[13728]: time="2026-04-15T06:01:11+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 15 06:01:11 volumio go-librespot[13728]: time="2026-04-15T06:01:11+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:11 volumio go-librespot[13728]: time="2026-04-15T06:01:11+01:00" level=debug msg="completed challenge" Apr 15 06:01:11 volumio volumio[13456]: info: Getting Spotify volume Apr 15 06:01:11 volumio volumio[13456]: 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 15 06:01:12 volumio volumio[13456]: info: CoreCommandRouter::volumioGetState Apr 15 06:01:12 volumio volumio[13456]: info: CorePlayQueue::getTrack 0 Apr 15 06:01:12 volumio volumio[13456]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Apr 15 06:01:12 volumio volumio[13456]: SPOTIFY: SPOTIFY VOLUME undefined Apr 15 06:01:12 volumio volumio[13456]: SPOTIFY: VOLUMIO VOLUME 0 Apr 15 06:01:12 volumio volumio[13456]: info: Aligning Spotify Volume to Volumio Volume Apr 15 06:01:12 volumio volumio[13456]: info: CoreCommandRouter::volumioGetState Apr 15 06:01:12 volumio volumio[13456]: info: CorePlayQueue::getTrack 0 Apr 15 06:01:12 volumio volumio[13456]: info: Setting Spotify Volume from Volumio: 0 Apr 15 06:01:12 volumio go-librespot[13728]: time="2026-04-15T06:01:12+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:12 volumio go-librespot[13728]: time="2026-04-15T06:01:12+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 15 06:01:12 volumio volumio[13456]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 15 06:01:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 06:01:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 06:01:12 volumio volumio[13456]: Error: socket hang up Apr 15 06:01:12 volumio volumio[13456]: at connResetException (node:internal/errors:720:14) Apr 15 06:01:12 volumio volumio[13456]: at Socket.socketOnEnd (node:_http_client:519:23) Apr 15 06:01:12 volumio volumio[13456]: at Socket.emit (node:events:526:35) Apr 15 06:01:12 volumio volumio[13456]: at endReadableNT (node:internal/streams/readable:1376:12) Apr 15 06:01:12 volumio volumio[13456]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Apr 15 06:01:12 volumio volumio[13456]: code: 'ECONNRESET', Apr 15 06:01:12 volumio volumio[13456]: response: undefined Apr 15 06:01:12 volumio volumio[13456]: } Apr 15 06:01:12 volumio volumio[13456]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 15 06:01:12 volumio sudo[13784]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-15 06:00' Apr 15 06:01:12 volumio sudo[13784]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:12 volumio sudo[13784]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:12 volumio volumio-remote-updater[945]: [2026-04-15 06:01:12] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Apr 15 06:01:12 volumio volumio-remote-updater[945]: [2026-04-15 06:01:12] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Apr 15 06:01:12 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Apr 15 06:01:12 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Apr 15 06:01:12 volumio systemd[1]: volumio.service: Consumed 9.008s CPU time. Apr 15 06:01:12 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 15 06:01:12 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 15 06:01:12 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 121874. Apr 15 06:01:12 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 15 06:01:12 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Apr 15 06:01:12 volumio systemd[1]: volumio.service: Consumed 9.008s CPU time. Apr 15 06:01:12 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Apr 15 06:01:12 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 15 06:01:13 volumio volumio[13799]: info: ------------------------------------------- Apr 15 06:01:13 volumio volumio[13799]: info: ----- Volumio3 ---- Apr 15 06:01:13 volumio volumio[13799]: info: ------------------------------------------- Apr 15 06:01:13 volumio volumio[13799]: info: ----- System startup ---- Apr 15 06:01:13 volumio volumio[13799]: info: ------------------------------------------- Apr 15 06:01:13 volumio volumio[13799]: info: MYVOLUMIO Environment detected Apr 15 06:01:13 volumio volumio[13799]: info: Plugin folders cleanup Apr 15 06:01:13 volumio volumio[13799]: info: Scanning into folder /volumio/app/plugins/ Apr 15 06:01:13 volumio volumio[13799]: info: Scanning category audio_interface Apr 15 06:01:13 volumio volumio[13799]: info: Scanning category miscellanea Apr 15 06:01:13 volumio volumio[13799]: info: Scanning category music_service Apr 15 06:01:13 volumio volumio[13799]: info: Scanning category plugins.json Apr 15 06:01:13 volumio volumio[13799]: info: Scanning category system_controller Apr 15 06:01:13 volumio volumio[13799]: info: Scanning category user_interface Apr 15 06:01:13 volumio volumio[13799]: info: Scanning into folder /data/plugins/ Apr 15 06:01:13 volumio volumio[13799]: info: Scanning category music_service Apr 15 06:01:13 volumio volumio[13799]: info: Plugin folders cleanup completed Apr 15 06:01:13 volumio volumio[13799]: info: ------------------------------------------- Apr 15 06:01:13 volumio volumio[13799]: info: ----- Core plugins startup ---- Apr 15 06:01:13 volumio volumio[13799]: info: ------------------------------------------- Apr 15 06:01:13 volumio volumio[13799]: info: Loading plugins from folder /volumio/app/plugins/ Apr 15 06:01:13 volumio volumio[13799]: info: Adding plugin upnp to MyMusic Plugins Apr 15 06:01:13 volumio volumio[13799]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 15 06:01:13 volumio volumio[13799]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 15 06:01:13 volumio volumio[13799]: info: Loading plugins from folder /data/plugins/ Apr 15 06:01:13 volumio volumio[13799]: info: Adding plugin rtlsdr_radio to MyMusic Plugins Apr 15 06:01:13 volumio volumio[13799]: info: Loading plugin "system"... Apr 15 06:01:13 volumio volumio[13799]: info: Loading plugin "appearance"... Apr 15 06:01:14 volumio volumio[13799]: info: Loading plugin "network"... Apr 15 06:01:14 volumio volumio[13799]: info: Refreshing Cached IP Addresses Apr 15 06:01:14 volumio sudo[13827]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 15 06:01:14 volumio sudo[13827]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:14 volumio sudo[13829]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 15 06:01:14 volumio sudo[13829]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:14 volumio sudo[13827]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:14 volumio sudo[13829]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:14 volumio volumio[13799]: info: Loading plugin "services"... Apr 15 06:01:14 volumio volumio[13799]: info: Loading plugin "alsa_controller"... Apr 15 06:01:14 volumio sudo[13838]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 15 06:01:14 volumio sudo[13838]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:14 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 15 06:01:14 volumio volumio[13799]: info: Loading plugin "wizard"... Apr 15 06:01:14 volumio volumio[13799]: info: Loading plugin "networkfs"... Apr 15 06:01:14 volumio volumio[13799]: info: Starting Udev Watcher for removable devices Apr 15 06:01:14 volumio volumio[13799]: info: Mounting Device 0ACB-A1DE Apr 15 06:01:14 volumio sudo[13866]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/0ACB-A1DE -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Apr 15 06:01:14 volumio sudo[13866]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:14 volumio sudo[13866]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:14 volumio volumio[13799]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Apr 15 06:01:14 volumio volumio[13799]: dmesg(1) may have more information after failed mount system call. Apr 15 06:01:14 volumio volumio[13799]: 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 15 06:01:14 volumio volumio[13799]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Apr 15 06:01:14 volumio volumio[13799]: dmesg(1) may have more information after failed mount system call. Apr 15 06:01:14 volumio volumio[13799]: info: Ignoring mount for partition: boot Apr 15 06:01:14 volumio volumio[13799]: info: Ignoring mount for partition: volumio Apr 15 06:01:14 volumio volumio[13799]: info: Ignoring mount for partition: volumio_data Apr 15 06:01:14 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 15 06:01:14 volumio volumio[13799]: info: Loading plugin "volumio_command_line_client"... Apr 15 06:01:14 volumio volumio[13799]: info: Loading plugin "upnp"... Apr 15 06:01:14 volumio volumio[13799]: info: [1776229274128] Starting Upmpd Daemon Apr 15 06:01:14 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 15 06:01:14 volumio volumio[13799]: info: Loading plugin "my_music"... Apr 15 06:01:14 volumio volumio[13799]: info: Loading plugin "mpd"... Apr 15 06:01:14 volumio volumio[13799]: info: Loading plugin "upnp_browser"... Apr 15 06:01:14 volumio volumio[13799]: info: Starting UPNP Browser Apr 15 06:01:14 volumio volumio[13799]: info: Loading plugin "alarm-clock"... Apr 15 06:01:14 volumio volumio[13799]: info: Loading plugin "airplay_emulation"... Apr 15 06:01:14 volumio volumio[13799]: info: Starting Shairport Sync Apr 15 06:01:14 volumio volumio[13799]: info: Loading plugin "last_100"... Apr 15 06:01:14 volumio volumio[13799]: info: Loading plugin "webradio"... Apr 15 06:01:14 volumio volumio[13799]: info: Loading plugin "i2s_dacs"... Apr 15 06:01:14 volumio volumio[13799]: info: Loading plugin "volumiodiscovery"... Apr 15 06:01:14 volumio volumio[13799]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 15 06:01:14 volumio node[13799]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 15 06:01:14 volumio volumio[13799]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 15 06:01:14 volumio volumio[13799]: *** WARNING *** For more information see Apr 15 06:01:14 volumio volumio[13799]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 15 06:01:14 volumio volumio[13799]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 15 06:01:14 volumio volumio[13799]: *** WARNING *** For more information see Apr 15 06:01:14 volumio node[13799]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 15 06:01:14 volumio volumio[13799]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 15 06:01:14 volumio node[13799]: *** WARNING *** For more information see Apr 15 06:01:14 volumio node[13799]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 15 06:01:14 volumio node[13799]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 15 06:01:14 volumio node[13799]: *** WARNING *** For more information see Apr 15 06:01:14 volumio volumio[13799]: info: Discovery: Started advertising with name: Volumio Apr 15 06:01:14 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 15 06:01:14 volumio volumio[13799]: info: Loading plugin "spop"... Apr 15 06:01:15 volumio volumio[13799]: info: Loading plugin "ytmusic"... Apr 15 06:01:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Apr 15 06:01:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 15 06:01:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 15 06:01:15 volumio go-librespot[13870]: go-librespot daemon starting... Apr 15 06:01:15 volumio go-librespot[13871]: time="2026-04-15T06:01:15+01:00" level=info msg="running go-librespot 0.6.2" Apr 15 06:01:15 volumio go-librespot[13871]: time="2026-04-15T06:01:15+01:00" level=debug msg="app state loaded" Apr 15 06:01:15 volumio go-librespot[13871]: time="2026-04-15T06:01:15+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 06:01:15 volumio volumio[13799]: info: Loading plugin "outputs"... Apr 15 06:01:15 volumio volumio[13799]: info: Loading plugin "albumart"... Apr 15 06:01:15 volumio volumio[13799]: info: Plugin example_plugin is not enabled Apr 15 06:01:15 volumio volumio[13799]: info: Loading plugin "inputs"... Apr 15 06:01:15 volumio volumio[13799]: info: Loading plugin "updater_comm"... Apr 15 06:01:15 volumio volumio[13799]: info: Plugin mpdemulation is not enabled Apr 15 06:01:15 volumio volumio[13799]: info: Loading plugin "rest_api"... Apr 15 06:01:15 volumio volumio[13799]: info: Loading plugin "websocket"... Apr 15 06:01:15 volumio volumio[13799]: info: Starting Socket.io Server version 1.7.4 Apr 15 06:01:15 volumio volumio[13799]: info: Loading plugin "podcast"... Apr 15 06:01:15 volumio volumio[13799]: info: ControllerPodcast::constructor Apr 15 06:01:15 volumio volumio[13799]: info: Loading plugin "rtlsdr_radio"... Apr 15 06:01:15 volumio volumio[13877]: Forking 3 albumart workers Apr 15 06:01:15 volumio volumio[13799]: info: Loading i18n strings for locale en Apr 15 06:01:15 volumio volumio[13799]: Updating browse sources language Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 06:01:15 volumio go-librespot[13871]: time="2026-04-15T06:01:15+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 15 06:01:15 volumio go-librespot[13871]: time="2026-04-15T06:01:15+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 15 06:01:15 volumio go-librespot[13871]: time="2026-04-15T06:01:15+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::initPlayerControls Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 15 06:01:15 volumio volumio[13799]: Express server listening on port 3000 Apr 15 06:01:15 volumio volumio[13799]: [Metrics] WebUI: 2s 335.85ms Apr 15 06:01:15 volumio go-librespot[13871]: time="2026-04-15T06:01:15+01:00" level=info msg="zeroconf server listening on port 46627" Apr 15 06:01:15 volumio volumio[13799]: info: CoreStateMachine::resetVolumioState Apr 15 06:01:15 volumio volumio[13799]: info: CoreStateMachine::getcurrentVolume Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::volumioRetrievevolume Apr 15 06:01:15 volumio volumio[13799]: info: Volumio Network Manager: Network status updated: 2 Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:15 volumio volumio[13799]: info: Reloading queue from file Apr 15 06:01:15 volumio volumio[13799]: info: CoreStateMachine::setRepeat null single undefined Apr 15 06:01:15 volumio volumio[13799]: info: CoreStateMachine::pushState Apr 15 06:01:15 volumio volumio[13799]: info: CorePlayQueue::getTrack 0 Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::volumioPushState Apr 15 06:01:15 volumio volumio[13799]: info: CoreStateMachine::setRandom true Apr 15 06:01:15 volumio volumio[13799]: info: CoreStateMachine::pushState Apr 15 06:01:15 volumio volumio[13799]: info: CorePlayQueue::getTrack 0 Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::volumioPushState Apr 15 06:01:15 volumio volumio[13799]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Apr 15 06:01:15 volumio volumio[13799]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04170 Apr 15 06:01:15 volumio volumio[13799]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Apr 15 06:01:15 volumio volumio[13799]: info: VolumeController:: Volume=36 Mute =true Apr 15 06:01:15 volumio volumio[13799]: info: CoreStateMachine::pushState Apr 15 06:01:15 volumio volumio[13799]: info: CorePlayQueue::getTrack 0 Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::volumioPushState Apr 15 06:01:15 volumio volumio[13799]: info: CoreStateMachine::updateTrackBlock Apr 15 06:01:15 volumio volumio[13799]: info: CorePlayQueue::getTrackBlock Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::volumioRetrievevolume Apr 15 06:01:15 volumio volumio[13799]: info: Setting Device type: Raspberry PI Apr 15 06:01:15 volumio volumio[13799]: info: Completed loading Core Plugins Apr 15 06:01:15 volumio volumio[13799]: info: Preparing to generate the ALSA configuration file Apr 15 06:01:15 volumio volumio[13887]: Starting albumart workers Apr 15 06:01:15 volumio volumio[13799]: info: Asound.conf file unchanged, so no further update is needed Apr 15 06:01:15 volumio volumio[13799]: info: Output device has changed, restarting MPD Apr 15 06:01:15 volumio volumio[13799]: info: Output device has changed, restarting Shairport Sync Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:15 volumio sudo[13940]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 15 06:01:15 volumio sudo[13940]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:15 volumio volumio[13799]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 15 06:01:15 volumio volumio[13799]: info: ___________ START PLUGINS ___________ Apr 15 06:01:15 volumio sudo[13938]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 15 06:01:15 volumio sudo[13938]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:15 volumio volumio[13799]: info: ControllerMpd::onStart: Initializing MPD Apr 15 06:01:15 volumio volumio[13799]: info: Creating MPD Configuration file Apr 15 06:01:15 volumio sudo[13938]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:15 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 15 06:01:15 volumio sudo[13948]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 15 06:01:15 volumio sudo[13948]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:15 volumio sudo[13948]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 15 06:01:15 volumio volumio[13799]: info: [1776229275917] CoreMusicLibrary::Adding element Media Servers Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 06:01:15 volumio volumio[13799]: info: UPNP Browser: Client initialized successfully Apr 15 06:01:15 volumio sudo[13951]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 15 06:01:15 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 15 06:01:15 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 15 06:01:15 volumio sudo[13951]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:15 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 15 06:01:15 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 15 06:01:15 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:15 volumio volumio[13888]: Starting albumart workers Apr 15 06:01:15 volumio volumio[13799]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:15 volumio volumio[13799]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 15 06:01:15 volumio volumio[13799]: info: [1776229275965] CoreMusicLibrary::Adding element Last_100 Apr 15 06:01:15 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 15 06:01:15 volumio volumio[13799]: info: [1776229275967] CoreMusicLibrary::Adding element Webradio Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 06:01:15 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 15 06:01:15 volumio volumio[13889]: Starting albumart workers Apr 15 06:01:15 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 15 06:01:15 volumio volumio[13799]: info: Initializing BBC Radios Apr 15 06:01:15 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 15 06:01:15 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 15 06:01:15 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 15 06:01:15 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 15 06:01:15 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 15 06:01:15 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 15 06:01:15 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 15 06:01:16 volumio go-librespot[13871]: time="2026-04-15T06:01:16+01:00" level=debug msg="obtained new client token: AAAEB1QEXVuPVzWUnj4hGQZp5E2edOu66scNOQWeI29hcGbEiujwSNog2NmOZ4aNRy1/GWFBRPCCh4btEp4C5mdjIEjfwjIq2RJA6k3UvdnW5lpGSnz/Ro5PgQvgLULgK6fTwAm9s+09E5F20ocB7yT5CUmPAJl/sCkSGKjM9IKei/grPjGHeRMBg0Evo7Fc52yhk4nXjs2bKX2YUe61zTtH381Aq76OZ8FJLkwuSAYB2U/KHIt1MQo=" Apr 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:16 volumio sudo[13964]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 15 06:01:16 volumio sudo[13964]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 15 06:01:16 volumio volumio[13799]: info: Creating Spotify config file Apr 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:16 volumio sudo[13964]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:16 volumio go-librespot[13871]: time="2026-04-15T06:01:16+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 15 06:01:16 volumio volumio[13799]: info: [1776229276199] CoreMusicLibrary::Adding element YouTube Music Apr 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 06:01:16 volumio volumio[13799]: Cannot find translation for source YouTube Music Apr 15 06:01:16 volumio go-librespot[13871]: time="2026-04-15T06:01:16+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:16 volumio go-librespot[13871]: time="2026-04-15T06:01:16+01:00" level=debug msg="completed challenge" Apr 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 15 06:01:16 volumio volumio[13799]: info: [1776229276203] CoreMusicLibrary::Adding element Podcast Apr 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 06:01:16 volumio volumio[13799]: Cannot find translation for source YouTube Music Apr 15 06:01:16 volumio volumio[13799]: Cannot find translation for source Podcast Apr 15 06:01:16 volumio volumio[13799]: info: [RTL-SDR Radio] Starting plugin Apr 15 06:01:16 volumio volumio[13799]: info: [RTL-SDR Radio] Loaded i18n strings for language: en Apr 15 06:01:16 volumio volumio[13799]: info: Volumio Calling Home Apr 15 06:01:16 volumio volumio[13799]: info: [RTL-SDR Radio] snd-aloop already loaded Apr 15 06:01:16 volumio volumio[13799]: info: [RTL-SDR Radio] No stations database found, creating v2 Apr 15 06:01:16 volumio volumio[13799]: info: [RTL-SDR Radio] Database loaded at: 2026-04-15T05:01:16.263Z Apr 15 06:01:16 volumio volumio[13799]: info: [RTL-SDR Radio] Loading blocklist from: /data/plugins/music_service/rtlsdr_radio/blocklist.json Apr 15 06:01:16 volumio volumio[13799]: info: [RTL-SDR Radio] Got 21 phrases from file Apr 15 06:01:16 volumio volumio[13799]: info: [RTL-SDR Radio] Updated metadata blocklist Apr 15 06:01:16 volumio volumio[13799]: info: [RTL-SDR Radio] Metadata module now has 21 phrases Apr 15 06:01:16 volumio volumio[13799]: info: [RTL-SDR Radio] Management server started on port 3456 Apr 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 15 06:01:16 volumio volumio[13799]: info: [1776229276297] CoreMusicLibrary::Adding element FM/DAB Radio Apr 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 06:01:16 volumio volumio[13799]: Cannot find translation for source YouTube Music Apr 15 06:01:16 volumio volumio[13799]: Cannot find translation for source Podcast Apr 15 06:01:16 volumio volumio[13799]: Cannot find translation for source FM/DAB Radio Apr 15 06:01:16 volumio volumio[13799]: info: [RTL-SDR Radio] Plugin started successfully Apr 15 06:01:16 volumio volumio[13799]: info: VolumeController:: Volume=36 Mute =true Apr 15 06:01:16 volumio volumio[13799]: info: CoreStateMachine::pushState Apr 15 06:01:16 volumio volumio[13799]: info: CorePlayQueue::getTrack 0 Apr 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::volumioPushState Apr 15 06:01:16 volumio volumio[13799]: info: Discovery: adding 072f109f-54a2-4344-b8c4-538b45da7e51 Apr 15 06:01:16 volumio volumio[13799]: info: Discovery: Found device Volumio Apr 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::volumioGetState Apr 15 06:01:16 volumio volumio[13799]: info: CorePlayQueue::getTrack 0 Apr 15 06:01:16 volumio volumio[13799]: info: MPD Permissions set Apr 15 06:01:16 volumio volumio[13799]: info: MPD Permissions set Apr 15 06:01:16 volumio volumio[13799]: info: Spotify config file written Apr 15 06:01:16 volumio sudo[14006]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 15 06:01:16 volumio sudo[14006]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:16 volumio volumio[13799]: 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 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:16 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Apr 15 06:01:16 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Apr 15 06:01:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:16 volumio volumio[13799]: info: No need to fix Spotify hosts Apr 15 06:01:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 15 06:01:16 volumio go-librespot[14013]: go-librespot daemon starting... Apr 15 06:01:16 volumio sudo[14006]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:16 volumio volumio[13799]: info: Starting Shairport Sync Apr 15 06:01:16 volumio volumio[13799]: info: Starting Shairport Sync Apr 15 06:01:16 volumio go-librespot[14019]: time="2026-04-15T06:01:16+01:00" level=info msg="running go-librespot 0.6.2" Apr 15 06:01:16 volumio go-librespot[14019]: time="2026-04-15T06:01:16+01:00" level=debug msg="app state loaded" Apr 15 06:01:16 volumio volumio[13799]: info: Starting Shairport Sync Apr 15 06:01:16 volumio go-librespot[14019]: time="2026-04-15T06:01:16+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 06:01:16 volumio sudo[14025]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 15 06:01:16 volumio sudo[14027]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 15 06:01:16 volumio sudo[14025]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:16 volumio sudo[14027]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:16 volumio sudo[14032]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 15 06:01:16 volumio sudo[14032]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:16 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 15 06:01:16 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 15 06:01:16 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 15 06:01:16 volumio systemd[1]: shairport-sync.service: Consumed 1.537s CPU time. Apr 15 06:01:16 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 15 06:01:16 volumio sudo[14027]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:16 volumio sudo[14032]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:16 volumio sudo[14025]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:16 volumio volumio[13799]: info: Shairport-Sync Started Apr 15 06:01:16 volumio volumio[13799]: Error adding Membership: Error: addMembership EINVAL Apr 15 06:01:16 volumio volumio[13799]: info: Shairport-Sync Started Apr 15 06:01:16 volumio volumio[13799]: info: Shairport-Sync Started Apr 15 06:01:16 volumio volumio[13799]: info: Discovery: this is already registered, 072f109f-54a2-4344-b8c4-538b45da7e51 Apr 15 06:01:16 volumio volumio[13799]: info: Discovery: Found device Volumio Apr 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::volumioGetState Apr 15 06:01:16 volumio volumio[13799]: info: CorePlayQueue::getTrack 0 Apr 15 06:01:16 volumio volumio[13799]: info: Volumio called home Apr 15 06:01:16 volumio volumio[13799]: info: CoreCommandRouter::volumioGetState Apr 15 06:01:16 volumio volumio[13799]: info: CorePlayQueue::getTrack 0 Apr 15 06:01:16 volumio mpd[13979]: 2026-04-15T06:01:16 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 15 06:01:16 volumio systemd[1]: Started mpd.service - Music Player Daemon. Apr 15 06:01:16 volumio sudo[13951]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:16 volumio sudo[13940]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:16 volumio volumio[13799]: info: Completed starting Core Plugins Apr 15 06:01:16 volumio volumio[13799]: info: ------------------------------------------- Apr 15 06:01:16 volumio volumio[13799]: info: ----- MyVolumio plugins startup ---- Apr 15 06:01:16 volumio volumio[13799]: info: ------------------------------------------- Apr 15 06:01:16 volumio volumio[13799]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 15 06:01:16 volumio volumio[13799]: error: MPD error: The expression evaluated to a falsy value: Apr 15 06:01:16 volumio volumio[13799]: assert.ok(self.idling) Apr 15 06:01:16 volumio volumio[13799]: error: The expression evaluated to a falsy value: Apr 15 06:01:16 volumio volumio[13799]: assert.ok(self.idling) Apr 15 06:01:16 volumio volumio[13799]: error: updateQueue error: null Apr 15 06:01:16 volumio volumio[13799]: info: MPD running with PID13979 Apr 15 06:01:16 volumio volumio[13799]: ,establishing connection Apr 15 06:01:16 volumio volumio[13799]: error: updateQueue error: null Apr 15 06:01:16 volumio go-librespot[14019]: time="2026-04-15T06:01:16+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 15 06:01:16 volumio go-librespot[14019]: time="2026-04-15T06:01:16+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 15 06:01:16 volumio go-librespot[14019]: time="2026-04-15T06:01:16+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 15 06:01:16 volumio go-librespot[14019]: time="2026-04-15T06:01:16+01:00" level=info msg="zeroconf server listening on port 33409" Apr 15 06:01:17 volumio go-librespot[14019]: time="2026-04-15T06:01:17+01:00" level=debug msg="obtained new client token: AABzWIFvgFVZUAjL4FUE1YFxTIUH+Qn7hvbbUq3bT8X0tTVx5N0Bv+kNN/+n/LOTyZcL7VXrutNtavUai0nuY710c3l7XprIY+lYeMNlcrZKzBMnnFxqVzGfJJEN8PbcINQKT38U3BHDk5M7EJL7VvPdNZ/eDTsYXG46zLPh9Z7tEExRB8UuE+T+AA9vPm9RtEQ8x7Pxfz0sMoM83mEWuyO4ekC6HnzOqLIL1dorTr+xUH1dAWVosXE=" Apr 15 06:01:17 volumio go-librespot[14019]: time="2026-04-15T06:01:17+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 06:01:17 volumio go-librespot[14019]: time="2026-04-15T06:01:17+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:17 volumio go-librespot[14019]: time="2026-04-15T06:01:17+01:00" level=debug msg="completed challenge" Apr 15 06:01:17 volumio go-librespot[14019]: time="2026-04-15T06:01:17+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:17 volumio volumio-remote-updater[945]: [2026-04-15 06:01:17] [connect] Successful connection Apr 15 06:01:17 volumio volumio-remote-updater[945]: [2026-04-15 06:01:17] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1776229277 101 Apr 15 06:01:17 volumio volumio[13799]: 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 15 06:01:17 volumio sudo[13838]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:18 volumio go-librespot[14019]: time="2026-04-15T06:01:18+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 15 06:01:18 volumio go-librespot[14019]: time="2026-04-15T06:01:18+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 15 06:01:18 volumio go-librespot[14019]: time="2026-04-15T06:01:18+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:18 volumio go-librespot[14019]: time="2026-04-15T06:01:18+01:00" level=debug msg="completed challenge" Apr 15 06:01:18 volumio go-librespot[14019]: time="2026-04-15T06:01:18+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:18 volumio go-librespot[14019]: time="2026-04-15T06:01:18+01:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Apr 15 06:01:18 volumio go-librespot[14019]: time="2026-04-15T06:01:18+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:18 volumio go-librespot[14019]: time="2026-04-15T06:01:18+01:00" level=debug msg="completed challenge" Apr 15 06:01:19 volumio go-librespot[14019]: time="2026-04-15T06:01:19+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:19 volumio volumio[13799]: info: go-librespot daemon successfully initialized Apr 15 06:01:19 volumio go-librespot[14019]: time="2026-04-15T06:01:19+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Apr 15 06:01:19 volumio go-librespot[14019]: time="2026-04-15T06:01:19+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:19 volumio go-librespot[14019]: time="2026-04-15T06:01:19+01:00" level=debug msg="completed challenge" Apr 15 06:01:19 volumio go-librespot[14019]: time="2026-04-15T06:01:19+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:20 volumio go-librespot[14019]: time="2026-04-15T06:01:20+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 15 06:01:20 volumio go-librespot[14019]: time="2026-04-15T06:01:20+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:20 volumio go-librespot[14019]: time="2026-04-15T06:01:20+01:00" level=debug msg="completed challenge" Apr 15 06:01:20 volumio go-librespot[14019]: time="2026-04-15T06:01:20+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:21 volumio go-librespot[14019]: time="2026-04-15T06:01:21+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 06:01:21 volumio volumio[13799]: info: An error occurred while refreshing Spotify Token Error: Bad Request Apr 15 06:01:21 volumio go-librespot[14019]: time="2026-04-15T06:01:21+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:21 volumio go-librespot[14019]: time="2026-04-15T06:01:21+01:00" level=debug msg="completed challenge" Apr 15 06:01:21 volumio go-librespot[14019]: time="2026-04-15T06:01:21+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:21 volumio go-librespot[14019]: time="2026-04-15T06:01:21+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 15 06:01:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 06:01:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 06:01:22 volumio volumio[13799]: info: Initializing connection to go-librespot Websocket Apr 15 06:01:22 volumio volumio[13799]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 06:01:24 volumio sudo[14073]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 15 06:01:24 volumio sudo[14073]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:24 volumio sudo[14075]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 15 06:01:24 volumio sudo[14075]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:24 volumio sudo[14073]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:24 volumio sudo[14075]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:24 volumio sudo[14079]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 15 06:01:24 volumio sudo[14079]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:24 volumio sudo[14079]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:24 volumio volumio[13799]: info: Upmpdcli Daemon Started Apr 15 06:01:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Apr 15 06:01:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 15 06:01:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 15 06:01:24 volumio go-librespot[14081]: go-librespot daemon starting... Apr 15 06:01:24 volumio go-librespot[14082]: time="2026-04-15T06:01:24+01:00" level=info msg="running go-librespot 0.6.2" Apr 15 06:01:24 volumio go-librespot[14082]: time="2026-04-15T06:01:24+01:00" level=debug msg="app state loaded" Apr 15 06:01:24 volumio go-librespot[14082]: time="2026-04-15T06:01:24+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 06:01:24 volumio go-librespot[14082]: time="2026-04-15T06:01:24+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 15 06:01:24 volumio go-librespot[14082]: time="2026-04-15T06:01:24+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 15 06:01:24 volumio go-librespot[14082]: time="2026-04-15T06:01:24+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 15 06:01:24 volumio go-librespot[14082]: time="2026-04-15T06:01:24+01:00" level=info msg="zeroconf server listening on port 35317" Apr 15 06:01:24 volumio go-librespot[14082]: time="2026-04-15T06:01:24+01:00" level=debug msg="obtained new client token: AADZwIZQ/n6wiEdJ9MC+OflS+664sTRc6zrH0rhxHXzNhhtWGiwIbbmF/cPsSqeCHauYMCalJDB342ZMh6Vnnf+1YGxEDKTicSRhyB58TbpL4e3Z6q3VEbvj33yLYgti+jc0qr7oMfRvrBPZCfx8ow7oMC9aV6LhwtZ44R9enHcVBtXGwhpUq/TBsxHZ8Umgm9+G3u37faZ7USSyJiRpILnUC0WEMAcUsizGzaxiXC9aovsiYbRSB34tYA==" Apr 15 06:01:24 volumio go-librespot[14082]: time="2026-04-15T06:01:24+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 15 06:01:24 volumio go-librespot[14082]: time="2026-04-15T06:01:24+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 15 06:01:24 volumio go-librespot[14082]: time="2026-04-15T06:01:24+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:24 volumio go-librespot[14082]: time="2026-04-15T06:01:24+01:00" level=debug msg="completed challenge" Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 15 06:01:25 volumio go-librespot[14082]: time="2026-04-15T06:01:25+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 15 06:01:25 volumio volumio[13799]: info: Adding plugin bluetooth to MyMusic Plugins Apr 15 06:01:25 volumio volumio[13799]: info: Adding plugin multiroom to MyMusic Plugins Apr 15 06:01:25 volumio volumio[13799]: info: Adding plugin metavolumio to MyMusic Plugins Apr 15 06:01:25 volumio volumio[13799]: info: Adding plugin cd_controller to MyMusic Plugins Apr 15 06:01:25 volumio volumio[13799]: info: Adding plugin qobuzconnect to MyMusic Plugins Apr 15 06:01:25 volumio volumio[13799]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 15 06:01:25 volumio volumio[13799]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 15 06:01:25 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:25 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:25 volumio volumio[13799]: info: Starting MyVolumio Remote Streaming Endpoints Apr 15 06:01:25 volumio volumio[13799]: info: MyVolumio login type: Token Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 15 06:01:25 volumio go-librespot[14082]: time="2026-04-15T06:01:25+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 15 06:01:25 volumio volumio[13799]: info: Streaming services startup Apr 15 06:01:25 volumio volumio[13799]: info: Starting Streaming Daemon Apr 15 06:01:25 volumio go-librespot[14082]: time="2026-04-15T06:01:25+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:25 volumio go-librespot[14082]: time="2026-04-15T06:01:25+01:00" level=debug msg="completed challenge" Apr 15 06:01:25 volumio sudo[14093]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 15 06:01:25 volumio sudo[14093]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:25 volumio volumio[13799]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 15 06:01:25 volumio sudo[14093]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:25 volumio go-librespot[14082]: time="2026-04-15T06:01:25+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:25 volumio volumio[13799]: info: Initializing connection to go-librespot Websocket Apr 15 06:01:25 volumio volumio[13799]: error: Cannot start Volumio Streaming Daemon Apr 15 06:01:25 volumio volumio[13799]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 15 06:01:25 volumio volumio[13799]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 15 06:01:25 volumio go-librespot[14082]: time="2026-04-15T06:01:25+01:00" level=debug msg="new websocket client" Apr 15 06:01:25 volumio volumio[13799]: info: Connection to go-librespot Websocket established Apr 15 06:01:26 volumio volumio[13799]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 15 06:01:26 volumio go-librespot[14082]: time="2026-04-15T06:01:26+01:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Apr 15 06:01:26 volumio go-librespot[14082]: time="2026-04-15T06:01:26+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:26 volumio go-librespot[14082]: time="2026-04-15T06:01:26+01:00" level=debug msg="completed challenge" Apr 15 06:01:26 volumio volumio[13799]: info: MyVolumio token set successfully Apr 15 06:01:26 volumio volumio[13799]: info: MYVOLUMIO: Adding device Apr 15 06:01:26 volumio volumio[13799]: info: MYVOLUMIO: Evaluating Server Apr 15 06:01:26 volumio go-librespot[14082]: time="2026-04-15T06:01:26+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:26 volumio volumio[13799]: info: MyVolumio status changed Apr 15 06:01:26 volumio volumio[13799]: info: Streaming services startup Apr 15 06:01:26 volumio volumio[13799]: info: Starting Streaming Daemon Apr 15 06:01:26 volumio volumio[13799]: info: Removing browser output: myVolumio user plan is not superstar Apr 15 06:01:26 volumio volumio[13799]: info: Removing audio output: Apr 15 06:01:26 volumio volumio[13799]: info: Stoppping Tunnel 1 Apr 15 06:01:26 volumio sudo[14120]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 15 06:01:26 volumio sudo[14120]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:26 volumio sudo[14122]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Apr 15 06:01:26 volumio sudo[14122]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:26 volumio sudo[14120]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:26 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 15 06:01:26 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 15 06:01:26 volumio volumio[13799]: error: Cannot start Volumio Streaming Daemon Apr 15 06:01:26 volumio volumio[13799]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 15 06:01:26 volumio volumio[13799]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 15 06:01:26 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 15 06:01:26 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 15 06:01:26 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 15 06:01:26 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 15 06:01:26 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 15 06:01:26 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 15 06:01:26 volumio sudo[14122]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:26 volumio volumio[13799]: info: Remote SSH Stopped Apr 15 06:01:26 volumio volumio[13799]: info: Setting Geolocation for MyVolumio to eu3 Apr 15 06:01:26 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:26 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:26 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:27 volumio go-librespot[14082]: time="2026-04-15T06:01:27+01:00" level=debug msg="connected to ap-gue1.spotify.com:443" Apr 15 06:01:27 volumio go-librespot[14082]: time="2026-04-15T06:01:27+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:27 volumio go-librespot[14082]: time="2026-04-15T06:01:27+01:00" level=debug msg="completed challenge" Apr 15 06:01:27 volumio go-librespot[14082]: time="2026-04-15T06:01:27+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:27 volumio volumio[13799]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Apr 15 06:01:27 volumio volumio[13799]: info: Updating MyVolumio device info Apr 15 06:01:27 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:27 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:27 volumio volumio[13799]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:27 volumio go-librespot[14082]: time="2026-04-15T06:01:27+01:00" level=debug msg="connected to ap-gew4.spotify.com:80" Apr 15 06:01:27 volumio go-librespot[14082]: time="2026-04-15T06:01:27+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:27 volumio go-librespot[14082]: time="2026-04-15T06:01:27+01:00" level=debug msg="completed challenge" Apr 15 06:01:27 volumio go-librespot[14082]: time="2026-04-15T06:01:27+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:28 volumio volumio[13799]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Apr 15 06:01:28 volumio go-librespot[14082]: time="2026-04-15T06:01:28+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 06:01:28 volumio go-librespot[14082]: time="2026-04-15T06:01:28+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:28 volumio go-librespot[14082]: time="2026-04-15T06:01:28+01:00" level=debug msg="completed challenge" Apr 15 06:01:28 volumio go-librespot[14082]: time="2026-04-15T06:01:28+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:28 volumio go-librespot[14082]: time="2026-04-15T06:01:28+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 06:01:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 06:01:28 volumio volumio[13799]: info: Connection to go-librespot Websocket closed Apr 15 06:01:28 volumio volumio[13799]: info: Getting Spotify volume Apr 15 06:01:28 volumio volumio[13799]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 15 06:01:28 volumio volumio[13799]: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 06:01:28 volumio volumio[13799]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Apr 15 06:01:28 volumio volumio[13799]: errno: -111, Apr 15 06:01:28 volumio volumio[13799]: code: 'ECONNREFUSED', Apr 15 06:01:28 volumio volumio[13799]: syscall: 'connect', Apr 15 06:01:28 volumio volumio[13799]: address: '127.0.0.1', Apr 15 06:01:28 volumio volumio[13799]: port: 9879, Apr 15 06:01:28 volumio volumio[13799]: response: undefined Apr 15 06:01:28 volumio volumio[13799]: } Apr 15 06:01:28 volumio volumio[13799]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 15 06:01:28 volumio sudo[14139]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-15 06:00' Apr 15 06:01:28 volumio sudo[14139]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:28 volumio sudo[14139]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:29 volumio volumio-remote-updater[945]: [2026-04-15 06:01:29] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Apr 15 06:01:29 volumio volumio-remote-updater[945]: [2026-04-15 06:01:29] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Apr 15 06:01:29 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Apr 15 06:01:29 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Apr 15 06:01:29 volumio systemd[1]: volumio.service: Consumed 9.046s CPU time. Apr 15 06:01:29 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 15 06:01:29 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 15 06:01:29 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 121875. Apr 15 06:01:29 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 15 06:01:29 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Apr 15 06:01:29 volumio systemd[1]: volumio.service: Consumed 9.046s CPU time. Apr 15 06:01:29 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Apr 15 06:01:29 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 15 06:01:30 volumio volumio[14154]: info: ------------------------------------------- Apr 15 06:01:30 volumio volumio[14154]: info: ----- Volumio3 ---- Apr 15 06:01:30 volumio volumio[14154]: info: ------------------------------------------- Apr 15 06:01:30 volumio volumio[14154]: info: ----- System startup ---- Apr 15 06:01:30 volumio volumio[14154]: info: ------------------------------------------- Apr 15 06:01:30 volumio volumio[14154]: info: MYVOLUMIO Environment detected Apr 15 06:01:30 volumio volumio[14154]: info: Plugin folders cleanup Apr 15 06:01:30 volumio volumio[14154]: info: Scanning into folder /volumio/app/plugins/ Apr 15 06:01:30 volumio volumio[14154]: info: Scanning category audio_interface Apr 15 06:01:30 volumio volumio[14154]: info: Scanning category miscellanea Apr 15 06:01:30 volumio volumio[14154]: info: Scanning category music_service Apr 15 06:01:30 volumio volumio[14154]: info: Scanning category plugins.json Apr 15 06:01:30 volumio volumio[14154]: info: Scanning category system_controller Apr 15 06:01:30 volumio volumio[14154]: info: Scanning category user_interface Apr 15 06:01:30 volumio volumio[14154]: info: Scanning into folder /data/plugins/ Apr 15 06:01:30 volumio volumio[14154]: info: Scanning category music_service Apr 15 06:01:30 volumio volumio[14154]: info: Plugin folders cleanup completed Apr 15 06:01:30 volumio volumio[14154]: info: ------------------------------------------- Apr 15 06:01:30 volumio volumio[14154]: info: ----- Core plugins startup ---- Apr 15 06:01:30 volumio volumio[14154]: info: ------------------------------------------- Apr 15 06:01:30 volumio volumio[14154]: info: Loading plugins from folder /volumio/app/plugins/ Apr 15 06:01:30 volumio volumio[14154]: info: Adding plugin upnp to MyMusic Plugins Apr 15 06:01:30 volumio volumio[14154]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 15 06:01:30 volumio volumio[14154]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 15 06:01:30 volumio volumio[14154]: info: Loading plugins from folder /data/plugins/ Apr 15 06:01:30 volumio volumio[14154]: info: Adding plugin rtlsdr_radio to MyMusic Plugins Apr 15 06:01:30 volumio volumio[14154]: info: Loading plugin "system"... Apr 15 06:01:30 volumio volumio[14154]: info: Loading plugin "appearance"... Apr 15 06:01:30 volumio volumio[14154]: info: Loading plugin "network"... Apr 15 06:01:30 volumio volumio[14154]: info: Refreshing Cached IP Addresses Apr 15 06:01:30 volumio sudo[14182]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 15 06:01:30 volumio sudo[14182]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:30 volumio sudo[14184]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 15 06:01:30 volumio sudo[14184]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:30 volumio sudo[14182]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:30 volumio sudo[14184]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:30 volumio volumio[14154]: info: Loading plugin "services"... Apr 15 06:01:30 volumio volumio[14154]: info: Loading plugin "alsa_controller"... Apr 15 06:01:30 volumio sudo[14193]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 15 06:01:30 volumio sudo[14193]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:30 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 15 06:01:30 volumio volumio[14154]: info: Loading plugin "wizard"... Apr 15 06:01:30 volumio volumio[14154]: info: Loading plugin "networkfs"... Apr 15 06:01:30 volumio volumio[14154]: info: Starting Udev Watcher for removable devices Apr 15 06:01:30 volumio volumio[14154]: info: Mounting Device 0ACB-A1DE Apr 15 06:01:30 volumio sudo[14221]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/0ACB-A1DE -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Apr 15 06:01:30 volumio sudo[14221]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:30 volumio sudo[14221]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:30 volumio volumio[14154]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Apr 15 06:01:30 volumio volumio[14154]: dmesg(1) may have more information after failed mount system call. Apr 15 06:01:30 volumio volumio[14154]: 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 15 06:01:30 volumio volumio[14154]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Apr 15 06:01:30 volumio volumio[14154]: dmesg(1) may have more information after failed mount system call. Apr 15 06:01:30 volumio volumio[14154]: info: Ignoring mount for partition: boot Apr 15 06:01:30 volumio volumio[14154]: info: Ignoring mount for partition: volumio Apr 15 06:01:30 volumio volumio[14154]: info: Ignoring mount for partition: volumio_data Apr 15 06:01:30 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 15 06:01:30 volumio volumio[14154]: info: Loading plugin "volumio_command_line_client"... Apr 15 06:01:30 volumio volumio[14154]: info: Loading plugin "upnp"... Apr 15 06:01:30 volumio volumio[14154]: info: [1776229290858] Starting Upmpd Daemon Apr 15 06:01:30 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 15 06:01:30 volumio volumio[14154]: info: Loading plugin "my_music"... Apr 15 06:01:30 volumio volumio[14154]: info: Loading plugin "mpd"... Apr 15 06:01:30 volumio volumio[14154]: info: Loading plugin "upnp_browser"... Apr 15 06:01:31 volumio volumio[14154]: info: Starting UPNP Browser Apr 15 06:01:31 volumio volumio[14154]: info: Loading plugin "alarm-clock"... Apr 15 06:01:31 volumio volumio[14154]: info: Loading plugin "airplay_emulation"... Apr 15 06:01:31 volumio volumio[14154]: info: Starting Shairport Sync Apr 15 06:01:31 volumio volumio[14154]: info: Loading plugin "last_100"... Apr 15 06:01:31 volumio volumio[14154]: info: Loading plugin "webradio"... Apr 15 06:01:31 volumio volumio[14154]: info: Loading plugin "i2s_dacs"... Apr 15 06:01:31 volumio volumio[14154]: info: Loading plugin "volumiodiscovery"... Apr 15 06:01:31 volumio volumio[14154]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 15 06:01:31 volumio volumio[14154]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 15 06:01:31 volumio volumio[14154]: *** WARNING *** For more information see Apr 15 06:01:31 volumio volumio[14154]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 15 06:01:31 volumio volumio[14154]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 15 06:01:31 volumio node[14154]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 15 06:01:31 volumio volumio[14154]: *** WARNING *** For more information see Apr 15 06:01:31 volumio node[14154]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 15 06:01:31 volumio node[14154]: *** WARNING *** For more information see Apr 15 06:01:31 volumio node[14154]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 15 06:01:31 volumio node[14154]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 15 06:01:31 volumio node[14154]: *** WARNING *** For more information see Apr 15 06:01:31 volumio volumio[14154]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 15 06:01:31 volumio volumio[14154]: info: Discovery: Started advertising with name: Volumio Apr 15 06:01:31 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 15 06:01:31 volumio volumio[14154]: info: Loading plugin "spop"... Apr 15 06:01:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Apr 15 06:01:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 15 06:01:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 15 06:01:31 volumio go-librespot[14225]: go-librespot daemon starting... Apr 15 06:01:31 volumio go-librespot[14226]: time="2026-04-15T06:01:31+01:00" level=info msg="running go-librespot 0.6.2" Apr 15 06:01:31 volumio go-librespot[14226]: time="2026-04-15T06:01:31+01:00" level=debug msg="app state loaded" Apr 15 06:01:31 volumio go-librespot[14226]: time="2026-04-15T06:01:31+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 06:01:31 volumio volumio[14154]: info: Loading plugin "ytmusic"... Apr 15 06:01:31 volumio go-librespot[14226]: time="2026-04-15T06:01:31+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 15 06:01:31 volumio go-librespot[14226]: time="2026-04-15T06:01:31+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Apr 15 06:01:31 volumio go-librespot[14226]: time="2026-04-15T06:01:31+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Apr 15 06:01:31 volumio go-librespot[14226]: time="2026-04-15T06:01:31+01:00" level=info msg="zeroconf server listening on port 40527" Apr 15 06:01:32 volumio volumio[14154]: info: Loading plugin "outputs"... Apr 15 06:01:32 volumio volumio[14154]: info: Loading plugin "albumart"... Apr 15 06:01:32 volumio volumio[14154]: info: Plugin example_plugin is not enabled Apr 15 06:01:32 volumio volumio[14154]: info: Loading plugin "inputs"... Apr 15 06:01:32 volumio volumio[14154]: info: Loading plugin "updater_comm"... Apr 15 06:01:32 volumio volumio[14154]: info: Plugin mpdemulation is not enabled Apr 15 06:01:32 volumio volumio[14154]: info: Loading plugin "rest_api"... Apr 15 06:01:32 volumio volumio[14154]: info: Loading plugin "websocket"... Apr 15 06:01:32 volumio volumio[14154]: info: Starting Socket.io Server version 1.7.4 Apr 15 06:01:32 volumio volumio[14154]: info: Loading plugin "podcast"... Apr 15 06:01:32 volumio volumio[14154]: info: ControllerPodcast::constructor Apr 15 06:01:32 volumio volumio[14154]: info: Loading plugin "rtlsdr_radio"... Apr 15 06:01:32 volumio volumio[14235]: Forking 3 albumart workers Apr 15 06:01:32 volumio go-librespot[14226]: time="2026-04-15T06:01:32+01:00" level=debug msg="obtained new client token: AAAafFeBwHe/VxdP8x++xEhBiw0M9cedQKAWdHGamPfbXVIPMCBKeYBg1EO4EKDwRv1MsmaOLwQLEl7jaQRtaHUVTomdZdZ48oh3/7usGPOGeYml+IMHTM8Q8VLpTGzOsloJdl6+8PzpNa2OkTyHWvOlc5fjMbj6wyGT4YIWaumFbQNeJjddWcAhuzHGvTTZewXwxfjIfY6v3zug2MwEeBSL3/p9BkmrnlkbSYEV0O18PaflRetNZEM=" Apr 15 06:01:32 volumio volumio[14154]: info: Loading i18n strings for locale en Apr 15 06:01:32 volumio volumio[14154]: Updating browse sources language Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::initPlayerControls Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:32 volumio go-librespot[14226]: time="2026-04-15T06:01:32+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 15 06:01:32 volumio volumio[14154]: Express server listening on port 3000 Apr 15 06:01:32 volumio volumio[14154]: [Metrics] WebUI: 2s 292.36ms Apr 15 06:01:32 volumio volumio[14154]: info: CoreStateMachine::resetVolumioState Apr 15 06:01:32 volumio volumio[14154]: info: CoreStateMachine::getcurrentVolume Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::volumioRetrievevolume Apr 15 06:01:32 volumio volumio[14154]: info: Volumio Network Manager: Network status updated: 2 Apr 15 06:01:32 volumio volumio[14154]: info: VolumeController:: Volume=36 Mute =true Apr 15 06:01:32 volumio volumio[14154]: info: CoreStateMachine::pushState Apr 15 06:01:32 volumio volumio[14154]: info: CorePlayQueue::getTrack 0 Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::volumioPushState Apr 15 06:01:32 volumio volumio[14154]: info: CoreStateMachine::updateTrackBlock Apr 15 06:01:32 volumio volumio[14154]: info: CorePlayQueue::getTrackBlock Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::volumioRetrievevolume Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:32 volumio volumio[14154]: info: Reloading queue from file Apr 15 06:01:32 volumio volumio[14154]: info: CoreStateMachine::setRepeat null single undefined Apr 15 06:01:32 volumio volumio[14154]: info: CoreStateMachine::pushState Apr 15 06:01:32 volumio volumio[14154]: info: CorePlayQueue::getTrack 0 Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::volumioPushState Apr 15 06:01:32 volumio volumio[14154]: info: CoreStateMachine::setRandom true Apr 15 06:01:32 volumio volumio[14154]: info: CoreStateMachine::pushState Apr 15 06:01:32 volumio volumio[14154]: info: CorePlayQueue::getTrack 0 Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::volumioPushState Apr 15 06:01:32 volumio volumio[14154]: info: Setting Device type: Raspberry PI Apr 15 06:01:32 volumio volumio[14154]: info: Completed loading Core Plugins Apr 15 06:01:32 volumio volumio[14154]: info: Preparing to generate the ALSA configuration file Apr 15 06:01:32 volumio volumio[14154]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Apr 15 06:01:32 volumio volumio[14154]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04170 Apr 15 06:01:32 volumio volumio[14154]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Apr 15 06:01:32 volumio go-librespot[14226]: time="2026-04-15T06:01:32+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:32 volumio go-librespot[14226]: time="2026-04-15T06:01:32+01:00" level=debug msg="completed challenge" Apr 15 06:01:32 volumio volumio[14245]: Starting albumart workers Apr 15 06:01:32 volumio volumio[14154]: info: VolumeController:: Volume=36 Mute =true Apr 15 06:01:32 volumio volumio[14154]: info: CoreStateMachine::pushState Apr 15 06:01:32 volumio volumio[14154]: info: CorePlayQueue::getTrack 0 Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::volumioPushState Apr 15 06:01:32 volumio volumio[14154]: info: Asound.conf file unchanged, so no further update is needed Apr 15 06:01:32 volumio volumio[14154]: info: Output device has changed, restarting MPD Apr 15 06:01:32 volumio go-librespot[14226]: time="2026-04-15T06:01:32+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:32 volumio volumio[14154]: info: Output device has changed, restarting Shairport Sync Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:32 volumio sudo[14291]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 15 06:01:32 volumio sudo[14293]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 15 06:01:32 volumio sudo[14293]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:32 volumio volumio[14247]: Starting albumart workers Apr 15 06:01:32 volumio sudo[14291]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:32 volumio volumio[14154]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 15 06:01:32 volumio volumio[14154]: info: ___________ START PLUGINS ___________ Apr 15 06:01:32 volumio sudo[14291]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:32 volumio volumio[14154]: info: ControllerMpd::onStart: Initializing MPD Apr 15 06:01:32 volumio volumio[14154]: info: Creating MPD Configuration file Apr 15 06:01:32 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 15 06:01:32 volumio volumio[14154]: info: [1776229292639] CoreMusicLibrary::Adding element Media Servers Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 06:01:32 volumio sudo[14301]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 15 06:01:32 volumio sudo[14301]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:32 volumio volumio[14154]: info: UPNP Browser: Client initialized successfully Apr 15 06:01:32 volumio sudo[14301]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:32 volumio sudo[14303]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 15 06:01:32 volumio sudo[14303]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:32 volumio volumio[14246]: Starting albumart workers Apr 15 06:01:32 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 15 06:01:32 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 15 06:01:32 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 15 06:01:32 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 15 06:01:32 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:32 volumio volumio[14154]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:32 volumio volumio[14154]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 15 06:01:32 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 15 06:01:32 volumio volumio[14154]: info: [1776229292695] CoreMusicLibrary::Adding element Last_100 Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 15 06:01:32 volumio volumio[14154]: info: [1776229292696] CoreMusicLibrary::Adding element Webradio Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 06:01:32 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 15 06:01:32 volumio volumio[14154]: info: Initializing BBC Radios Apr 15 06:01:32 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 15 06:01:32 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 15 06:01:32 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 15 06:01:32 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 15 06:01:32 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 15 06:01:32 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 15 06:01:32 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:32 volumio volumio[14154]: info: Creating Spotify config file Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:32 volumio sudo[14330]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 15 06:01:32 volumio sudo[14330]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 15 06:01:32 volumio sudo[14330]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 15 06:01:32 volumio volumio[14154]: info: [1776229292893] CoreMusicLibrary::Adding element YouTube Music Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 06:01:32 volumio volumio[14154]: Cannot find translation for source YouTube Music Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 15 06:01:32 volumio volumio[14154]: info: [1776229292902] CoreMusicLibrary::Adding element Podcast Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 06:01:32 volumio volumio[14154]: Cannot find translation for source YouTube Music Apr 15 06:01:32 volumio volumio[14154]: Cannot find translation for source Podcast Apr 15 06:01:32 volumio volumio[14154]: info: [RTL-SDR Radio] Starting plugin Apr 15 06:01:32 volumio volumio[14154]: info: [RTL-SDR Radio] Loaded i18n strings for language: en Apr 15 06:01:32 volumio volumio[14154]: info: Volumio Calling Home Apr 15 06:01:32 volumio volumio[14154]: info: [RTL-SDR Radio] snd-aloop already loaded Apr 15 06:01:32 volumio volumio[14154]: info: [RTL-SDR Radio] No stations database found, creating v2 Apr 15 06:01:32 volumio volumio[14154]: info: [RTL-SDR Radio] Database loaded at: 2026-04-15T05:01:32.959Z Apr 15 06:01:32 volumio volumio[14154]: info: [RTL-SDR Radio] Loading blocklist from: /data/plugins/music_service/rtlsdr_radio/blocklist.json Apr 15 06:01:32 volumio volumio[14154]: info: [RTL-SDR Radio] Got 21 phrases from file Apr 15 06:01:32 volumio volumio[14154]: info: [RTL-SDR Radio] Updated metadata blocklist Apr 15 06:01:32 volumio volumio[14154]: info: [RTL-SDR Radio] Metadata module now has 21 phrases Apr 15 06:01:32 volumio volumio[14154]: info: [RTL-SDR Radio] Management server started on port 3456 Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 15 06:01:32 volumio volumio[14154]: info: [1776229292992] CoreMusicLibrary::Adding element FM/DAB Radio Apr 15 06:01:32 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 06:01:32 volumio volumio[14154]: Cannot find translation for source YouTube Music Apr 15 06:01:32 volumio volumio[14154]: Cannot find translation for source Podcast Apr 15 06:01:32 volumio volumio[14154]: Cannot find translation for source FM/DAB Radio Apr 15 06:01:32 volumio volumio[14154]: info: [RTL-SDR Radio] Plugin started successfully Apr 15 06:01:33 volumio volumio[14154]: info: MPD Permissions set Apr 15 06:01:33 volumio volumio[14154]: info: MPD Permissions set Apr 15 06:01:33 volumio volumio[14154]: info: Spotify config file written Apr 15 06:01:33 volumio sudo[14359]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 15 06:01:33 volumio sudo[14359]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:33 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Apr 15 06:01:33 volumio systemd[1]: go-librespot-daemon.service: Killing process 14232 (go-librespot) with signal SIGKILL. Apr 15 06:01:33 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Apr 15 06:01:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 15 06:01:33 volumio volumio[14154]: 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 15 06:01:33 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:33 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:33 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:33 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:33 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:33 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:33 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:33 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:33 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:33 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:33 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:33 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:33 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:33 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:33 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:33 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:33 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:33 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:33 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:33 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:33 volumio volumio[14154]: info: No need to fix Spotify hosts Apr 15 06:01:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 15 06:01:33 volumio volumio[14154]: info: Discovery: adding 072f109f-54a2-4344-b8c4-538b45da7e51 Apr 15 06:01:33 volumio volumio[14154]: info: Discovery: Found device Volumio Apr 15 06:01:33 volumio go-librespot[14361]: go-librespot daemon starting... Apr 15 06:01:33 volumio volumio[14154]: info: CoreCommandRouter::volumioGetState Apr 15 06:01:33 volumio volumio[14154]: info: CorePlayQueue::getTrack 0 Apr 15 06:01:33 volumio sudo[14359]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:33 volumio volumio[14154]: info: Starting Shairport Sync Apr 15 06:01:33 volumio volumio[14154]: info: Starting Shairport Sync Apr 15 06:01:33 volumio go-librespot[14372]: time="2026-04-15T06:01:33+01:00" level=info msg="running go-librespot 0.6.2" Apr 15 06:01:33 volumio go-librespot[14372]: time="2026-04-15T06:01:33+01:00" level=debug msg="app state loaded" Apr 15 06:01:33 volumio go-librespot[14372]: time="2026-04-15T06:01:33+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 06:01:33 volumio volumio[14154]: info: Starting Shairport Sync Apr 15 06:01:33 volumio volumio[14154]: info: Discovery: this is already registered, 072f109f-54a2-4344-b8c4-538b45da7e51 Apr 15 06:01:33 volumio sudo[14379]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 15 06:01:33 volumio volumio[14154]: info: Discovery: Found device Volumio Apr 15 06:01:33 volumio volumio[14154]: info: CoreCommandRouter::volumioGetState Apr 15 06:01:33 volumio volumio[14154]: info: CorePlayQueue::getTrack 0 Apr 15 06:01:33 volumio sudo[14379]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:33 volumio sudo[14383]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 15 06:01:33 volumio sudo[14383]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:33 volumio sudo[14382]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 15 06:01:33 volumio sudo[14382]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:33 volumio volumio[14154]: info: Volumio called home Apr 15 06:01:33 volumio volumio[14154]: info: CoreCommandRouter::volumioGetState Apr 15 06:01:33 volumio volumio[14154]: info: CorePlayQueue::getTrack 0 Apr 15 06:01:33 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 15 06:01:33 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 15 06:01:33 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 15 06:01:33 volumio systemd[1]: shairport-sync.service: Consumed 1.548s CPU time. Apr 15 06:01:33 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 15 06:01:33 volumio sudo[14382]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:33 volumio sudo[14383]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:33 volumio sudo[14379]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:33 volumio volumio[14154]: info: Shairport-Sync Started Apr 15 06:01:33 volumio volumio[14154]: Error adding Membership: Error: addMembership EINVAL Apr 15 06:01:33 volumio volumio[14154]: info: Shairport-Sync Started Apr 15 06:01:33 volumio volumio[14154]: info: Shairport-Sync Started Apr 15 06:01:33 volumio go-librespot[14372]: time="2026-04-15T06:01:33+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 15 06:01:33 volumio go-librespot[14372]: time="2026-04-15T06:01:33+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 15 06:01:33 volumio go-librespot[14372]: time="2026-04-15T06:01:33+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 15 06:01:33 volumio volumio[14154]: info: An error occurred while refreshing Spotify Token Error: Bad Request Apr 15 06:01:33 volumio go-librespot[14372]: time="2026-04-15T06:01:33+01:00" level=info msg="zeroconf server listening on port 43189" Apr 15 06:01:33 volumio mpd[14338]: 2026-04-15T06:01:33 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 15 06:01:33 volumio systemd[1]: Started mpd.service - Music Player Daemon. Apr 15 06:01:33 volumio sudo[14303]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:33 volumio sudo[14293]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:33 volumio volumio[14154]: info: Completed starting Core Plugins Apr 15 06:01:33 volumio volumio[14154]: info: ------------------------------------------- Apr 15 06:01:33 volumio volumio[14154]: info: ----- MyVolumio plugins startup ---- Apr 15 06:01:33 volumio volumio[14154]: info: ------------------------------------------- Apr 15 06:01:33 volumio volumio[14154]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 15 06:01:33 volumio volumio[14154]: error: MPD error: The expression evaluated to a falsy value: Apr 15 06:01:33 volumio volumio[14154]: assert.ok(self.idling) Apr 15 06:01:33 volumio volumio[14154]: error: The expression evaluated to a falsy value: Apr 15 06:01:33 volumio volumio[14154]: assert.ok(self.idling) Apr 15 06:01:33 volumio volumio[14154]: info: MPD running with PID14338 Apr 15 06:01:33 volumio volumio[14154]: ,establishing connection Apr 15 06:01:33 volumio volumio[14154]: error: updateQueue error: null Apr 15 06:01:33 volumio volumio[14154]: error: updateQueue error: null Apr 15 06:01:33 volumio go-librespot[14372]: time="2026-04-15T06:01:33+01:00" level=debug msg="obtained new client token: AABOZu/TjKK7swm5km+AMdWbuKsLBowYtt21Ekoh5Bz3B8iqmj2LYPzJqdFcV9+g1wbWMj9IxOnOTPLV34JkNhlm+zzDPrrKn7GjOkoe8QPgQTcW0P+hFC5uKFXERcD+/ZqRhqtuDaJuX/0aypeP2/nAxLReJR60qxW+DWXOU12P47dq7qCeyGRBAsyq+4TdkTqS1NEKLmdg9MP5pKTbAEbYgB85Hij3e4tmIFMG/zlT2oB1VUVo23xZqw==" Apr 15 06:01:33 volumio go-librespot[14372]: time="2026-04-15T06:01:33+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 06:01:33 volumio go-librespot[14372]: time="2026-04-15T06:01:33+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:33 volumio go-librespot[14372]: time="2026-04-15T06:01:33+01:00" level=debug msg="completed challenge" Apr 15 06:01:34 volumio go-librespot[14372]: time="2026-04-15T06:01:34+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:34 volumio volumio-remote-updater[945]: [2026-04-15 06:01:34] [connect] Successful connection Apr 15 06:01:34 volumio volumio-remote-updater[945]: [2026-04-15 06:01:34] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1776229294 101 Apr 15 06:01:34 volumio volumio[14154]: 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 15 06:01:34 volumio sudo[14193]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:34 volumio go-librespot[14372]: time="2026-04-15T06:01:34+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 15 06:01:34 volumio go-librespot[14372]: time="2026-04-15T06:01:34+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:34 volumio go-librespot[14372]: time="2026-04-15T06:01:34+01:00" level=debug msg="completed challenge" Apr 15 06:01:34 volumio go-librespot[14372]: time="2026-04-15T06:01:34+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:35 volumio go-librespot[14372]: time="2026-04-15T06:01:35+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 15 06:01:35 volumio go-librespot[14372]: time="2026-04-15T06:01:35+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:35 volumio go-librespot[14372]: time="2026-04-15T06:01:35+01:00" level=debug msg="completed challenge" Apr 15 06:01:35 volumio go-librespot[14372]: time="2026-04-15T06:01:35+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:35 volumio go-librespot[14372]: time="2026-04-15T06:01:35+01:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Apr 15 06:01:36 volumio go-librespot[14372]: time="2026-04-15T06:01:36+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:36 volumio go-librespot[14372]: time="2026-04-15T06:01:36+01:00" level=debug msg="completed challenge" Apr 15 06:01:36 volumio volumio[14154]: info: go-librespot daemon successfully initialized Apr 15 06:01:36 volumio go-librespot[14372]: time="2026-04-15T06:01:36+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:36 volumio go-librespot[14372]: time="2026-04-15T06:01:36+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Apr 15 06:01:36 volumio go-librespot[14372]: time="2026-04-15T06:01:36+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:36 volumio go-librespot[14372]: time="2026-04-15T06:01:36+01:00" level=debug msg="completed challenge" Apr 15 06:01:36 volumio go-librespot[14372]: time="2026-04-15T06:01:36+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:37 volumio go-librespot[14372]: time="2026-04-15T06:01:37+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 15 06:01:37 volumio go-librespot[14372]: time="2026-04-15T06:01:37+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:37 volumio go-librespot[14372]: time="2026-04-15T06:01:37+01:00" level=debug msg="completed challenge" Apr 15 06:01:37 volumio go-librespot[14372]: time="2026-04-15T06:01:37+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:37 volumio go-librespot[14372]: time="2026-04-15T06:01:37+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 06:01:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 06:01:39 volumio volumio[14154]: info: Initializing connection to go-librespot Websocket Apr 15 06:01:39 volumio volumio[14154]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 06:01:40 volumio sudo[14425]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 15 06:01:40 volumio sudo[14427]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 15 06:01:40 volumio sudo[14427]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:40 volumio sudo[14425]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:40 volumio sudo[14427]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:40 volumio sudo[14425]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:40 volumio sudo[14429]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 15 06:01:40 volumio sudo[14429]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:40 volumio sudo[14429]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:40 volumio volumio[14154]: info: Upmpdcli Daemon Started Apr 15 06:01:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Apr 15 06:01:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 15 06:01:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 15 06:01:41 volumio go-librespot[14433]: go-librespot daemon starting... Apr 15 06:01:41 volumio go-librespot[14434]: time="2026-04-15T06:01:41+01:00" level=info msg="running go-librespot 0.6.2" Apr 15 06:01:41 volumio go-librespot[14434]: time="2026-04-15T06:01:41+01:00" level=debug msg="app state loaded" Apr 15 06:01:41 volumio go-librespot[14434]: time="2026-04-15T06:01:41+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 06:01:41 volumio go-librespot[14434]: time="2026-04-15T06:01:41+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 15 06:01:41 volumio go-librespot[14434]: time="2026-04-15T06:01:41+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 15 06:01:41 volumio go-librespot[14434]: time="2026-04-15T06:01:41+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 15 06:01:41 volumio go-librespot[14434]: time="2026-04-15T06:01:41+01:00" level=info msg="zeroconf server listening on port 37531" Apr 15 06:01:41 volumio go-librespot[14434]: time="2026-04-15T06:01:41+01:00" level=debug msg="obtained new client token: AAAxxrjpooeVNb3V+cj3zKLNTBj2Ew5fBIg2W0IaAdkQIvVGOqtLgpGrTF4FUm2FwRzTsqaNN6LhvHfhes3+7PnwwXaQyuIco7d/5OSoYOkKupJszvvhhVbw/CDMmW+hnEhOne1d+De4D4oYIl9ix6bl0Dq/CyabWw1/VrJxuHSVWdw5L4Tcrh2U24vkyyrzjJXHfJPIL8eStEnaoiXruEwNfBqBDCY/zDpkyPrQ4E2GGJNCvpdEH0VeXg==" Apr 15 06:01:41 volumio go-librespot[14434]: time="2026-04-15T06:01:41+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 06:01:41 volumio go-librespot[14434]: time="2026-04-15T06:01:41+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:41 volumio go-librespot[14434]: time="2026-04-15T06:01:41+01:00" level=debug msg="completed challenge" Apr 15 06:01:41 volumio go-librespot[14434]: time="2026-04-15T06:01:41+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:41 volumio volumio[14154]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 15 06:01:41 volumio volumio[14154]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 15 06:01:41 volumio volumio[14154]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 15 06:01:41 volumio volumio[14154]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 15 06:01:41 volumio volumio[14154]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 15 06:01:41 volumio volumio[14154]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 15 06:01:41 volumio volumio[14154]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 15 06:01:41 volumio volumio[14154]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 15 06:01:41 volumio volumio[14154]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 15 06:01:41 volumio volumio[14154]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 15 06:01:41 volumio volumio[14154]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Apr 15 06:01:41 volumio volumio[14154]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 15 06:01:41 volumio volumio[14154]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 15 06:01:41 volumio volumio[14154]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 15 06:01:41 volumio volumio[14154]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 15 06:01:41 volumio volumio[14154]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 15 06:01:41 volumio volumio[14154]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 15 06:01:41 volumio volumio[14154]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 15 06:01:41 volumio volumio[14154]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 15 06:01:41 volumio volumio[14154]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 15 06:01:41 volumio volumio[14154]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 15 06:01:41 volumio volumio[14154]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Apr 15 06:01:41 volumio volumio[14154]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 15 06:01:41 volumio volumio[14154]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 15 06:01:41 volumio volumio[14154]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 15 06:01:41 volumio volumio[14154]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 15 06:01:41 volumio volumio[14154]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 15 06:01:41 volumio volumio[14154]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 15 06:01:41 volumio volumio[14154]: info: Adding plugin bluetooth to MyMusic Plugins Apr 15 06:01:41 volumio volumio[14154]: info: Adding plugin multiroom to MyMusic Plugins Apr 15 06:01:41 volumio volumio[14154]: info: Adding plugin metavolumio to MyMusic Plugins Apr 15 06:01:41 volumio volumio[14154]: info: Adding plugin cd_controller to MyMusic Plugins Apr 15 06:01:41 volumio volumio[14154]: info: Adding plugin qobuzconnect to MyMusic Plugins Apr 15 06:01:41 volumio volumio[14154]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 15 06:01:41 volumio volumio[14154]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 15 06:01:41 volumio volumio[14154]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 15 06:01:42 volumio go-librespot[14434]: time="2026-04-15T06:01:42+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 15 06:01:42 volumio go-librespot[14434]: time="2026-04-15T06:01:42+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:42 volumio go-librespot[14434]: time="2026-04-15T06:01:42+01:00" level=debug msg="completed challenge" Apr 15 06:01:42 volumio go-librespot[14434]: time="2026-04-15T06:01:42+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:42 volumio volumio[14154]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 15 06:01:42 volumio volumio[14154]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 15 06:01:42 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:42 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:42 volumio volumio[14154]: info: Starting MyVolumio Remote Streaming Endpoints Apr 15 06:01:42 volumio volumio[14154]: info: MyVolumio login type: Token Apr 15 06:01:42 volumio volumio[14154]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 15 06:01:42 volumio volumio[14154]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 15 06:01:42 volumio volumio[14154]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 15 06:01:42 volumio volumio[14154]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 15 06:01:42 volumio volumio[14154]: info: Streaming services startup Apr 15 06:01:42 volumio volumio[14154]: info: Starting Streaming Daemon Apr 15 06:01:42 volumio sudo[14445]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 15 06:01:42 volumio sudo[14445]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:42 volumio volumio[14154]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 15 06:01:42 volumio sudo[14445]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:42 volumio volumio[14154]: info: Initializing connection to go-librespot Websocket Apr 15 06:01:42 volumio volumio[14154]: error: Cannot start Volumio Streaming Daemon Apr 15 06:01:42 volumio volumio[14154]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 15 06:01:42 volumio volumio[14154]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 15 06:01:42 volumio go-librespot[14434]: time="2026-04-15T06:01:42+01:00" level=debug msg="new websocket client" Apr 15 06:01:42 volumio volumio[14154]: info: Connection to go-librespot Websocket established Apr 15 06:01:42 volumio go-librespot[14434]: time="2026-04-15T06:01:42+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 15 06:01:42 volumio go-librespot[14434]: time="2026-04-15T06:01:42+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:42 volumio go-librespot[14434]: time="2026-04-15T06:01:42+01:00" level=debug msg="completed challenge" Apr 15 06:01:42 volumio go-librespot[14434]: time="2026-04-15T06:01:42+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:42 volumio volumio[14154]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 15 06:01:43 volumio volumio[14154]: info: MyVolumio token set successfully Apr 15 06:01:43 volumio volumio[14154]: info: MYVOLUMIO: Adding device Apr 15 06:01:43 volumio volumio[14154]: info: MYVOLUMIO: Evaluating Server Apr 15 06:01:43 volumio go-librespot[14434]: time="2026-04-15T06:01:43+01:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Apr 15 06:01:43 volumio volumio[14154]: info: MyVolumio status changed Apr 15 06:01:43 volumio volumio[14154]: info: Streaming services startup Apr 15 06:01:43 volumio volumio[14154]: info: Starting Streaming Daemon Apr 15 06:01:43 volumio volumio[14154]: info: Removing browser output: myVolumio user plan is not superstar Apr 15 06:01:43 volumio volumio[14154]: info: Removing audio output: Apr 15 06:01:43 volumio volumio[14154]: info: Stoppping Tunnel 1 Apr 15 06:01:43 volumio sudo[14472]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 15 06:01:43 volumio sudo[14472]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:43 volumio sudo[14474]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Apr 15 06:01:43 volumio sudo[14474]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:43 volumio sudo[14472]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:43 volumio volumio[14154]: error: Cannot start Volumio Streaming Daemon Apr 15 06:01:43 volumio volumio[14154]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 15 06:01:43 volumio volumio[14154]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 15 06:01: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 15 06:01: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 15 06:01: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 15 06:01: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 15 06:01: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 15 06:01: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 15 06:01: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 15 06:01: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 15 06:01:43 volumio sudo[14474]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:43 volumio volumio[14154]: info: Remote SSH Stopped Apr 15 06:01:43 volumio go-librespot[14434]: time="2026-04-15T06:01:43+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:43 volumio go-librespot[14434]: time="2026-04-15T06:01:43+01:00" level=debug msg="completed challenge" Apr 15 06:01:43 volumio go-librespot[14434]: time="2026-04-15T06:01:43+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:43 volumio volumio[14154]: info: Setting Geolocation for MyVolumio to eu3 Apr 15 06:01:43 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:43 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:43 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:43 volumio volumio[14154]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Apr 15 06:01:44 volumio go-librespot[14434]: time="2026-04-15T06:01:44+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Apr 15 06:01:44 volumio go-librespot[14434]: time="2026-04-15T06:01:44+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:44 volumio go-librespot[14434]: time="2026-04-15T06:01:44+01:00" level=debug msg="completed challenge" Apr 15 06:01:44 volumio go-librespot[14434]: time="2026-04-15T06:01:44+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:44 volumio volumio[14154]: info: Updating MyVolumio device info Apr 15 06:01:44 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:44 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:44 volumio volumio[14154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:44 volumio go-librespot[14434]: time="2026-04-15T06:01:44+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 15 06:01:44 volumio volumio[14154]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Apr 15 06:01:45 volumio go-librespot[14434]: time="2026-04-15T06:01:45+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:45 volumio go-librespot[14434]: time="2026-04-15T06:01:45+01:00" level=debug msg="completed challenge" Apr 15 06:01:45 volumio go-librespot[14434]: time="2026-04-15T06:01:45+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:45 volumio go-librespot[14434]: time="2026-04-15T06:01:45+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 15 06:01:45 volumio volumio[14154]: info: Connection to go-librespot Websocket closed Apr 15 06:01:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 06:01:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 06:01:45 volumio volumio[14154]: info: Getting Spotify volume Apr 15 06:01:45 volumio volumio[14154]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 15 06:01:45 volumio volumio[14154]: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 06:01:45 volumio volumio[14154]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Apr 15 06:01:45 volumio volumio[14154]: errno: -111, Apr 15 06:01:45 volumio volumio[14154]: code: 'ECONNREFUSED', Apr 15 06:01:45 volumio volumio[14154]: syscall: 'connect', Apr 15 06:01:45 volumio volumio[14154]: address: '127.0.0.1', Apr 15 06:01:45 volumio volumio[14154]: port: 9879, Apr 15 06:01:45 volumio volumio[14154]: response: undefined Apr 15 06:01:45 volumio volumio[14154]: } Apr 15 06:01:45 volumio volumio[14154]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 15 06:01:45 volumio sudo[14492]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-15 06:00' Apr 15 06:01:45 volumio sudo[14492]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:45 volumio sudo[14492]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:45 volumio volumio-remote-updater[945]: [2026-04-15 06:01:45] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Apr 15 06:01:45 volumio volumio-remote-updater[945]: [2026-04-15 06:01:45] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Apr 15 06:01:45 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Apr 15 06:01:45 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Apr 15 06:01:45 volumio systemd[1]: volumio.service: Consumed 8.970s CPU time. Apr 15 06:01:45 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 15 06:01:45 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 15 06:01:46 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 121876. Apr 15 06:01:46 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 15 06:01:46 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Apr 15 06:01:46 volumio systemd[1]: volumio.service: Consumed 8.970s CPU time. Apr 15 06:01:46 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Apr 15 06:01:46 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 15 06:01:46 volumio volumio[14504]: info: ------------------------------------------- Apr 15 06:01:46 volumio volumio[14504]: info: ----- Volumio3 ---- Apr 15 06:01:46 volumio volumio[14504]: info: ------------------------------------------- Apr 15 06:01:46 volumio volumio[14504]: info: ----- System startup ---- Apr 15 06:01:46 volumio volumio[14504]: info: ------------------------------------------- Apr 15 06:01:46 volumio volumio[14504]: info: MYVOLUMIO Environment detected Apr 15 06:01:46 volumio volumio[14504]: info: Plugin folders cleanup Apr 15 06:01:46 volumio volumio[14504]: info: Scanning into folder /volumio/app/plugins/ Apr 15 06:01:46 volumio volumio[14504]: info: Scanning category audio_interface Apr 15 06:01:46 volumio volumio[14504]: info: Scanning category miscellanea Apr 15 06:01:46 volumio volumio[14504]: info: Scanning category music_service Apr 15 06:01:46 volumio volumio[14504]: info: Scanning category plugins.json Apr 15 06:01:46 volumio volumio[14504]: info: Scanning category system_controller Apr 15 06:01:46 volumio volumio[14504]: info: Scanning category user_interface Apr 15 06:01:46 volumio volumio[14504]: info: Scanning into folder /data/plugins/ Apr 15 06:01:46 volumio volumio[14504]: info: Scanning category music_service Apr 15 06:01:46 volumio volumio[14504]: info: Plugin folders cleanup completed Apr 15 06:01:46 volumio volumio[14504]: info: ------------------------------------------- Apr 15 06:01:46 volumio volumio[14504]: info: ----- Core plugins startup ---- Apr 15 06:01:46 volumio volumio[14504]: info: ------------------------------------------- Apr 15 06:01:46 volumio volumio[14504]: info: Loading plugins from folder /volumio/app/plugins/ Apr 15 06:01:46 volumio volumio[14504]: info: Adding plugin upnp to MyMusic Plugins Apr 15 06:01:46 volumio volumio[14504]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 15 06:01:46 volumio volumio[14504]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 15 06:01:46 volumio volumio[14504]: info: Loading plugins from folder /data/plugins/ Apr 15 06:01:46 volumio volumio[14504]: info: Adding plugin rtlsdr_radio to MyMusic Plugins Apr 15 06:01:46 volumio volumio[14504]: info: Loading plugin "system"... Apr 15 06:01:46 volumio volumio[14504]: info: Loading plugin "appearance"... Apr 15 06:01:47 volumio volumio[14504]: info: Loading plugin "network"... Apr 15 06:01:47 volumio volumio[14504]: info: Refreshing Cached IP Addresses Apr 15 06:01:47 volumio sudo[14532]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 15 06:01:47 volumio sudo[14532]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:47 volumio sudo[14534]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 15 06:01:47 volumio sudo[14534]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:47 volumio sudo[14532]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:47 volumio sudo[14534]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:47 volumio volumio[14504]: info: Loading plugin "services"... Apr 15 06:01:47 volumio volumio[14504]: info: Loading plugin "alsa_controller"... Apr 15 06:01:47 volumio sudo[14543]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 15 06:01:47 volumio sudo[14543]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:47 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 15 06:01:47 volumio volumio[14504]: info: Loading plugin "wizard"... Apr 15 06:01:47 volumio volumio[14504]: info: Loading plugin "networkfs"... Apr 15 06:01:47 volumio volumio[14504]: info: Starting Udev Watcher for removable devices Apr 15 06:01:47 volumio volumio[14504]: info: Mounting Device 0ACB-A1DE Apr 15 06:01:47 volumio sudo[14571]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/0ACB-A1DE -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Apr 15 06:01:47 volumio sudo[14571]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:47 volumio sudo[14571]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:47 volumio volumio[14504]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Apr 15 06:01:47 volumio volumio[14504]: dmesg(1) may have more information after failed mount system call. Apr 15 06:01:47 volumio volumio[14504]: 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 15 06:01:47 volumio volumio[14504]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Apr 15 06:01:47 volumio volumio[14504]: dmesg(1) may have more information after failed mount system call. Apr 15 06:01:47 volumio volumio[14504]: info: Ignoring mount for partition: boot Apr 15 06:01:47 volumio volumio[14504]: info: Ignoring mount for partition: volumio Apr 15 06:01:47 volumio volumio[14504]: info: Ignoring mount for partition: volumio_data Apr 15 06:01:47 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 15 06:01:47 volumio volumio[14504]: info: Loading plugin "volumio_command_line_client"... Apr 15 06:01:47 volumio volumio[14504]: info: Loading plugin "upnp"... Apr 15 06:01:47 volumio volumio[14504]: info: [1776229307359] Starting Upmpd Daemon Apr 15 06:01:47 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 15 06:01:47 volumio volumio[14504]: info: Loading plugin "my_music"... Apr 15 06:01:47 volumio volumio[14504]: info: Loading plugin "mpd"... Apr 15 06:01:47 volumio volumio[14504]: info: Loading plugin "upnp_browser"... Apr 15 06:01:47 volumio volumio[14504]: info: Starting UPNP Browser Apr 15 06:01:47 volumio volumio[14504]: info: Loading plugin "alarm-clock"... Apr 15 06:01:47 volumio volumio[14504]: info: Loading plugin "airplay_emulation"... Apr 15 06:01:47 volumio volumio[14504]: info: Starting Shairport Sync Apr 15 06:01:47 volumio volumio[14504]: info: Loading plugin "last_100"... Apr 15 06:01:47 volumio volumio[14504]: info: Loading plugin "webradio"... Apr 15 06:01:47 volumio volumio[14504]: info: Loading plugin "i2s_dacs"... Apr 15 06:01:47 volumio volumio[14504]: info: Loading plugin "volumiodiscovery"... Apr 15 06:01:48 volumio volumio[14504]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 15 06:01:48 volumio volumio[14504]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 15 06:01:48 volumio volumio[14504]: *** WARNING *** For more information see Apr 15 06:01:48 volumio volumio[14504]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 15 06:01:48 volumio volumio[14504]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 15 06:01:48 volumio volumio[14504]: *** WARNING *** For more information see Apr 15 06:01:48 volumio node[14504]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 15 06:01:48 volumio node[14504]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 15 06:01:48 volumio node[14504]: *** WARNING *** For more information see Apr 15 06:01:48 volumio node[14504]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 15 06:01:48 volumio node[14504]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 15 06:01:48 volumio node[14504]: *** WARNING *** For more information see Apr 15 06:01:48 volumio volumio[14504]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 15 06:01:48 volumio volumio[14504]: info: Discovery: Started advertising with name: Volumio Apr 15 06:01:48 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 15 06:01:48 volumio volumio[14504]: info: Loading plugin "spop"... Apr 15 06:01:48 volumio volumio[14504]: info: Loading plugin "ytmusic"... Apr 15 06:01:48 volumio volumio[14504]: info: Loading plugin "outputs"... Apr 15 06:01:48 volumio volumio[14504]: info: Loading plugin "albumart"... Apr 15 06:01:48 volumio volumio[14504]: info: Plugin example_plugin is not enabled Apr 15 06:01:48 volumio volumio[14504]: info: Loading plugin "inputs"... Apr 15 06:01:48 volumio volumio[14504]: info: Loading plugin "updater_comm"... Apr 15 06:01:48 volumio volumio[14504]: info: Plugin mpdemulation is not enabled Apr 15 06:01:48 volumio volumio[14504]: info: Loading plugin "rest_api"... Apr 15 06:01:48 volumio volumio[14504]: info: Loading plugin "websocket"... Apr 15 06:01:48 volumio volumio[14504]: info: Starting Socket.io Server version 1.7.4 Apr 15 06:01:48 volumio volumio[14504]: info: Loading plugin "podcast"... Apr 15 06:01:48 volumio volumio[14504]: info: ControllerPodcast::constructor Apr 15 06:01:48 volumio volumio[14504]: info: Loading plugin "rtlsdr_radio"... Apr 15 06:01:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Apr 15 06:01:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 15 06:01:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 15 06:01:48 volumio go-librespot[14585]: go-librespot daemon starting... Apr 15 06:01:48 volumio volumio[14575]: Forking 3 albumart workers Apr 15 06:01:48 volumio go-librespot[14586]: time="2026-04-15T06:01:48+01:00" level=info msg="running go-librespot 0.6.2" Apr 15 06:01:48 volumio go-librespot[14586]: time="2026-04-15T06:01:48+01:00" level=debug msg="app state loaded" Apr 15 06:01:48 volumio go-librespot[14586]: time="2026-04-15T06:01:48+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 06:01:48 volumio volumio[14504]: info: Loading i18n strings for locale en Apr 15 06:01:48 volumio volumio[14504]: Updating browse sources language Apr 15 06:01:48 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 06:01:48 volumio go-librespot[14586]: time="2026-04-15T06:01:48+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 15 06:01:48 volumio go-librespot[14586]: time="2026-04-15T06:01:48+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 15 06:01:48 volumio go-librespot[14586]: time="2026-04-15T06:01:48+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 15 06:01:48 volumio go-librespot[14586]: time="2026-04-15T06:01:48+01:00" level=info msg="zeroconf server listening on port 33433" Apr 15 06:01:48 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 15 06:01:48 volumio volumio[14504]: info: CoreCommandRouter::initPlayerControls Apr 15 06:01:48 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:48 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:48 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:48 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:48 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:48 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:48 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:48 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:48 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 15 06:01:48 volumio volumio[14504]: Express server listening on port 3000 Apr 15 06:01:48 volumio volumio[14504]: [Metrics] WebUI: 2s 361.63ms Apr 15 06:01:48 volumio volumio[14504]: info: CoreStateMachine::resetVolumioState Apr 15 06:01:48 volumio volumio[14504]: info: CoreStateMachine::getcurrentVolume Apr 15 06:01:48 volumio volumio[14504]: info: CoreCommandRouter::volumioRetrievevolume Apr 15 06:01:48 volumio volumio[14504]: info: Volumio Network Manager: Network status updated: 2 Apr 15 06:01:49 volumio volumio[14504]: info: VolumeController:: Volume=36 Mute =true Apr 15 06:01:49 volumio volumio[14504]: info: CoreStateMachine::pushState Apr 15 06:01:49 volumio volumio[14504]: info: CorePlayQueue::getTrack 0 Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::volumioPushState Apr 15 06:01:49 volumio volumio[14504]: info: CoreStateMachine::updateTrackBlock Apr 15 06:01:49 volumio volumio[14504]: info: CorePlayQueue::getTrackBlock Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::volumioRetrievevolume Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:49 volumio volumio[14504]: info: Reloading queue from file Apr 15 06:01:49 volumio volumio[14593]: Starting albumart workers Apr 15 06:01:49 volumio volumio[14504]: info: CoreStateMachine::setRepeat null single undefined Apr 15 06:01:49 volumio volumio[14504]: info: CoreStateMachine::pushState Apr 15 06:01:49 volumio volumio[14504]: info: CorePlayQueue::getTrack 0 Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::volumioPushState Apr 15 06:01:49 volumio volumio[14504]: info: CoreStateMachine::setRandom true Apr 15 06:01:49 volumio volumio[14504]: info: CoreStateMachine::pushState Apr 15 06:01:49 volumio volumio[14504]: info: CorePlayQueue::getTrack 0 Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::volumioPushState Apr 15 06:01:49 volumio volumio[14504]: info: Setting Device type: Raspberry PI Apr 15 06:01:49 volumio volumio[14504]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Apr 15 06:01:49 volumio volumio[14504]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04170 Apr 15 06:01:49 volumio volumio[14504]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Apr 15 06:01:49 volumio volumio[14504]: info: Completed loading Core Plugins Apr 15 06:01:49 volumio volumio[14504]: info: Preparing to generate the ALSA configuration file Apr 15 06:01:49 volumio volumio[14504]: info: VolumeController:: Volume=36 Mute =true Apr 15 06:01:49 volumio volumio[14592]: Starting albumart workers Apr 15 06:01:49 volumio volumio[14504]: info: CoreStateMachine::pushState Apr 15 06:01:49 volumio volumio[14504]: info: CorePlayQueue::getTrack 0 Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::volumioPushState Apr 15 06:01:49 volumio volumio[14504]: info: Asound.conf file unchanged, so no further update is needed Apr 15 06:01:49 volumio volumio[14504]: info: Output device has changed, restarting MPD Apr 15 06:01:49 volumio volumio[14504]: info: Output device has changed, restarting Shairport Sync Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:49 volumio sudo[14643]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 15 06:01:49 volumio sudo[14644]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 15 06:01:49 volumio sudo[14644]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:49 volumio sudo[14643]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:49 volumio sudo[14643]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:49 volumio volumio[14504]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 15 06:01:49 volumio volumio[14504]: info: ___________ START PLUGINS ___________ Apr 15 06:01:49 volumio volumio[14504]: info: ControllerMpd::onStart: Initializing MPD Apr 15 06:01:49 volumio volumio[14594]: Starting albumart workers Apr 15 06:01:49 volumio volumio[14504]: info: Creating MPD Configuration file Apr 15 06:01:49 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 15 06:01:49 volumio volumio[14504]: info: [1776229309190] CoreMusicLibrary::Adding element Media Servers Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 06:01:49 volumio volumio[14504]: info: UPNP Browser: Client initialized successfully Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:49 volumio sudo[14654]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 15 06:01:49 volumio sudo[14654]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:49 volumio sudo[14653]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 15 06:01:49 volumio sudo[14653]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:49 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 15 06:01:49 volumio sudo[14653]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:49 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 15 06:01:49 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 15 06:01:49 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 15 06:01:49 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 15 06:01:49 volumio volumio[14504]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:49 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 15 06:01:49 volumio go-librespot[14586]: time="2026-04-15T06:01:49+01:00" level=debug msg="obtained new client token: AAD7FPeJjYoDmqvp1RivNgEL6wB4/rvacuOymYM7x0f1su1V77WtOSZ4FQ7SNHbQTf9dgBYg7NAYH/6EsgcWWkHmVklfPwaECzqaI4sG0XKNv3spUP+AJjNRorhaHhSnAzv72phas03IYa6yJbq4YnHTFwZt1E38byB6UbYQNdqhJge+GzKBp5tN5FS5IgwZqFpeCbYktIC8iNk9aQhr2GSxXU4lidAyl1X3ji/okPddLuqTFX3r5KA=" Apr 15 06:01:49 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 15 06:01:49 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 15 06:01:49 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 15 06:01:49 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 15 06:01:49 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 15 06:01:49 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 15 06:01:49 volumio volumio[14504]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 15 06:01:49 volumio volumio[14504]: info: [1776229309275] CoreMusicLibrary::Adding element Last_100 Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 06:01:49 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 15 06:01:49 volumio volumio[14504]: info: [1776229309282] CoreMusicLibrary::Adding element Webradio Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 06:01:49 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 15 06:01:49 volumio volumio[14504]: info: Initializing BBC Radios Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:49 volumio sudo[14668]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 15 06:01:49 volumio sudo[14668]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 15 06:01:49 volumio sudo[14668]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:49 volumio volumio[14504]: info: Creating Spotify config file Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:49 volumio go-librespot[14586]: time="2026-04-15T06:01:49+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 15 06:01:49 volumio volumio[14504]: info: [1776229309471] CoreMusicLibrary::Adding element YouTube Music Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 06:01:49 volumio volumio[14504]: Cannot find translation for source YouTube Music Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 15 06:01:49 volumio volumio[14504]: info: [1776229309475] CoreMusicLibrary::Adding element Podcast Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 06:01:49 volumio volumio[14504]: Cannot find translation for source YouTube Music Apr 15 06:01:49 volumio volumio[14504]: Cannot find translation for source Podcast Apr 15 06:01:49 volumio volumio[14504]: info: [RTL-SDR Radio] Starting plugin Apr 15 06:01:49 volumio volumio[14504]: info: [RTL-SDR Radio] Loaded i18n strings for language: en Apr 15 06:01:49 volumio volumio[14504]: info: Volumio Calling Home Apr 15 06:01:49 volumio volumio[14504]: info: [RTL-SDR Radio] snd-aloop already loaded Apr 15 06:01:49 volumio volumio[14504]: info: [RTL-SDR Radio] No stations database found, creating v2 Apr 15 06:01:49 volumio volumio[14504]: info: [RTL-SDR Radio] Database loaded at: 2026-04-15T05:01:49.517Z Apr 15 06:01:49 volumio volumio[14504]: info: [RTL-SDR Radio] Loading blocklist from: /data/plugins/music_service/rtlsdr_radio/blocklist.json Apr 15 06:01:49 volumio volumio[14504]: info: [RTL-SDR Radio] Got 21 phrases from file Apr 15 06:01:49 volumio volumio[14504]: info: [RTL-SDR Radio] Updated metadata blocklist Apr 15 06:01:49 volumio volumio[14504]: info: [RTL-SDR Radio] Metadata module now has 21 phrases Apr 15 06:01:49 volumio volumio[14504]: info: [RTL-SDR Radio] Management server started on port 3456 Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 15 06:01:49 volumio volumio[14504]: info: [1776229309550] CoreMusicLibrary::Adding element FM/DAB Radio Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 06:01:49 volumio volumio[14504]: Cannot find translation for source YouTube Music Apr 15 06:01:49 volumio volumio[14504]: Cannot find translation for source Podcast Apr 15 06:01:49 volumio volumio[14504]: Cannot find translation for source FM/DAB Radio Apr 15 06:01:49 volumio volumio[14504]: info: [RTL-SDR Radio] Plugin started successfully Apr 15 06:01:49 volumio volumio[14504]: info: Discovery: adding 072f109f-54a2-4344-b8c4-538b45da7e51 Apr 15 06:01:49 volumio volumio[14504]: info: Discovery: Found device Volumio Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::volumioGetState Apr 15 06:01:49 volumio volumio[14504]: info: CorePlayQueue::getTrack 0 Apr 15 06:01:49 volumio volumio[14504]: info: Discovery: this is already registered, 072f109f-54a2-4344-b8c4-538b45da7e51 Apr 15 06:01:49 volumio volumio[14504]: info: Discovery: Found device Volumio Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::volumioGetState Apr 15 06:01:49 volumio volumio[14504]: info: CorePlayQueue::getTrack 0 Apr 15 06:01:49 volumio volumio[14504]: info: MPD Permissions set Apr 15 06:01:49 volumio go-librespot[14586]: time="2026-04-15T06:01:49+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:49 volumio go-librespot[14586]: time="2026-04-15T06:01:49+01:00" level=debug msg="completed challenge" Apr 15 06:01:49 volumio volumio[14504]: info: MPD Permissions set Apr 15 06:01:49 volumio volumio[14504]: info: Spotify config file written Apr 15 06:01:49 volumio sudo[14710]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 15 06:01:49 volumio sudo[14710]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:49 volumio go-librespot[14586]: time="2026-04-15T06:01:49+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:49 volumio volumio[14504]: 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 15 06:01:49 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:49 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:01:49 volumio volumio[14504]: info: No need to fix Spotify hosts Apr 15 06:01:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 15 06:01:49 volumio go-librespot[14714]: go-librespot daemon starting... Apr 15 06:01:49 volumio sudo[14710]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:49 volumio go-librespot[14723]: time="2026-04-15T06:01:49+01:00" level=info msg="running go-librespot 0.6.2" Apr 15 06:01:49 volumio go-librespot[14723]: time="2026-04-15T06:01:49+01:00" level=debug msg="app state loaded" Apr 15 06:01:49 volumio go-librespot[14723]: time="2026-04-15T06:01:49+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 06:01:49 volumio volumio[14504]: info: Starting Shairport Sync Apr 15 06:01:49 volumio volumio[14504]: info: Starting Shairport Sync Apr 15 06:01:49 volumio volumio[14504]: info: Starting Shairport Sync Apr 15 06:01:49 volumio sudo[14730]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 15 06:01:49 volumio sudo[14730]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:49 volumio sudo[14734]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 15 06:01:49 volumio sudo[14734]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:49 volumio sudo[14733]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 15 06:01:49 volumio sudo[14733]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:49 volumio volumio[14504]: info: CoreCommandRouter::volumioGetState Apr 15 06:01:49 volumio volumio[14504]: info: CorePlayQueue::getTrack 0 Apr 15 06:01:49 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 15 06:01:49 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 15 06:01:49 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 15 06:01:49 volumio systemd[1]: shairport-sync.service: Consumed 1.544s CPU time. Apr 15 06:01:49 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 15 06:01:49 volumio sudo[14733]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:49 volumio sudo[14734]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:49 volumio sudo[14730]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:49 volumio volumio[14504]: info: Shairport-Sync Started Apr 15 06:01:49 volumio volumio[14504]: Error adding Membership: Error: addMembership EINVAL Apr 15 06:01:49 volumio volumio[14504]: info: Shairport-Sync Started Apr 15 06:01:49 volumio volumio[14504]: info: Shairport-Sync Started Apr 15 06:01:49 volumio volumio[14504]: info: Volumio called home Apr 15 06:01:49 volumio volumio[14504]: info: An error occurred while refreshing Spotify Token Error: Bad Request Apr 15 06:01:50 volumio mpd[14689]: 2026-04-15T06:01:50 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 15 06:01:50 volumio systemd[1]: Started mpd.service - Music Player Daemon. Apr 15 06:01:50 volumio sudo[14644]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:50 volumio sudo[14654]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:50 volumio volumio[14504]: error: updateQueue error: null Apr 15 06:01:50 volumio volumio[14504]: info: Completed starting Core Plugins Apr 15 06:01:50 volumio volumio[14504]: info: ------------------------------------------- Apr 15 06:01:50 volumio volumio[14504]: info: ----- MyVolumio plugins startup ---- Apr 15 06:01:50 volumio volumio[14504]: info: ------------------------------------------- Apr 15 06:01:50 volumio volumio[14504]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 15 06:01:50 volumio volumio[14504]: error: updateQueue error: null Apr 15 06:01:50 volumio volumio[14504]: info: MPD running with PID14689 Apr 15 06:01:50 volumio volumio[14504]: ,establishing connection Apr 15 06:01:50 volumio volumio[14504]: error: updateQueue error: null Apr 15 06:01:50 volumio go-librespot[14723]: time="2026-04-15T06:01:50+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 15 06:01:50 volumio go-librespot[14723]: time="2026-04-15T06:01:50+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 15 06:01:50 volumio go-librespot[14723]: time="2026-04-15T06:01:50+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 15 06:01:50 volumio go-librespot[14723]: time="2026-04-15T06:01:50+01:00" level=info msg="zeroconf server listening on port 46653" Apr 15 06:01:50 volumio go-librespot[14723]: time="2026-04-15T06:01:50+01:00" level=debug msg="obtained new client token: AAA7su5ldsWhuzm7o/2l9q2BAf4Vi0o0dlaZVf9uz4Rgk2MPVzsO6VLoK/DMrTJgkcKlALnGDQ9OjH9LE4EVXr8yokS+1sq6lUIVp29WKwZIFbyIQhe3xKQO7iMH+lmh9BRo7GbW6exGwNbSbXswmDzZUmHhobV71rlaZqrdLWRds59uMFkYW4XJpDE5tBARB9MDs1e7vAJkxCGIABZP3LuElusi3FGMqNmeplMcbNun7Ukbs9xIWDxOug==" Apr 15 06:01:50 volumio volumio-remote-updater[945]: [2026-04-15 06:01:50] [connect] Successful connection Apr 15 06:01:50 volumio volumio-remote-updater[945]: [2026-04-15 06:01:50] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1776229310 101 Apr 15 06:01:50 volumio volumio[14504]: 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 15 06:01:50 volumio go-librespot[14723]: time="2026-04-15T06:01:50+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 06:01:51 volumio go-librespot[14723]: time="2026-04-15T06:01:51+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:51 volumio go-librespot[14723]: time="2026-04-15T06:01:51+01:00" level=debug msg="completed challenge" Apr 15 06:01:51 volumio sudo[14543]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:51 volumio go-librespot[14723]: time="2026-04-15T06:01:51+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:51 volumio go-librespot[14723]: time="2026-04-15T06:01:51+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 15 06:01:51 volumio go-librespot[14723]: time="2026-04-15T06:01:51+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:51 volumio go-librespot[14723]: time="2026-04-15T06:01:51+01:00" level=debug msg="completed challenge" Apr 15 06:01:51 volumio go-librespot[14723]: time="2026-04-15T06:01:51+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:52 volumio go-librespot[14723]: time="2026-04-15T06:01:52+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 15 06:01:52 volumio go-librespot[14723]: time="2026-04-15T06:01:52+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:52 volumio go-librespot[14723]: time="2026-04-15T06:01:52+01:00" level=debug msg="completed challenge" Apr 15 06:01:52 volumio go-librespot[14723]: time="2026-04-15T06:01:52+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:52 volumio volumio[14504]: info: go-librespot daemon successfully initialized Apr 15 06:01:52 volumio go-librespot[14723]: time="2026-04-15T06:01:52+01:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Apr 15 06:01:53 volumio go-librespot[14723]: time="2026-04-15T06:01:53+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:53 volumio go-librespot[14723]: time="2026-04-15T06:01:53+01:00" level=debug msg="completed challenge" Apr 15 06:01:53 volumio go-librespot[14723]: time="2026-04-15T06:01:53+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:53 volumio go-librespot[14723]: time="2026-04-15T06:01:53+01:00" level=debug msg="connected to ap-gue1.spotify.com:443" Apr 15 06:01:53 volumio go-librespot[14723]: time="2026-04-15T06:01:53+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:53 volumio go-librespot[14723]: time="2026-04-15T06:01:53+01:00" level=debug msg="completed challenge" Apr 15 06:01:54 volumio go-librespot[14723]: time="2026-04-15T06:01:54+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:54 volumio go-librespot[14723]: time="2026-04-15T06:01:54+01:00" level=debug msg="connected to ap-gew4.spotify.com:80" Apr 15 06:01:54 volumio go-librespot[14723]: time="2026-04-15T06:01:54+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:54 volumio go-librespot[14723]: time="2026-04-15T06:01:54+01:00" level=debug msg="completed challenge" Apr 15 06:01:54 volumio go-librespot[14723]: time="2026-04-15T06:01:54+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:54 volumio go-librespot[14723]: time="2026-04-15T06:01:54+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 15 06:01:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 06:01:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 06:01:55 volumio volumio[14504]: info: Initializing connection to go-librespot Websocket Apr 15 06:01:55 volumio volumio[14504]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 06:01:57 volumio sudo[14776]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 15 06:01:57 volumio sudo[14776]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:57 volumio sudo[14778]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 15 06:01:57 volumio sudo[14778]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:57 volumio sudo[14776]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:57 volumio sudo[14778]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:57 volumio sudo[14780]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 15 06:01:57 volumio sudo[14780]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:57 volumio sudo[14780]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:57 volumio volumio[14504]: info: Upmpdcli Daemon Started Apr 15 06:01:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Apr 15 06:01:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 15 06:01:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 15 06:01:57 volumio go-librespot[14784]: go-librespot daemon starting... Apr 15 06:01:57 volumio go-librespot[14785]: time="2026-04-15T06:01:57+01:00" level=info msg="running go-librespot 0.6.2" Apr 15 06:01:57 volumio go-librespot[14785]: time="2026-04-15T06:01:57+01:00" level=debug msg="app state loaded" Apr 15 06:01:57 volumio go-librespot[14785]: time="2026-04-15T06:01:57+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 06:01:58 volumio go-librespot[14785]: time="2026-04-15T06:01:58+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 15 06:01:58 volumio go-librespot[14785]: time="2026-04-15T06:01:58+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 15 06:01:58 volumio go-librespot[14785]: time="2026-04-15T06:01:58+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 15 06:01:58 volumio go-librespot[14785]: time="2026-04-15T06:01:58+01:00" level=info msg="zeroconf server listening on port 34791" Apr 15 06:01:58 volumio go-librespot[14785]: time="2026-04-15T06:01:58+01:00" level=debug msg="obtained new client token: AADoQZTzqbemcamBVR4U/jz9a9yMwt+TEZt2yRuIQmr40sm/+OeyrP/OuvxCxj3U+6Yc5L04xuopuvxkHCOH4hPFc+OnZw78jmEa8XDU03ab/l18sVDEIY6ApPwlDPeMHGMKC2T3DgxYmrEYd4jjJ5AJR8OsBmjEIokzBt7IC/dT1MbZGbfRK2hsuO+6Iu4Ea36f8tEMvo2gXp8T38mEIuZlrDkTyIfqdJSfKLRbgmY3T640bwtKh58=" Apr 15 06:01:58 volumio go-librespot[14785]: time="2026-04-15T06:01:58+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 06:01:58 volumio go-librespot[14785]: time="2026-04-15T06:01:58+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:58 volumio go-librespot[14785]: time="2026-04-15T06:01:58+01:00" level=debug msg="completed challenge" Apr 15 06:01:58 volumio go-librespot[14785]: time="2026-04-15T06:01:58+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 15 06:01:58 volumio volumio[14504]: info: Adding plugin bluetooth to MyMusic Plugins Apr 15 06:01:58 volumio volumio[14504]: info: Adding plugin multiroom to MyMusic Plugins Apr 15 06:01:58 volumio volumio[14504]: info: Adding plugin metavolumio to MyMusic Plugins Apr 15 06:01:58 volumio volumio[14504]: info: Adding plugin cd_controller to MyMusic Plugins Apr 15 06:01:58 volumio volumio[14504]: info: Adding plugin qobuzconnect to MyMusic Plugins Apr 15 06:01:58 volumio volumio[14504]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 15 06:01:58 volumio volumio[14504]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 15 06:01:58 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:58 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:01:58 volumio volumio[14504]: info: Starting MyVolumio Remote Streaming Endpoints Apr 15 06:01:58 volumio volumio[14504]: info: MyVolumio login type: Token Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 15 06:01:58 volumio go-librespot[14785]: time="2026-04-15T06:01:58+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 15 06:01:58 volumio go-librespot[14785]: time="2026-04-15T06:01:58+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:58 volumio go-librespot[14785]: time="2026-04-15T06:01:58+01:00" level=debug msg="completed challenge" Apr 15 06:01:58 volumio go-librespot[14785]: time="2026-04-15T06:01:58+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 15 06:01:58 volumio volumio[14504]: info: Streaming services startup Apr 15 06:01:58 volumio volumio[14504]: info: Starting Streaming Daemon Apr 15 06:01:58 volumio sudo[14795]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 15 06:01:58 volumio sudo[14795]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:58 volumio volumio[14504]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 15 06:01:59 volumio sudo[14795]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:59 volumio volumio[14504]: info: Initializing connection to go-librespot Websocket Apr 15 06:01:59 volumio volumio[14504]: error: Cannot start Volumio Streaming Daemon Apr 15 06:01:59 volumio volumio[14504]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 15 06:01:59 volumio volumio[14504]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 15 06:01:59 volumio go-librespot[14785]: time="2026-04-15T06:01:59+01:00" level=debug msg="new websocket client" Apr 15 06:01:59 volumio volumio[14504]: info: Connection to go-librespot Websocket established Apr 15 06:01:59 volumio go-librespot[14785]: time="2026-04-15T06:01:59+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 15 06:01:59 volumio go-librespot[14785]: time="2026-04-15T06:01:59+01:00" level=debug msg="completed keyexchange" Apr 15 06:01:59 volumio go-librespot[14785]: time="2026-04-15T06:01:59+01:00" level=debug msg="completed challenge" Apr 15 06:01:59 volumio go-librespot[14785]: time="2026-04-15T06:01:59+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:01:59 volumio volumio[14504]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 15 06:01:59 volumio volumio[14504]: info: MyVolumio token set successfully Apr 15 06:01:59 volumio volumio[14504]: info: MYVOLUMIO: Adding device Apr 15 06:01:59 volumio volumio[14504]: info: MYVOLUMIO: Evaluating Server Apr 15 06:01:59 volumio volumio[14504]: info: MyVolumio status changed Apr 15 06:01:59 volumio volumio[14504]: info: Streaming services startup Apr 15 06:01:59 volumio volumio[14504]: info: Starting Streaming Daemon Apr 15 06:01:59 volumio volumio[14504]: info: Removing browser output: myVolumio user plan is not superstar Apr 15 06:01:59 volumio volumio[14504]: info: Removing audio output: Apr 15 06:01:59 volumio volumio[14504]: info: Stoppping Tunnel 1 Apr 15 06:01:59 volumio sudo[14822]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 15 06:01:59 volumio sudo[14822]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:59 volumio sudo[14824]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Apr 15 06:01:59 volumio sudo[14824]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:01:59 volumio sudo[14822]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:59 volumio volumio[14504]: error: Cannot start Volumio Streaming Daemon Apr 15 06:01:59 volumio volumio[14504]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 15 06:01:59 volumio volumio[14504]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 15 06:01: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 15 06:01: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 15 06:01: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 15 06:01: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 15 06:01: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 15 06:01: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 15 06:01: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 15 06:01: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 15 06:01:59 volumio sudo[14824]: pam_unix(sudo:session): session closed for user root Apr 15 06:01:59 volumio volumio[14504]: info: Remote SSH Stopped Apr 15 06:02:00 volumio go-librespot[14785]: time="2026-04-15T06:02:00+01:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Apr 15 06:02:00 volumio go-librespot[14785]: time="2026-04-15T06:02:00+01:00" level=debug msg="completed keyexchange" Apr 15 06:02:00 volumio go-librespot[14785]: time="2026-04-15T06:02:00+01:00" level=debug msg="completed challenge" Apr 15 06:02:00 volumio volumio[14504]: info: Setting Geolocation for MyVolumio to eu3 Apr 15 06:02:00 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:02:00 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:02:00 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:02:00 volumio go-librespot[14785]: time="2026-04-15T06:02:00+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:02:00 volumio volumio[14504]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Apr 15 06:02:00 volumio go-librespot[14785]: time="2026-04-15T06:02:00+01:00" level=debug msg="connected to ap-gue1.spotify.com:443" Apr 15 06:02:01 volumio go-librespot[14785]: time="2026-04-15T06:02:01+01:00" level=debug msg="completed keyexchange" Apr 15 06:02:01 volumio go-librespot[14785]: time="2026-04-15T06:02:01+01:00" level=debug msg="completed challenge" Apr 15 06:02:01 volumio go-librespot[14785]: time="2026-04-15T06:02:01+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:02:01 volumio volumio[14504]: info: Updating MyVolumio device info Apr 15 06:02:01 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:02:01 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:02:01 volumio volumio[14504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:02:01 volumio volumio[14504]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Apr 15 06:02:01 volumio go-librespot[14785]: time="2026-04-15T06:02:01+01:00" level=debug msg="connected to ap-gew4.spotify.com:80" Apr 15 06:02:01 volumio go-librespot[14785]: time="2026-04-15T06:02:01+01:00" level=debug msg="completed keyexchange" Apr 15 06:02:01 volumio go-librespot[14785]: time="2026-04-15T06:02:01+01:00" level=debug msg="completed challenge" Apr 15 06:02:01 volumio go-librespot[14785]: time="2026-04-15T06:02:01+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:02:01 volumio go-librespot[14785]: time="2026-04-15T06:02:01+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 15 06:02:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 06:02:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 06:02:01 volumio volumio[14504]: info: Connection to go-librespot Websocket closed Apr 15 06:02:02 volumio volumio[14504]: info: Getting Spotify volume Apr 15 06:02:02 volumio volumio[14504]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 15 06:02:02 volumio volumio[14504]: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 06:02:02 volumio volumio[14504]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Apr 15 06:02:02 volumio volumio[14504]: errno: -111, Apr 15 06:02:02 volumio volumio[14504]: code: 'ECONNREFUSED', Apr 15 06:02:02 volumio volumio[14504]: syscall: 'connect', Apr 15 06:02:02 volumio volumio[14504]: address: '127.0.0.1', Apr 15 06:02:02 volumio volumio[14504]: port: 9879, Apr 15 06:02:02 volumio volumio[14504]: response: undefined Apr 15 06:02:02 volumio volumio[14504]: } Apr 15 06:02:02 volumio volumio[14504]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 15 06:02:02 volumio sudo[14841]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-15 06:01' Apr 15 06:02:02 volumio sudo[14841]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:02:02 volumio sudo[14841]: pam_unix(sudo:session): session closed for user root Apr 15 06:02:02 volumio volumio-remote-updater[945]: [2026-04-15 06:02:02] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Apr 15 06:02:02 volumio volumio-remote-updater[945]: [2026-04-15 06:02:02] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Apr 15 06:02:02 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Apr 15 06:02:02 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Apr 15 06:02:02 volumio systemd[1]: volumio.service: Consumed 8.852s CPU time. Apr 15 06:02:02 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 15 06:02:02 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 15 06:02:02 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 121877. Apr 15 06:02:02 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 15 06:02:02 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Apr 15 06:02:02 volumio systemd[1]: volumio.service: Consumed 8.852s CPU time. Apr 15 06:02:02 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Apr 15 06:02:02 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 15 06:02:03 volumio volumio[14853]: info: ------------------------------------------- Apr 15 06:02:03 volumio volumio[14853]: info: ----- Volumio3 ---- Apr 15 06:02:03 volumio volumio[14853]: info: ------------------------------------------- Apr 15 06:02:03 volumio volumio[14853]: info: ----- System startup ---- Apr 15 06:02:03 volumio volumio[14853]: info: ------------------------------------------- Apr 15 06:02:03 volumio volumio[14853]: info: MYVOLUMIO Environment detected Apr 15 06:02:03 volumio volumio[14853]: info: Plugin folders cleanup Apr 15 06:02:03 volumio volumio[14853]: info: Scanning into folder /volumio/app/plugins/ Apr 15 06:02:03 volumio volumio[14853]: info: Scanning category audio_interface Apr 15 06:02:03 volumio volumio[14853]: info: Scanning category miscellanea Apr 15 06:02:03 volumio volumio[14853]: info: Scanning category music_service Apr 15 06:02:03 volumio volumio[14853]: info: Scanning category plugins.json Apr 15 06:02:03 volumio volumio[14853]: info: Scanning category system_controller Apr 15 06:02:03 volumio volumio[14853]: info: Scanning category user_interface Apr 15 06:02:03 volumio volumio[14853]: info: Scanning into folder /data/plugins/ Apr 15 06:02:03 volumio volumio[14853]: info: Scanning category music_service Apr 15 06:02:03 volumio volumio[14853]: info: Plugin folders cleanup completed Apr 15 06:02:03 volumio volumio[14853]: info: ------------------------------------------- Apr 15 06:02:03 volumio volumio[14853]: info: ----- Core plugins startup ---- Apr 15 06:02:03 volumio volumio[14853]: info: ------------------------------------------- Apr 15 06:02:03 volumio volumio[14853]: info: Loading plugins from folder /volumio/app/plugins/ Apr 15 06:02:03 volumio volumio[14853]: info: Adding plugin upnp to MyMusic Plugins Apr 15 06:02:03 volumio volumio[14853]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 15 06:02:03 volumio volumio[14853]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 15 06:02:03 volumio volumio[14853]: info: Loading plugins from folder /data/plugins/ Apr 15 06:02:03 volumio volumio[14853]: info: Adding plugin rtlsdr_radio to MyMusic Plugins Apr 15 06:02:03 volumio volumio[14853]: info: Loading plugin "system"... Apr 15 06:02:03 volumio volumio[14853]: info: Loading plugin "appearance"... Apr 15 06:02:03 volumio volumio[14853]: info: Loading plugin "network"... Apr 15 06:02:03 volumio volumio[14853]: info: Refreshing Cached IP Addresses Apr 15 06:02:03 volumio sudo[14882]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 15 06:02:03 volumio sudo[14882]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:02:03 volumio sudo[14884]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 15 06:02:03 volumio sudo[14884]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:02:03 volumio sudo[14884]: pam_unix(sudo:session): session closed for user root Apr 15 06:02:03 volumio sudo[14882]: pam_unix(sudo:session): session closed for user root Apr 15 06:02:03 volumio volumio[14853]: info: Loading plugin "services"... Apr 15 06:02:03 volumio volumio[14853]: info: Loading plugin "alsa_controller"... Apr 15 06:02:03 volumio sudo[14897]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 15 06:02:03 volumio sudo[14897]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:02:03 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 15 06:02:03 volumio volumio[14853]: info: Loading plugin "wizard"... Apr 15 06:02:03 volumio volumio[14853]: info: Loading plugin "networkfs"... Apr 15 06:02:03 volumio volumio[14853]: info: Starting Udev Watcher for removable devices Apr 15 06:02:03 volumio volumio[14853]: info: Mounting Device 0ACB-A1DE Apr 15 06:02:03 volumio sudo[14921]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/0ACB-A1DE -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Apr 15 06:02:03 volumio sudo[14921]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:02:03 volumio sudo[14921]: pam_unix(sudo:session): session closed for user root Apr 15 06:02:03 volumio volumio[14853]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Apr 15 06:02:03 volumio volumio[14853]: dmesg(1) may have more information after failed mount system call. Apr 15 06:02:03 volumio volumio[14853]: 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 15 06:02:03 volumio volumio[14853]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Apr 15 06:02:03 volumio volumio[14853]: dmesg(1) may have more information after failed mount system call. Apr 15 06:02:03 volumio volumio[14853]: info: Ignoring mount for partition: boot Apr 15 06:02:03 volumio volumio[14853]: info: Ignoring mount for partition: volumio Apr 15 06:02:03 volumio volumio[14853]: info: Ignoring mount for partition: volumio_data Apr 15 06:02:03 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 15 06:02:03 volumio volumio[14853]: info: Loading plugin "volumio_command_line_client"... Apr 15 06:02:03 volumio volumio[14853]: info: Loading plugin "upnp"... Apr 15 06:02:03 volumio volumio[14853]: info: [1776229323867] Starting Upmpd Daemon Apr 15 06:02:03 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 15 06:02:03 volumio volumio[14853]: info: Loading plugin "my_music"... Apr 15 06:02:03 volumio volumio[14853]: info: Loading plugin "mpd"... Apr 15 06:02:03 volumio volumio[14853]: info: Loading plugin "upnp_browser"... Apr 15 06:02:04 volumio volumio[14853]: info: Starting UPNP Browser Apr 15 06:02:04 volumio volumio[14853]: info: Loading plugin "alarm-clock"... Apr 15 06:02:04 volumio volumio[14853]: info: Loading plugin "airplay_emulation"... Apr 15 06:02:04 volumio volumio[14853]: info: Starting Shairport Sync Apr 15 06:02:04 volumio volumio[14853]: info: Loading plugin "last_100"... Apr 15 06:02:04 volumio volumio[14853]: info: Loading plugin "webradio"... Apr 15 06:02:04 volumio volumio[14853]: info: Loading plugin "i2s_dacs"... Apr 15 06:02:04 volumio volumio[14853]: info: Loading plugin "volumiodiscovery"... Apr 15 06:02:04 volumio volumio[14853]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 15 06:02:04 volumio volumio[14853]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 15 06:02:04 volumio volumio[14853]: *** WARNING *** For more information see Apr 15 06:02:04 volumio volumio[14853]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 15 06:02:04 volumio volumio[14853]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 15 06:02:04 volumio volumio[14853]: *** WARNING *** For more information see Apr 15 06:02:04 volumio node[14853]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 15 06:02:04 volumio node[14853]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 15 06:02:04 volumio node[14853]: *** WARNING *** For more information see Apr 15 06:02:04 volumio node[14853]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 15 06:02:04 volumio node[14853]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 15 06:02:04 volumio node[14853]: *** WARNING *** For more information see Apr 15 06:02:04 volumio volumio[14853]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 15 06:02:04 volumio volumio[14853]: info: Discovery: Started advertising with name: Volumio Apr 15 06:02:04 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 15 06:02:04 volumio volumio[14853]: info: Loading plugin "spop"... Apr 15 06:02:04 volumio volumio[14853]: info: Loading plugin "ytmusic"... Apr 15 06:02:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Apr 15 06:02:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 15 06:02:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 15 06:02:04 volumio go-librespot[14925]: go-librespot daemon starting... Apr 15 06:02:04 volumio go-librespot[14926]: time="2026-04-15T06:02:04+01:00" level=info msg="running go-librespot 0.6.2" Apr 15 06:02:04 volumio go-librespot[14926]: time="2026-04-15T06:02:04+01:00" level=debug msg="app state loaded" Apr 15 06:02:04 volumio go-librespot[14926]: time="2026-04-15T06:02:04+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 06:02:05 volumio volumio[14853]: info: Loading plugin "outputs"... Apr 15 06:02:05 volumio volumio[14853]: info: Loading plugin "albumart"... Apr 15 06:02:05 volumio volumio[14853]: info: Plugin example_plugin is not enabled Apr 15 06:02:05 volumio volumio[14853]: info: Loading plugin "inputs"... Apr 15 06:02:05 volumio volumio[14853]: info: Loading plugin "updater_comm"... Apr 15 06:02:05 volumio volumio[14853]: info: Plugin mpdemulation is not enabled Apr 15 06:02:05 volumio volumio[14853]: info: Loading plugin "rest_api"... Apr 15 06:02:05 volumio volumio[14853]: info: Loading plugin "websocket"... Apr 15 06:02:05 volumio volumio[14853]: info: Starting Socket.io Server version 1.7.4 Apr 15 06:02:05 volumio volumio[14853]: info: Loading plugin "podcast"... Apr 15 06:02:05 volumio volumio[14853]: info: ControllerPodcast::constructor Apr 15 06:02:05 volumio volumio[14853]: info: Loading plugin "rtlsdr_radio"... Apr 15 06:02:05 volumio volumio[14932]: Forking 3 albumart workers Apr 15 06:02:05 volumio volumio[14853]: info: Loading i18n strings for locale en Apr 15 06:02:05 volumio volumio[14853]: Updating browse sources language Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 06:02:05 volumio go-librespot[14926]: time="2026-04-15T06:02: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 15 06:02:05 volumio go-librespot[14926]: time="2026-04-15T06:02: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 15 06:02:05 volumio go-librespot[14926]: time="2026-04-15T06:02: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 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::initPlayerControls Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 15 06:02:05 volumio go-librespot[14926]: time="2026-04-15T06:02:05+01:00" level=info msg="zeroconf server listening on port 39773" Apr 15 06:02:05 volumio volumio[14853]: Express server listening on port 3000 Apr 15 06:02:05 volumio volumio[14853]: [Metrics] WebUI: 2s 350.23ms Apr 15 06:02:05 volumio volumio[14853]: info: CoreStateMachine::resetVolumioState Apr 15 06:02:05 volumio volumio[14853]: info: CoreStateMachine::getcurrentVolume Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::volumioRetrievevolume Apr 15 06:02:05 volumio volumio[14853]: info: Volumio Network Manager: Network status updated: 2 Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:02:05 volumio volumio[14853]: info: Reloading queue from file Apr 15 06:02:05 volumio volumio[14853]: info: VolumeController:: Volume=36 Mute =true Apr 15 06:02:05 volumio volumio[14853]: info: CoreStateMachine::pushState Apr 15 06:02:05 volumio volumio[14853]: info: CorePlayQueue::getTrack 0 Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::volumioPushState Apr 15 06:02:05 volumio volumio[14853]: info: CoreStateMachine::updateTrackBlock Apr 15 06:02:05 volumio volumio[14853]: info: CorePlayQueue::getTrackBlock Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::volumioRetrievevolume Apr 15 06:02:05 volumio volumio[14853]: info: CoreStateMachine::setRepeat null single undefined Apr 15 06:02:05 volumio volumio[14853]: info: CoreStateMachine::pushState Apr 15 06:02:05 volumio volumio[14853]: info: CorePlayQueue::getTrack 0 Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::volumioPushState Apr 15 06:02:05 volumio volumio[14853]: info: CoreStateMachine::setRandom true Apr 15 06:02:05 volumio volumio[14853]: info: CoreStateMachine::pushState Apr 15 06:02:05 volumio volumio[14853]: info: CorePlayQueue::getTrack 0 Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::volumioPushState Apr 15 06:02:05 volumio volumio[14853]: info: Setting Device type: Raspberry PI Apr 15 06:02:05 volumio volumio[14853]: info: Completed loading Core Plugins Apr 15 06:02:05 volumio volumio[14853]: info: Preparing to generate the ALSA configuration file Apr 15 06:02:05 volumio volumio[14853]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Apr 15 06:02:05 volumio volumio[14853]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04170 Apr 15 06:02:05 volumio volumio[14853]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Apr 15 06:02:05 volumio volumio[14853]: info: VolumeController:: Volume=36 Mute =true Apr 15 06:02:05 volumio volumio[14853]: info: CoreStateMachine::pushState Apr 15 06:02:05 volumio volumio[14853]: info: CorePlayQueue::getTrack 0 Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::volumioPushState Apr 15 06:02:05 volumio volumio[14853]: info: Asound.conf file unchanged, so no further update is needed Apr 15 06:02:05 volumio volumio[14853]: info: Output device has changed, restarting MPD Apr 15 06:02:05 volumio volumio[14853]: info: Output device has changed, restarting Shairport Sync Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:02:05 volumio sudo[14992]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 15 06:02:05 volumio sudo[14992]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:02:05 volumio sudo[14994]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 15 06:02:05 volumio sudo[14994]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:02:05 volumio sudo[14992]: pam_unix(sudo:session): session closed for user root Apr 15 06:02:05 volumio volumio[14853]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 15 06:02:05 volumio volumio[14853]: info: ___________ START PLUGINS ___________ Apr 15 06:02:05 volumio volumio[14853]: info: ControllerMpd::onStart: Initializing MPD Apr 15 06:02:05 volumio volumio[14853]: info: Creating MPD Configuration file Apr 15 06:02:05 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 15 06:02:05 volumio sudo[15002]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 15 06:02:05 volumio sudo[15002]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 15 06:02:05 volumio volumio[14853]: info: [1776229325657] CoreMusicLibrary::Adding element Media Servers Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 06:02:05 volumio sudo[15002]: pam_unix(sudo:session): session closed for user root Apr 15 06:02:05 volumio volumio[14853]: info: UPNP Browser: Client initialized successfully Apr 15 06:02:05 volumio volumio[14944]: Starting albumart workers Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:02:05 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 15 06:02:05 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 15 06:02:05 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 15 06:02:05 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 15 06:02:05 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 15 06:02:05 volumio sudo[15005]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 15 06:02:05 volumio sudo[15005]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:02:05 volumio volumio[14943]: Starting albumart workers Apr 15 06:02:05 volumio volumio[14853]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:02:05 volumio volumio[14853]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 15 06:02:05 volumio volumio[14853]: info: [1776229325700] CoreMusicLibrary::Adding element Last_100 Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 06:02:05 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 15 06:02:05 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 15 06:02:05 volumio volumio[14942]: Starting albumart workers Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 15 06:02:05 volumio volumio[14853]: info: [1776229325714] CoreMusicLibrary::Adding element Webradio Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 15 06:02:05 volumio volumio[14853]: info: Initializing BBC Radios Apr 15 06:02:05 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 15 06:02:05 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 15 06:02:05 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 15 06:02:05 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 15 06:02:05 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 15 06:02:05 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 15 06:02:05 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 15 06:02:05 volumio go-librespot[14926]: time="2026-04-15T06:02:05+01:00" level=debug msg="obtained new client token: AADiBiFGIOm9F+mRIy0k65DUkobYyZ9ZWqRpacb4OyhxiORwgnOuidTC+kJOBERtBK+z/UaGh5fnhXQbbTWLQ2p00CV1qyRwIQGq/dUbA06QBecx3H2lLgVfhv+4ximFRwlKQApa5tcw7Xte21CTAIJXTjASwc/a5D5ssPwiY78ai/w42+BLu2BmMMa+ltE96qo0CcR2/qTY9HmjqP+w2O4z9PA9UojPpMPgOmhNUsZhpe6DXHiYRJlihQ==" Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:02:05 volumio volumio[14853]: info: Creating Spotify config file Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:02:05 volumio sudo[15026]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 15 06:02:05 volumio sudo[15026]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 15 06:02:05 volumio sudo[15026]: pam_unix(sudo:session): session closed for user root Apr 15 06:02:05 volumio go-librespot[14926]: time="2026-04-15T06:02:05+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 15 06:02:05 volumio volumio[14853]: info: [1776229325926] CoreMusicLibrary::Adding element YouTube Music Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 06:02:05 volumio volumio[14853]: Cannot find translation for source YouTube Music Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 15 06:02:05 volumio volumio[14853]: info: [1776229325939] CoreMusicLibrary::Adding element Podcast Apr 15 06:02:05 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 06:02:05 volumio volumio[14853]: Cannot find translation for source YouTube Music Apr 15 06:02:05 volumio volumio[14853]: Cannot find translation for source Podcast Apr 15 06:02:05 volumio volumio[14853]: info: [RTL-SDR Radio] Starting plugin Apr 15 06:02:05 volumio go-librespot[14926]: time="2026-04-15T06:02:05+01:00" level=debug msg="completed keyexchange" Apr 15 06:02:05 volumio go-librespot[14926]: time="2026-04-15T06:02:05+01:00" level=debug msg="completed challenge" Apr 15 06:02:05 volumio volumio[14853]: info: [RTL-SDR Radio] Loaded i18n strings for language: en Apr 15 06:02:05 volumio volumio[14853]: info: Volumio Calling Home Apr 15 06:02:05 volumio volumio[14853]: info: [RTL-SDR Radio] snd-aloop already loaded Apr 15 06:02:05 volumio volumio[14853]: info: [RTL-SDR Radio] No stations database found, creating v2 Apr 15 06:02:05 volumio volumio[14853]: info: [RTL-SDR Radio] Database loaded at: 2026-04-15T05:02:05.995Z Apr 15 06:02:06 volumio volumio[14853]: info: [RTL-SDR Radio] Loading blocklist from: /data/plugins/music_service/rtlsdr_radio/blocklist.json Apr 15 06:02:06 volumio volumio[14853]: info: [RTL-SDR Radio] Got 21 phrases from file Apr 15 06:02:06 volumio volumio[14853]: info: [RTL-SDR Radio] Updated metadata blocklist Apr 15 06:02:06 volumio volumio[14853]: info: [RTL-SDR Radio] Metadata module now has 21 phrases Apr 15 06:02:06 volumio volumio[14853]: info: [RTL-SDR Radio] Management server started on port 3456 Apr 15 06:02:06 volumio volumio[14853]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 15 06:02:06 volumio volumio[14853]: info: [1776229326036] CoreMusicLibrary::Adding element FM/DAB Radio Apr 15 06:02:06 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 06:02:06 volumio volumio[14853]: Cannot find translation for source YouTube Music Apr 15 06:02:06 volumio volumio[14853]: Cannot find translation for source Podcast Apr 15 06:02:06 volumio volumio[14853]: Cannot find translation for source FM/DAB Radio Apr 15 06:02:06 volumio volumio[14853]: info: [RTL-SDR Radio] Plugin started successfully Apr 15 06:02:06 volumio volumio[14853]: info: Discovery: adding 072f109f-54a2-4344-b8c4-538b45da7e51 Apr 15 06:02:06 volumio volumio[14853]: info: Discovery: Found device Volumio Apr 15 06:02:06 volumio volumio[14853]: info: CoreCommandRouter::volumioGetState Apr 15 06:02:06 volumio volumio[14853]: info: CorePlayQueue::getTrack 0 Apr 15 06:02:06 volumio volumio[14853]: info: Discovery: this is already registered, 072f109f-54a2-4344-b8c4-538b45da7e51 Apr 15 06:02:06 volumio volumio[14853]: info: Discovery: Found device Volumio Apr 15 06:02:06 volumio volumio[14853]: info: CoreCommandRouter::volumioGetState Apr 15 06:02:06 volumio volumio[14853]: info: CorePlayQueue::getTrack 0 Apr 15 06:02:06 volumio volumio[14853]: info: MPD Permissions set Apr 15 06:02:06 volumio volumio[14853]: info: MPD Permissions set Apr 15 06:02:06 volumio volumio[14853]: info: Spotify config file written Apr 15 06:02:06 volumio sudo[15060]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 15 06:02:06 volumio sudo[15060]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:02:06 volumio go-librespot[14926]: time="2026-04-15T06:02:06+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:02:06 volumio volumio[14853]: 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 15 06:02:06 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:02:06 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:02:06 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:02:06 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:02:06 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:02:06 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:02:06 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:02:06 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:02:06 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Apr 15 06:02:06 volumio systemd[1]: go-librespot-daemon.service: Killing process 14928 (go-librespot) with signal SIGKILL. Apr 15 06:02:06 volumio systemd[1]: go-librespot-daemon.service: Killing process 14931 (go-librespot) with signal SIGKILL. Apr 15 06:02:06 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Apr 15 06:02:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 15 06:02:06 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:02:06 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:02:06 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:02:06 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:02:06 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:02:06 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:02:06 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:02:06 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:02:06 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:02:06 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:02:06 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:02:06 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 06:02:06 volumio volumio[14853]: info: No need to fix Spotify hosts Apr 15 06:02:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 15 06:02:06 volumio go-librespot[15067]: go-librespot daemon starting... Apr 15 06:02:06 volumio sudo[15060]: pam_unix(sudo:session): session closed for user root Apr 15 06:02:06 volumio go-librespot[15073]: time="2026-04-15T06:02:06+01:00" level=info msg="running go-librespot 0.6.2" Apr 15 06:02:06 volumio go-librespot[15073]: time="2026-04-15T06:02:06+01:00" level=debug msg="app state loaded" Apr 15 06:02:06 volumio go-librespot[15073]: time="2026-04-15T06:02:06+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 06:02:06 volumio volumio[14853]: info: Starting Shairport Sync Apr 15 06:02:06 volumio volumio[14853]: info: Starting Shairport Sync Apr 15 06:02:06 volumio volumio[14853]: info: Starting Shairport Sync Apr 15 06:02:06 volumio sudo[15079]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 15 06:02:06 volumio sudo[15079]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:02:06 volumio sudo[15081]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 15 06:02:06 volumio sudo[15081]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:02:06 volumio sudo[15083]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 15 06:02:06 volumio sudo[15083]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:02:06 volumio volumio[14853]: info: CoreCommandRouter::volumioGetState Apr 15 06:02:06 volumio volumio[14853]: info: CorePlayQueue::getTrack 0 Apr 15 06:02:06 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 15 06:02:06 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 15 06:02:06 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 15 06:02:06 volumio systemd[1]: shairport-sync.service: Consumed 1.551s CPU time. Apr 15 06:02:06 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 15 06:02:06 volumio sudo[15079]: pam_unix(sudo:session): session closed for user root Apr 15 06:02:06 volumio volumio[14853]: info: Shairport-Sync Started Apr 15 06:02:06 volumio sudo[15083]: pam_unix(sudo:session): session closed for user root Apr 15 06:02:06 volumio volumio[14853]: Error adding Membership: Error: addMembership EINVAL Apr 15 06:02:06 volumio sudo[15081]: pam_unix(sudo:session): session closed for user root Apr 15 06:02:06 volumio volumio[14853]: info: Shairport-Sync Started Apr 15 06:02:06 volumio volumio[14853]: info: Shairport-Sync Started Apr 15 06:02:06 volumio volumio[14853]: info: Volumio called home Apr 15 06:02:06 volumio volumio[14853]: info: An error occurred while refreshing Spotify Token Error: Bad Request Apr 15 06:02:06 volumio mpd[15033]: 2026-04-15T06:02:06 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 15 06:02:06 volumio systemd[1]: Started mpd.service - Music Player Daemon. Apr 15 06:02:06 volumio sudo[14994]: pam_unix(sudo:session): session closed for user root Apr 15 06:02:06 volumio sudo[15005]: pam_unix(sudo:session): session closed for user root Apr 15 06:02:06 volumio volumio[14853]: error: updateQueue error: null Apr 15 06:02:06 volumio volumio[14853]: info: Completed starting Core Plugins Apr 15 06:02:06 volumio volumio[14853]: info: ------------------------------------------- Apr 15 06:02:06 volumio volumio[14853]: info: ----- MyVolumio plugins startup ---- Apr 15 06:02:06 volumio volumio[14853]: info: ------------------------------------------- Apr 15 06:02:06 volumio volumio[14853]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 15 06:02:06 volumio volumio[14853]: error: updateQueue error: null Apr 15 06:02:06 volumio volumio[14853]: info: MPD running with PID15033 Apr 15 06:02:06 volumio volumio[14853]: ,establishing connection Apr 15 06:02:06 volumio volumio[14853]: error: updateQueue error: null Apr 15 06:02:06 volumio go-librespot[15073]: time="2026-04-15T06:02:06+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 15 06:02:06 volumio go-librespot[15073]: time="2026-04-15T06:02:06+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 15 06:02:06 volumio go-librespot[15073]: time="2026-04-15T06:02:06+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 15 06:02:06 volumio go-librespot[15073]: time="2026-04-15T06:02:06+01:00" level=info msg="zeroconf server listening on port 35555" Apr 15 06:02:07 volumio volumio-remote-updater[945]: [2026-04-15 06:02:07] [connect] Successful connection Apr 15 06:02:07 volumio volumio-remote-updater[945]: [2026-04-15 06:02:07] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1776229327 101 Apr 15 06:02:07 volumio volumio[14853]: 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 15 06:02:07 volumio go-librespot[15073]: time="2026-04-15T06:02:07+01:00" level=debug msg="obtained new client token: AAByOxR5k39s9HEikDGPbfFVme2Fwz7/GnOqh4rgfID7V2tOOomGRlzmhDBAs1rET2B4d/S1tn3pwnG370pzMEr3fzDbkRBSOfMAy5h/P4qzZRzAXVo9fVvuJCs7pZet6dLBiY6jxYSJnCoqNRld+pVyK1EftSnPvitZOygUXar3BnVdnmHxBIlPiM1fLkl48TxfKw6pkAlc5fr6xt66NZcneH19OGtuhkaDWbWVb9IGZM2MKBKzRXIRSQ==" Apr 15 06:02:07 volumio go-librespot[15073]: time="2026-04-15T06:02:07+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 06:02:07 volumio go-librespot[15073]: time="2026-04-15T06:02:07+01:00" level=debug msg="completed keyexchange" Apr 15 06:02:07 volumio go-librespot[15073]: time="2026-04-15T06:02:07+01:00" level=debug msg="completed challenge" Apr 15 06:02:07 volumio go-librespot[15073]: time="2026-04-15T06:02:07+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:02:07 volumio sudo[14897]: pam_unix(sudo:session): session closed for user root Apr 15 06:02:08 volumio go-librespot[15073]: time="2026-04-15T06:02:08+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 15 06:02:08 volumio go-librespot[15073]: time="2026-04-15T06:02:08+01:00" level=debug msg="completed keyexchange" Apr 15 06:02:08 volumio go-librespot[15073]: time="2026-04-15T06:02:08+01:00" level=debug msg="completed challenge" Apr 15 06:02:08 volumio go-librespot[15073]: time="2026-04-15T06:02:08+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:02:08 volumio go-librespot[15073]: time="2026-04-15T06:02:08+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 15 06:02:08 volumio go-librespot[15073]: time="2026-04-15T06:02:08+01:00" level=debug msg="completed keyexchange" Apr 15 06:02:08 volumio go-librespot[15073]: time="2026-04-15T06:02:08+01:00" level=debug msg="completed challenge" Apr 15 06:02:08 volumio go-librespot[15073]: time="2026-04-15T06:02:08+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:02:09 volumio volumio[14853]: info: go-librespot daemon successfully initialized Apr 15 06:02:09 volumio go-librespot[15073]: time="2026-04-15T06:02:09+01:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Apr 15 06:02:09 volumio go-librespot[15073]: time="2026-04-15T06:02:09+01:00" level=debug msg="completed keyexchange" Apr 15 06:02:09 volumio go-librespot[15073]: time="2026-04-15T06:02:09+01:00" level=debug msg="completed challenge" Apr 15 06:02:09 volumio go-librespot[15073]: time="2026-04-15T06:02:09+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:02:10 volumio go-librespot[15073]: time="2026-04-15T06:02:10+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Apr 15 06:02:10 volumio go-librespot[15073]: time="2026-04-15T06:02:10+01:00" level=debug msg="completed keyexchange" Apr 15 06:02:10 volumio go-librespot[15073]: time="2026-04-15T06:02:10+01:00" level=debug msg="completed challenge" Apr 15 06:02:10 volumio go-librespot[15073]: time="2026-04-15T06:02:10+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:02:10 volumio go-librespot[15073]: time="2026-04-15T06:02:10+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 15 06:02:11 volumio go-librespot[15073]: time="2026-04-15T06:02:11+01:00" level=debug msg="completed keyexchange" Apr 15 06:02:11 volumio go-librespot[15073]: time="2026-04-15T06:02:11+01:00" level=debug msg="completed challenge" Apr 15 06:02:11 volumio go-librespot[15073]: time="2026-04-15T06:02:11+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:02:11 volumio go-librespot[15073]: time="2026-04-15T06:02: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 15 06:02:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 06:02:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 06:02:12 volumio volumio[14853]: info: Initializing connection to go-librespot Websocket Apr 15 06:02:12 volumio volumio[14853]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 06:02:13 volumio sudo[15127]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 15 06:02:13 volumio sudo[15127]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:02:13 volumio sudo[15129]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 15 06:02:13 volumio sudo[15127]: pam_unix(sudo:session): session closed for user root Apr 15 06:02:13 volumio sudo[15129]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:02:13 volumio sudo[15129]: pam_unix(sudo:session): session closed for user root Apr 15 06:02:13 volumio sudo[15131]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 15 06:02:13 volumio sudo[15131]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:02:13 volumio sudo[15131]: pam_unix(sudo:session): session closed for user root Apr 15 06:02:13 volumio volumio[14853]: info: Upmpdcli Daemon Started Apr 15 06:02:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Apr 15 06:02:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 15 06:02:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 15 06:02:14 volumio go-librespot[15135]: go-librespot daemon starting... Apr 15 06:02:14 volumio go-librespot[15136]: time="2026-04-15T06:02:14+01:00" level=info msg="running go-librespot 0.6.2" Apr 15 06:02:14 volumio go-librespot[15136]: time="2026-04-15T06:02:14+01:00" level=debug msg="app state loaded" Apr 15 06:02:14 volumio go-librespot[15136]: time="2026-04-15T06:02:14+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 06:02:14 volumio go-librespot[15136]: time="2026-04-15T06:02:14+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 15 06:02:14 volumio go-librespot[15136]: time="2026-04-15T06:02:14+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 15 06:02:14 volumio go-librespot[15136]: time="2026-04-15T06:02:14+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 15 06:02:14 volumio go-librespot[15136]: time="2026-04-15T06:02:14+01:00" level=info msg="zeroconf server listening on port 43627" Apr 15 06:02:14 volumio volumio[14853]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 15 06:02:14 volumio volumio[14853]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 15 06:02:14 volumio volumio[14853]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 15 06:02:14 volumio volumio[14853]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 15 06:02:14 volumio volumio[14853]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 15 06:02:14 volumio volumio[14853]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 15 06:02:14 volumio volumio[14853]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 15 06:02:14 volumio volumio[14853]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 15 06:02:14 volumio volumio[14853]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 15 06:02:14 volumio volumio[14853]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 15 06:02:14 volumio volumio[14853]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Apr 15 06:02:14 volumio volumio[14853]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 15 06:02:14 volumio volumio[14853]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 15 06:02:14 volumio volumio[14853]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 15 06:02:14 volumio volumio[14853]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 15 06:02:14 volumio volumio[14853]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 15 06:02:14 volumio volumio[14853]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 15 06:02:14 volumio volumio[14853]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 15 06:02:14 volumio volumio[14853]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 15 06:02:14 volumio volumio[14853]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 15 06:02:14 volumio volumio[14853]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 15 06:02:14 volumio volumio[14853]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Apr 15 06:02:14 volumio volumio[14853]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 15 06:02:14 volumio volumio[14853]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 15 06:02:14 volumio volumio[14853]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 15 06:02:14 volumio volumio[14853]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 15 06:02:14 volumio volumio[14853]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 15 06:02:14 volumio volumio[14853]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 15 06:02:14 volumio volumio[14853]: info: Adding plugin bluetooth to MyMusic Plugins Apr 15 06:02:14 volumio volumio[14853]: info: Adding plugin multiroom to MyMusic Plugins Apr 15 06:02:14 volumio volumio[14853]: info: Adding plugin metavolumio to MyMusic Plugins Apr 15 06:02:14 volumio volumio[14853]: info: Adding plugin cd_controller to MyMusic Plugins Apr 15 06:02:14 volumio volumio[14853]: info: Adding plugin qobuzconnect to MyMusic Plugins Apr 15 06:02:14 volumio volumio[14853]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 15 06:02:14 volumio volumio[14853]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 15 06:02:14 volumio volumio[14853]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 15 06:02:14 volumio go-librespot[15136]: time="2026-04-15T06:02:14+01:00" level=debug msg="obtained new client token: AAAO3oyuAO5GZ76Xsi75Yao6y2o1W8+Hepctt5kqnoX/jS36Y8nNxzIQSJBliYa3r27VqYXmdGPQA15eWwb3wwCDzta0obPfN0eh88BcGDiwu67KZiGtRmTj1NdUOdrTmCtvGU9OV+/uU0aHODigguu1vxZTcfcJvYzcR35q0p6cRm+JJQeBe48fasmpZZyzI58QjaUOBDmz475/XFC78lw1KGt/hw4/D8vgeIzi08fp/48L2gjjYSK3ew==" Apr 15 06:02:14 volumio go-librespot[15136]: time="2026-04-15T06:02:14+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 06:02:14 volumio go-librespot[15136]: time="2026-04-15T06:02:14+01:00" level=debug msg="completed keyexchange" Apr 15 06:02:14 volumio go-librespot[15136]: time="2026-04-15T06:02:14+01:00" level=debug msg="completed challenge" Apr 15 06:02:15 volumio go-librespot[15136]: time="2026-04-15T06:02:15+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:02:15 volumio volumio[14853]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 15 06:02:15 volumio volumio[14853]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 15 06:02:15 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:02:15 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:02:15 volumio volumio[14853]: info: Starting MyVolumio Remote Streaming Endpoints Apr 15 06:02:15 volumio volumio[14853]: info: MyVolumio login type: Token Apr 15 06:02:15 volumio volumio[14853]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 15 06:02:15 volumio volumio[14853]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 15 06:02:15 volumio volumio[14853]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 15 06:02:15 volumio volumio[14853]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 15 06:02:15 volumio volumio[14853]: info: Streaming services startup Apr 15 06:02:15 volumio volumio[14853]: info: Starting Streaming Daemon Apr 15 06:02:15 volumio sudo[15146]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 15 06:02:15 volumio sudo[15146]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:02:15 volumio volumio[14853]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 15 06:02:15 volumio sudo[15146]: pam_unix(sudo:session): session closed for user root Apr 15 06:02:15 volumio volumio[14853]: info: Initializing connection to go-librespot Websocket Apr 15 06:02:15 volumio volumio[14853]: error: Cannot start Volumio Streaming Daemon Apr 15 06:02:15 volumio volumio[14853]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 15 06:02:15 volumio volumio[14853]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 15 06:02:15 volumio go-librespot[15136]: time="2026-04-15T06:02:15+01:00" level=debug msg="new websocket client" Apr 15 06:02:15 volumio volumio[14853]: info: Connection to go-librespot Websocket established Apr 15 06:02:15 volumio go-librespot[15136]: time="2026-04-15T06:02:15+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 15 06:02:15 volumio go-librespot[15136]: time="2026-04-15T06:02:15+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 15 06:02:15 volumio go-librespot[15136]: time="2026-04-15T06:02:15+01:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" Apr 15 06:02:15 volumio go-librespot[15136]: time="2026-04-15T06:02:15+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.1.133:443: connect: connection refused" Apr 15 06:02:15 volumio volumio[14853]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 15 06:02:15 volumio go-librespot[15136]: time="2026-04-15T06:02:15+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 15 06:02:16 volumio go-librespot[15136]: time="2026-04-15T06:02:16+01:00" level=debug msg="completed keyexchange" Apr 15 06:02:16 volumio go-librespot[15136]: time="2026-04-15T06:02:16+01:00" level=debug msg="completed challenge" Apr 15 06:02:16 volumio volumio[14853]: info: MyVolumio token set successfully Apr 15 06:02:16 volumio volumio[14853]: info: MYVOLUMIO: Adding device Apr 15 06:02:16 volumio volumio[14853]: info: MYVOLUMIO: Evaluating Server Apr 15 06:02:16 volumio go-librespot[15136]: time="2026-04-15T06:02:16+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:02:16 volumio volumio[14853]: info: MyVolumio status changed Apr 15 06:02:16 volumio volumio[14853]: info: Streaming services startup Apr 15 06:02:16 volumio volumio[14853]: info: Starting Streaming Daemon Apr 15 06:02:16 volumio volumio[14853]: info: Removing browser output: myVolumio user plan is not superstar Apr 15 06:02:16 volumio volumio[14853]: info: Removing audio output: Apr 15 06:02:16 volumio volumio[14853]: info: Stoppping Tunnel 1 Apr 15 06:02:16 volumio sudo[15173]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 15 06:02:16 volumio sudo[15173]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:02:16 volumio sudo[15175]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Apr 15 06:02:16 volumio sudo[15175]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 06:02: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 15 06:02: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 15 06:02:16 volumio sudo[15173]: pam_unix(sudo:session): session closed for user root Apr 15 06:02:16 volumio volumio[14853]: error: Cannot start Volumio Streaming Daemon Apr 15 06:02:16 volumio volumio[14853]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 15 06:02:16 volumio volumio[14853]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 15 06:02: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 15 06:02: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 15 06:02: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 15 06:02: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 15 06:02: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 15 06:02: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 15 06:02:16 volumio sudo[15175]: pam_unix(sudo:session): session closed for user root Apr 15 06:02:16 volumio volumio[14853]: info: Remote SSH Stopped Apr 15 06:02:16 volumio volumio[14853]: info: Setting Geolocation for MyVolumio to eu3 Apr 15 06:02:16 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:02:16 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:02:16 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:02:16 volumio go-librespot[15136]: time="2026-04-15T06:02:16+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 06:02:16 volumio go-librespot[15136]: time="2026-04-15T06:02:16+01:00" level=debug msg="completed keyexchange" Apr 15 06:02:16 volumio go-librespot[15136]: time="2026-04-15T06:02:16+01:00" level=debug msg="completed challenge" Apr 15 06:02:16 volumio go-librespot[15136]: time="2026-04-15T06:02:16+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:02:17 volumio volumio[14853]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Apr 15 06:02:17 volumio go-librespot[15136]: time="2026-04-15T06:02:17+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 15 06:02:17 volumio go-librespot[15136]: time="2026-04-15T06:02:17+01:00" level=debug msg="completed keyexchange" Apr 15 06:02:17 volumio go-librespot[15136]: time="2026-04-15T06:02:17+01:00" level=debug msg="completed challenge" Apr 15 06:02:17 volumio go-librespot[15136]: time="2026-04-15T06:02:17+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:02:17 volumio volumio[14853]: info: Updating MyVolumio device info Apr 15 06:02:17 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:02:17 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:02:17 volumio volumio[14853]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 06:02:18 volumio volumio[14853]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Apr 15 06:02:18 volumio go-librespot[15136]: time="2026-04-15T06:02:18+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 15 06:02:18 volumio go-librespot[15136]: time="2026-04-15T06:02:18+01:00" level=debug msg="completed keyexchange" Apr 15 06:02:18 volumio go-librespot[15136]: time="2026-04-15T06:02:18+01:00" level=debug msg="completed challenge" Apr 15 06:02:18 volumio go-librespot[15136]: time="2026-04-15T06:02:18+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:02:18 volumio volumio[14853]: info: Getting Spotify volume Apr 15 06:02:18 volumio volumio[14853]: 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 15 06:02:18 volumio volumio[14853]: info: CoreCommandRouter::volumioGetState Apr 15 06:02:18 volumio volumio[14853]: info: CorePlayQueue::getTrack 0 Apr 15 06:02:18 volumio volumio[14853]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Apr 15 06:02:18 volumio volumio[14853]: SPOTIFY: SPOTIFY VOLUME undefined Apr 15 06:02:18 volumio volumio[14853]: SPOTIFY: VOLUMIO VOLUME 0 Apr 15 06:02:18 volumio volumio[14853]: info: Aligning Spotify Volume to Volumio Volume Apr 15 06:02:18 volumio volumio[14853]: info: CoreCommandRouter::volumioGetState Apr 15 06:02:18 volumio volumio[14853]: info: CorePlayQueue::getTrack 0 Apr 15 06:02:18 volumio volumio[14853]: info: Setting Spotify Volume from Volumio: 0 Apr 15 06:02:18 volumio go-librespot[15136]: time="2026-04-15T06:02:18+01:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Apr 15 06:02:18 volumio go-librespot[15136]: time="2026-04-15T06:02:18+01:00" level=debug msg="completed keyexchange" Apr 15 06:02:18 volumio go-librespot[15136]: time="2026-04-15T06:02:18+01:00" level=debug msg="completed challenge" Apr 15 06:02:18 volumio go-librespot[15136]: time="2026-04-15T06:02:18+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 15 06:02:18 volumio go-librespot[15136]: time="2026-04-15T06:02:18+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 15 06:02:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 06:02:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 06:02:18 volumio volumio[14853]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 15 06:02:18 volumio volumio[14853]: Error: socket hang up Apr 15 06:02:18 volumio volumio[14853]: at connResetException (node:internal/errors:720:14) Apr 15 06:02:18 volumio volumio[14853]: at Socket.socketOnEnd (node:_http_client:519:23) Apr 15 06:02:18 volumio volumio[14853]: at Socket.emit (node:events:526:35) Apr 15 06:02:18 volumio volumio[14853]: at endReadableNT (node:internal/streams/readable:1376:12) Apr 15 06:02:18 volumio volumio[14853]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Apr 15 06:02:18 volumio volumio[14853]: code: 'ECONNRESET', Apr 15 06:02:18 volumio volumio[14853]: response: undefined Apr 15 06:02:18 volumio volumio[14853]: } Apr 15 06:02:18 volumio volumio[14853]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 15 06:02:19 volumio sudo[15192]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-15 06:01' Apr 15 06:02:19 volumio sudo[15192]: 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"