Mar 04 07:16:00 loe volumio[23061]: info: Remote config written successfully Mar 04 07:16:00 loe volumio[23061]: info: Starting Tunnel 1 Mar 04 07:16:00 loe volumio[23061]: info: Starting Tunnel Connection Checker Mar 04 07:16:00 loe volumio[23061]: info: Completed starting MyVolumio Plugin Mar 04 07:16:00 loe volumio[23061]: info: MYVolumio Device enabled Mar 04 07:16:00 loe volumio[23061]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Mar 04 07:16:00 loe volumio[23061]: info: MyVolumio status changed Mar 04 07:16:00 loe volumio[23061]: info: Streaming services startup Mar 04 07:16:00 loe volumio[23061]: info: Starting Streaming Daemon Mar 04 07:16:00 loe volumio[23061]: info: Setting Geolocation for MyVolumio to eu8 Mar 04 07:16:00 loe sudo[23479]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 04 07:16:00 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:16:00 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:16:00 loe sudo[23479]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:16:00 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:16:00 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Mar 04 07:16:00 loe sudo[23479]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:00 loe volumio[23061]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Mar 04 07:16:01 loe volumio[23061]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Mar 04 07:16:01 loe volumio[23061]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Mar 04 07:16:01 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:16:01 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:16:01 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:16:02 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Mar 04 07:16:02 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:16:02 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:16:02 loe go-librespot[23481]: go-librespot daemon starting... Mar 04 07:16:02 loe go-librespot[23482]: time="2026-03-04T07:16:02+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 07:16:02 loe go-librespot[23482]: time="2026-03-04T07:16:02+01:00" level=debug msg="app state loaded" Mar 04 07:16:02 loe go-librespot[23482]: time="2026-03-04T07:16:02+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 07:16:03 loe go-librespot[23482]: time="2026-03-04T07:16:03+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 07:16:03 loe go-librespot[23482]: time="2026-03-04T07:16:03+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 04 07:16:03 loe go-librespot[23482]: time="2026-03-04T07:16:03+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 04 07:16:03 loe go-librespot[23482]: time="2026-03-04T07:16:03+01:00" level=info msg="zeroconf server listening on port 40933" Mar 04 07:16:03 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:16:03 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:16:03 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:16:03 loe go-librespot[23482]: time="2026-03-04T07:16:03+01:00" level=debug msg="obtained new client token: AADCVLIFAp2WoWCk5acuPVu+mfuMhg09Pgok2tLJW1AZO71DCqiK4fOBFquFZl6iVHPqQxTES1VHiIw3TH7ocG7JpE7Tc3ETy4JRzjZRmhV/9mRMs+ZykvQgkzGKlOgOhs9q4+qn2GwDhvzOYBQ0qhyFZEm0PCof4s7tmbbmtvZTjf1+qMUWOUxh3fE5kz0bxAlLZbBD2ta73CCD/+Xvl5tvJZgAmCw1c6MS9mqHvYFY3AfPZiVl5h0=" Mar 04 07:16:03 loe volumio[23061]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Mar 04 07:16:03 loe sudo[23491]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Mar 04 07:16:03 loe sudo[23491]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:16:03 loe go-librespot[23482]: time="2026-03-04T07:16:03+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 07:16:03 loe sudo[23491]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:03 loe go-librespot[23482]: time="2026-03-04T07:16:03+01:00" level=debug msg="completed keyexchange" Mar 04 07:16:03 loe go-librespot[23482]: time="2026-03-04T07:16:03+01:00" level=debug msg="completed challenge" Mar 04 07:16:03 loe volumio[23061]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Mar 04 07:16:03 loe go-librespot[23482]: time="2026-03-04T07:16:03+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 07:16:03 loe volumio[23061]: info: MRS: MultiRoom plugin initialized Mar 04 07:16:03 loe volumio[23061]: info: MRS: STOPPING SNAPCLIENT Mar 04 07:16:03 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 07:16:03 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 07:16:03 loe volumio[23061]: info: MRS: Snap server stop Mar 04 07:16:03 loe volumio[23061]: info: MRS: STOPPING volumioStreaming Mar 04 07:16:03 loe sudo[23508]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Mar 04 07:16:03 loe sudo[23508]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:16:03 loe sudo[23510]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Mar 04 07:16:03 loe sudo[23510]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:16:03 loe volumio[23061]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Mar 04 07:16:03 loe sudo[23512]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Mar 04 07:16:03 loe sudo[23512]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:16:03 loe sudo[23515]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Mar 04 07:16:03 loe sudo[23515]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:16:03 loe volumio[23061]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Mar 04 07:16:03 loe sudo[23515]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:03 loe volumio[23061]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Mar 04 07:16:03 loe volumio[23061]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Mar 04 07:16:03 loe volumio[23061]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Mar 04 07:16:03 loe volumio[23061]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Mar 04 07:16:03 loe volumio[23061]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Mar 04 07:16:03 loe volumio[23061]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Mar 04 07:16:03 loe volumio[23061]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Mar 04 07:16:03 loe sudo[23508]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:03 loe volumio[23061]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Mar 04 07:16:03 loe sudo[23510]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:03 loe sudo[23512]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:03 loe volumio[23061]: info: Preparing to generate the ALSA configuration file Mar 04 07:16:03 loe volumio[23061]: info: Initializing connection to go-librespot Websocket Mar 04 07:16:03 loe volumio[23061]: info: Updating MyVolumio device info Mar 04 07:16:03 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:16:03 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:16:03 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:16:04 loe volumio[23061]: info: Setting Geolocation for MyVolumio to eu12 Mar 04 07:16:04 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:16:04 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:16:04 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:16:04 loe volumio[23061]: info: Successfully Added MyVolumio device Mar 04 07:16:04 loe volumio[23061]: info: MRS: Removed streaming files Mar 04 07:16:04 loe volumio[23061]: info: MRS: volumioStreaming STOPPED Mar 04 07:16:04 loe volumio[23061]: info: MRS: SNAPSERVER STOPPED Mar 04 07:16:04 loe volumio[23061]: info: MRS: SNAPCLIENT STOPPED Mar 04 07:16:04 loe volumio[23061]: error: Cannot start Volumio Streaming Daemon Mar 04 07:16:04 loe volumio[23061]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 04 07:16:04 loe volumio[23061]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 04 07:16:04 loe volumio[23061]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 07:16:04 loe volumio[23061]: info: Asound.conf file unchanged, so no further update is needed Mar 04 07:16:04 loe volumio[23061]: info: Output device has changed, restarting MPD Mar 04 07:16:04 loe systemd[1]: qobuz-connect.service: Scheduled restart job, restart counter is at 6. Mar 04 07:16:04 loe systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Mar 04 07:16:04 loe volumio[23061]: info: Output device has changed, restarting Shairport Sync Mar 04 07:16:04 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:04 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:16:04 loe sudo[23521]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 07:16:04 loe sudo[23521]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:16:04 loe systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Mar 04 07:16:04 loe sudo[23521]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:04 loe sudo[23524]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 07:16:04 loe sudo[23524]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:16:04 loe volumio[23061]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 07:16:04 loe volumio[23061]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Mar 04 07:16:04 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:04 loe volumio[23061]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Mar 04 07:16:04 loe volumio[23061]: ------------------------------------ BT MESSAGE: [FUNC] onStart Mar 04 07:16:04 loe volumio[23061]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Mar 04 07:16:04 loe systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 04 07:16:04 loe volumio[23061]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Mar 04 07:16:04 loe volumio[23061]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Mar 04 07:16:04 loe volumio[23061]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Mar 04 07:16:04 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Mar 04 07:16:04 loe volumio[23061]: info: MRS: Pushing multiroomSync output for this device Mar 04 07:16:04 loe volumio[23061]: info: MRS: Pushing multiroomSync output Mar 04 07:16:04 loe volumio[23061]: info: Adding audio output: Mar 04 07:16:04 loe volumio[23061]: info: Adding audio output: Mar 04 07:16:04 loe systemd[1]: mpd.service: Deactivated successfully. Mar 04 07:16:04 loe systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 04 07:16:04 loe systemd[1]: mpd.service: Consumed 6.543s CPU time. Mar 04 07:16:04 loe systemd[1]: mpd.socket: Deactivated successfully. Mar 04 07:16:04 loe systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 04 07:16:04 loe systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 04 07:16:04 loe bluetoothd[980]: Path / reserved for Adv Monitor app :1.4809 Mar 04 07:16:04 loe systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 04 07:16:04 loe systemd[1]: Starting mpd.service - Music Player Daemon... Mar 04 07:16:04 loe bluetoothd[980]: Adv Monitor app :1.4809 disconnected from D-Bus Mar 04 07:16:04 loe volumio[23061]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Mar 04 07:16:04 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:04 loe volumio[23061]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Mar 04 07:16:04 loe volumio[23061]: info: Adding METAVOLUMIO REST API Endpoints Mar 04 07:16:04 loe volumio[23061]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Mar 04 07:16:04 loe volumio[23061]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Mar 04 07:16:04 loe volumio[23061]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Mar 04 07:16:04 loe volumio[23061]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Mar 04 07:16:04 loe volumio[23061]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Mar 04 07:16:04 loe volumio[23061]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Mar 04 07:16:04 loe volumio[23061]: info: Preparing CD Folders Mar 04 07:16:04 loe volumio[23061]: info: Adding CD REST API Endpoints Mar 04 07:16:04 loe volumio[23061]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Mar 04 07:16:04 loe volumio[23061]: info: Starting UDEV Watcher for CD Mar 04 07:16:04 loe volumio[23061]: info: Detecting CD presence with UDEV Mar 04 07:16:04 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Mar 04 07:16:05 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:16:05 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:16:05 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:16:05 loe sudo[23538]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 04 07:16:05 loe sudo[23538]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 04 07:16:05 loe sudo[23538]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:06 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Mar 04 07:16:06 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:16:06 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:16:06 loe go-librespot[23546]: go-librespot daemon starting... Mar 04 07:16:06 loe go-librespot[23547]: time="2026-03-04T07:16:06+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 07:16:06 loe go-librespot[23547]: time="2026-03-04T07:16:06+01:00" level=debug msg="app state loaded" Mar 04 07:16:06 loe go-librespot[23547]: time="2026-03-04T07:16:06+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 07:16:07 loe go-librespot[23547]: time="2026-03-04T07:16:07+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 07:16:07 loe go-librespot[23547]: time="2026-03-04T07:16:07+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 07:16:07 loe go-librespot[23547]: time="2026-03-04T07:16:07+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 07:16:07 loe go-librespot[23547]: time="2026-03-04T07:16:07+01:00" level=info msg="zeroconf server listening on port 44911" Mar 04 07:16:07 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:16:07 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:16:07 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:16:07 loe go-librespot[23547]: time="2026-03-04T07:16:07+01:00" level=debug msg="obtained new client token: AAA238UJcDLFPdCY/YkfQ6U9hoFKnZfNmwiABuJv6NZQub61aNigXATEzvcxO9ECb0UdND2+LE6sGgIrRiPJzDP5cqLS3lblxJGM3c+69rSRXlHEVAFmHu0RukZReOA3SPEZd4JSqBT8UYS4+6ogy83ZxfYRKRKhofSSLWXYxwB2OJkrgzksAybNwx4b5WzUtIGT4Y/u6/LhS2/D5sAWgVDGHOANXKBJ/uMJfzaigfcG3GCqFM3O4HE=" Mar 04 07:16:07 loe go-librespot[23547]: time="2026-03-04T07:16:07+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 07:16:07 loe go-librespot[23547]: time="2026-03-04T07:16:07+01:00" level=debug msg="completed keyexchange" Mar 04 07:16:07 loe go-librespot[23547]: time="2026-03-04T07:16:07+01:00" level=debug msg="completed challenge" Mar 04 07:16:07 loe go-librespot[23547]: time="2026-03-04T07:16:07+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 " Mar 04 07:16:07 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 07:16:07 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 07:16:09 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:16:09 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:16:09 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:16:09 loe mpd[23545]: 2026-03-04T07:16:09 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 04 07:16:09 loe systemd[1]: Started mpd.service - Music Player Daemon. Mar 04 07:16:09 loe sudo[23524]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:09 loe volumio[23061]: warn: [cd-plugin] cdspeedctl: device or media not ready Mar 04 07:16:09 loe volumio[23061]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Mar 04 07:16:09 loe volumio[23061]: info: Adding inputs REST Endpoints Mar 04 07:16:09 loe volumio[23061]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Mar 04 07:16:09 loe volumio[23061]: info: Scanning Audio Inputs Mar 04 07:16:10 loe volumio[23061]: info: Checking against Known Cards name Mar 04 07:16:10 loe volumio[23061]: info: Adding Server instance for streaming Mar 04 07:16:10 loe volumio[23061]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Mar 04 07:16:10 loe volumio[23061]: info: Adding HIGHRESAUDIO REST API Endpoints Mar 04 07:16:10 loe volumio[23061]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Mar 04 07:16:10 loe volumio[23061]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Mar 04 07:16:10 loe volumio[23061]: info: Refreshing TIDAL token Mar 04 07:16:10 loe volumio[23061]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Mar 04 07:16:10 loe volumio[23061]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Mar 04 07:16:10 loe volumio[23061]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Mar 04 07:16:10 loe volumio[23061]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Mar 04 07:16:10 loe volumio[23061]: info: QobuzConnect: Starting Qobuz Connect socket and service Mar 04 07:16:10 loe sudo[23560]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Mar 04 07:16:10 loe sudo[23560]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:16:10 loe volumio[23061]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Mar 04 07:16:10 loe volumio[23061]: info: Stopping AccessToken refresher cron for QOBUZ Mar 04 07:16:10 loe sudo[23567]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Mar 04 07:16:10 loe sudo[23567]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:16:10 loe sudo[23560]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:10 loe volumio[23061]: info: AccessToken refresher cron started for QOBUZ Mar 04 07:16:10 loe volumio[23061]: info: Adding QOBUZ REST API Endpoints Mar 04 07:16:10 loe sudo[23567]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:10 loe sudo[23570]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Mar 04 07:16:10 loe sudo[23570]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:16:10 loe volumio[23061]: info: MRS: Getting audio outputs on start Mar 04 07:16:10 loe volumio[23061]: info: MRS: Requesting all other devices output Mar 04 07:16:10 loe volumio[23061]: info: Updating MyVolumio device info Mar 04 07:16:10 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:16:10 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:16:10 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:16:10 loe volumio[23061]: info: Initializing connection to go-librespot Websocket Mar 04 07:16:10 loe systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Mar 04 07:16:10 loe systemd[1]: qobuz-connect.service: Deactivated successfully. Mar 04 07:16:10 loe systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Mar 04 07:16:10 loe systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Mar 04 07:16:10 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Mar 04 07:16:10 loe sudo[23570]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:10 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:16:10 loe volumio[23061]: info: Successfully Updated MyVolumio device Mar 04 07:16:10 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:16:10 loe go-librespot[23588]: go-librespot daemon starting... Mar 04 07:16:10 loe volumio[23061]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Mar 04 07:16:10 loe go-librespot[23589]: time="2026-03-04T07:16:10+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 07:16:10 loe go-librespot[23589]: time="2026-03-04T07:16:10+01:00" level=debug msg="app state loaded" Mar 04 07:16:10 loe go-librespot[23589]: time="2026-03-04T07:16:10+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 07:16:10 loe volumio[23061]: info: MPD Permissions set Mar 04 07:16:10 loe sudo[23596]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Mar 04 07:16:10 loe sudo[23596]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:16:10 loe volumio[23061]: ------------------------------------ BT MESSAGE: [_watchMediaPlayer] Binding activePlayer for path: /org/bluez/hci0/dev_C0_D5_E2_9C_B7_BA/avrcp/player0 Mar 04 07:16:10 loe volumio[23061]: ------------------------------------ BT MESSAGE: activePlayer bound: /org/bluez/hci0/dev_C0_D5_E2_9C_B7_BA/avrcp/player0 Mar 04 07:16:10 loe sudo[23596]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:10 loe volumio[23061]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 07:16:10 loe volumio[23061]: info: Executing endpoint qc_getconfig Mar 04 07:16:10 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Mar 04 07:16:10 loe volumio[23061]: info: Successfully Added MyVolumio device Mar 04 07:16:10 loe volumio[23061]: info: Executing endpoint qc_getconfig Mar 04 07:16:10 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Mar 04 07:16:10 loe qobuz-connect[23572]: 20260304 07:16:10.968 [23572.23572] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Mar 04 07:16:10 loe volumio[23061]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Mar 04 07:16:10 loe volumio[23061]: info: CoreCommandRouter::volumioStop Mar 04 07:16:10 loe volumio[23061]: info: CoreStateMachine::stop Mar 04 07:16:10 loe volumio[23061]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 04 07:16:10 loe volumio[23061]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Mar 04 07:16:10 loe volumio[23061]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 04 07:16:10 loe qobuz-connect[23572]: 20260304 07:16:10.980 [23572.23572] INFO VolumeManager: [0x94c408]: Setting new playback volume: 75 Mar 04 07:16:10 loe qobuz-connect[23572]: 20260304 07:16:10.981 [23572.23572] INFO VolumeManager: [0x94c408]: Setting new mute state: 0 Mar 04 07:16:10 loe qobuz-connect[23572]: 20260304 07:16:10.981 [23572.23572] INFO QobuzConnect: [0x94cdd8]: Client initialized! Mar 04 07:16:10 loe qobuz-connect[23572]: 20260304 07:16:10.981 [23572.23572] INFO SampleApp: Starting Avahi advertising, name: Loe, service name: _qobuz-connect._tcp Mar 04 07:16:11 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 07:16:11 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:16:11 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 04 07:16:11 loe qobuz-connect[23572]: 20260304 07:16:11.028 [23572.23572] INFO LocalConfigManager: [0x94bce8]: Starting Local Configuration server Mar 04 07:16:11 loe qobuz-connect[23572]: 20260304 07:16:11.029 [23572.23572] INFO SampleApp: Starting Local configuration server Mar 04 07:16:11 loe qobuz-connect[23572]: 20260304 07:16:11.030 [23572.23572] INFO SampleApp: Connected to UNIX socket client 0x936818 Mar 04 07:16:11 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:11 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:11 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:11 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:11 loe go-librespot[23589]: time="2026-03-04T07:16:11+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 07:16:11 loe go-librespot[23589]: time="2026-03-04T07:16:11+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 07:16:11 loe go-librespot[23589]: time="2026-03-04T07:16:11+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 07:16:11 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:11 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:11 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:11 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:11 loe go-librespot[23589]: time="2026-03-04T07:16:11+01:00" level=info msg="zeroconf server listening on port 42535" Mar 04 07:16:11 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:16:11 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:11 loe qobuz-connect[23572]: 20260304 07:16:11.118 [23572.23572] INFO SampleApp: Playback volume changed: 75 Mar 04 07:16:11 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:16:11 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:16:11 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:16:11 loe volumio[23061]: error: Hi Res Audio Failed Login: [object Object] Mar 04 07:16:11 loe volumio[23061]: error: updateQueue error: null Mar 04 07:16:11 loe go-librespot[23589]: time="2026-03-04T07:16:11+01:00" level=debug msg="obtained new client token: AABS45yaaAgPVprgOrjYwCpc5gryraGJ8LkLk/6MR0vtxwGKerPBZc0OVZ2lShf3MeeSuuyXuKAw5JD1IW4F3aPJwsn9UNqfkFIHbobV8wdMCVB+cCOAzLxo5yQxDn4gezaUq3AI+wkyi6teazM7qse/dPMbT/Vmp+/Cnkul/DMHdoSxtFw6nxdNvoNFSWN8y/i/fkIGj8PIRV/21XWCIbluWWODiM9IFbMNImRUU3hQXuBP+lNgiI0=" Mar 04 07:16:11 loe go-librespot[23589]: time="2026-03-04T07:16:11+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 07:16:11 loe go-librespot[23589]: time="2026-03-04T07:16:11+01:00" level=debug msg="completed keyexchange" Mar 04 07:16:11 loe go-librespot[23589]: time="2026-03-04T07:16:11+01:00" level=debug msg="completed challenge" Mar 04 07:16:11 loe go-librespot[23589]: time="2026-03-04T07:16: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 " Mar 04 07:16:11 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 07:16:11 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 07:16:11 loe volumio[23061]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Mar 04 07:16:11 loe volumio[23061]: info: QobuzConnect: QOBUZ Connect daemon connected Mar 04 07:16:11 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 04 07:16:11 loe volumio[23061]: info: Successfully Updated MyVolumio device Mar 04 07:16:11 loe volumio[23061]: info: CoreCommandRouter::volumioGetState Mar 04 07:16:11 loe volumio[23061]: info: Starting Shairport Sync Mar 04 07:16:11 loe sudo[23623]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Mar 04 07:16:11 loe sudo[23623]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:16:11 loe volumio[23061]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Mar 04 07:16:11 loe sudo[23625]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 07:16:11 loe sudo[23625]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:16:11 loe volumio-remote-updater[714]: Test mode disabled Mar 04 07:16:11 loe volumio-remote-updater[714]: Alpha mode disabled Mar 04 07:16:11 loe volumio-remote-updater[714]: Alpha legacy test mode disabled Mar 04 07:16:11 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Mar 04 07:16:11 loe volumio[23061]: info: MRS: Found cast device: Chromecast-84d0dcfc86c31e08fb7722859cd1fe00 Mar 04 07:16:11 loe volumio[23061]: info: Adding audio output: Mar 04 07:16:11 loe systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 04 07:16:11 loe autossh[22397]: received signal to exit (15) Mar 04 07:16:11 loe systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel... Mar 04 07:16:11 loe systemd[1]: shairport-sync.service: Deactivated successfully. Mar 04 07:16:11 loe systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 07:16:11 loe volumio[23061]: info: Access Token successfully retrieved Mar 04 07:16:11 loe systemd[1]: shairport-sync.service: Consumed 2.026s CPU time. Mar 04 07:16:11 loe systemd[1]: sshtunnel.service: Deactivated successfully. Mar 04 07:16:11 loe systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Mar 04 07:16:11 loe volumio[23061]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 04 07:16:11 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 04 07:16:11 loe systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 07:16:11 loe sudo[23625]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:11 loe systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Mar 04 07:16:11 loe sudo[23623]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:11 loe autossh[23631]: port set to 0, monitoring disabled Mar 04 07:16:11 loe autossh[23631]: starting ssh (count 1) Mar 04 07:16:11 loe autossh[23631]: ssh child pid is 23634 Mar 04 07:16:12 loe volumio[23061]: info: Remote SSH Started Mar 04 07:16:12 loe volumiossh-tunnel[23634]: Warning: Permanently added '[eu12.myvolumio.org]:2222' (ED25519) to the list of known hosts. Mar 04 07:16:12 loe volumio[23061]: info: Shairport-Sync Started Mar 04 07:16:12 loe volumio[23061]: info: CoreCommandRouter::volumioGetState Mar 04 07:16:12 loe volumio[23061]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Mar 04 07:16:12 loe volumio[23061]: info: Successfully retrieved User Session From TIDAL Mar 04 07:16:12 loe volumio[23061]: info: CoreCommandRouter::volumioGetState Mar 04 07:16:12 loe volumio[23061]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.mjORZRjMx8YIlyGajvB2CXSYA5r2.a53384b16fd4d7a180fdac1b5068092c.state.status' Mar 04 07:16:12 loe volumio[23061]: info: Successfully retrieved User Subscription From TIDAL Mar 04 07:16:12 loe volumio[23061]: info: Adding TIDAL to Browse Sources Mar 04 07:16:12 loe volumio[23061]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 07:16:12 loe volumio[23061]: info: [1772604972811] CoreMusicLibrary::Adding element TIDAL Mar 04 07:16:12 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 07:16:12 loe volumio[23061]: Cannot find translation for source TIDAL Mar 04 07:16:12 loe volumio[23061]: info: Adding TIDAL REST API Endpoints Mar 04 07:16:13 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:16:13 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:16:13 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:16:13 loe volumio[23061]: info: TidalConnect service stoped! Mar 04 07:16:13 loe volumio[23061]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Mar 04 07:16:13 loe volumio[23061]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Mar 04 07:16:13 loe sudo[23658]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Mar 04 07:16:13 loe sudo[23658]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:16:13 loe systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Mar 04 07:16:13 loe sudo[23658]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:13 loe volumio[23061]: info: Initializing connection to go-librespot Websocket Mar 04 07:16:13 loe volumio[23061]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 07:16:13 loe volumio[23061]: info: Executing endpoint tc_getconfig Mar 04 07:16:13 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Mar 04 07:16:13 loe vtcs[23661]: STARTING TidalConnect services, version: 1.6.1 Mar 04 07:16:13 loe vtcs[23661]: STARTED TidalConnect services. Mar 04 07:16:13 loe volumio[23061]: info: Executing endpoint tc_connect Mar 04 07:16:13 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Mar 04 07:16:13 loe volumio[23061]: info: Connecting to TidalConnect Mar 04 07:16:13 loe volumio[23061]: info: CoreCommandRouter::servicePushState Mar 04 07:16:13 loe volumio[23061]: info: CoreStateMachine::pushState Mar 04 07:16:13 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 07:16:13 loe volumio[23061]: info: CoreCommandRouter::volumioPushState Mar 04 07:16:14 loe volumio[23061]: info: MRS: Pushing multiroomSync output update for this device Mar 04 07:16:14 loe volumio[23061]: info: MRS: Pushing multiroomSync output Mar 04 07:16:14 loe volumio[23061]: info: CoreCommandRouter::volumioGetState Mar 04 07:16:14 loe volumio[23061]: info: CorePlayQueue::getTrack 0 Mar 04 07:16:14 loe volumio[23061]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect Mar 04 07:16:14 loe volumio[23061]: info: CoreCommandRouter::servicePushState Mar 04 07:16:14 loe volumio[23061]: info: CoreStateMachine::pushState Mar 04 07:16:14 loe volumio[23061]: info: CoreCommandRouter::volumioPushState Mar 04 07:16:14 loe volumio[23061]: info: MRS: Pushing multiroomSync output update for this device Mar 04 07:16:14 loe volumio[23061]: info: MRS: Pushing multiroomSync output Mar 04 07:16:14 loe volumio[23061]: info: CoreCommandRouter::volumioGetState Mar 04 07:16:14 loe volumio[23061]: info: CorePlayQueue::getTrack 0 Mar 04 07:16:14 loe volumio[23061]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect Mar 04 07:16:14 loe volumio[23061]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.mjORZRjMx8YIlyGajvB2CXSYA5r2.a53384b16fd4d7a180fdac1b5068092c.state.status' Mar 04 07:16:14 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Mar 04 07:16:14 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:16:14 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:16:14 loe go-librespot[23677]: go-librespot daemon starting... Mar 04 07:16:14 loe go-librespot[23678]: time="2026-03-04T07:16:14+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 07:16:14 loe go-librespot[23678]: time="2026-03-04T07:16:14+01:00" level=debug msg="app state loaded" Mar 04 07:16:14 loe go-librespot[23678]: time="2026-03-04T07:16:14+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 07:16:15 loe go-librespot[23678]: time="2026-03-04T07:16:15+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 07:16:15 loe go-librespot[23678]: time="2026-03-04T07:16:15+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 07:16:15 loe go-librespot[23678]: time="2026-03-04T07:16:15+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 07:16:15 loe go-librespot[23678]: time="2026-03-04T07:16:15+01:00" level=info msg="zeroconf server listening on port 44257" Mar 04 07:16:15 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:16:15 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:16:15 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:16:15 loe go-librespot[23678]: time="2026-03-04T07:16:15+01:00" level=debug msg="obtained new client token: AADqe/wDFkE6FWw05xWCl/E31Vlm/Q7R7iq390XmcYloG9VAp4gXvPy7lAfUnE/8gPvLmqAUpQfmt6KmuKgwzx7aNp/a7ZQnLUMRLZ1Jqhwo5ggReop0EAbXvWeP4ff+bbh8AnI7+1NtUJZFt9MGKtCCCsvTm1Wch1Gsbh46LCrC6UVwq9pQD0ugPNw4PrCSNf9eHDlr0FX3m//zQ6h5o3pGkAHbGuNsdTmcnmy9g4gwbydwbC+D/V4=" Mar 04 07:16:15 loe go-librespot[23678]: time="2026-03-04T07:16:15+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Mar 04 07:16:15 loe go-librespot[23678]: time="2026-03-04T07:16:15+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 04 07:16:15 loe go-librespot[23678]: time="2026-03-04T07:16:15+01:00" level=debug msg="completed keyexchange" Mar 04 07:16:15 loe go-librespot[23678]: time="2026-03-04T07:16:15+01:00" level=debug msg="completed challenge" Mar 04 07:16:15 loe go-librespot[23678]: time="2026-03-04T07:16:15+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 " Mar 04 07:16:15 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 07:16:15 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 07:16:16 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:16 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:16 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Mar 04 07:16:16 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Mar 04 07:16:16 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Mar 04 07:16:16 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Mar 04 07:16:16 loe volumio[23061]: info: CoreCommandRouter::volumioGetBrowseSources Mar 04 07:16:16 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 07:16:16 loe volumio[23061]: info: TidalConnect service started! Mar 04 07:16:16 loe volumio[23061]: [Metrics] CommandRouter: 50s 114.16ms Mar 04 07:16:16 loe volumio[23061]: info: CoreCommandRouter::volumiosetStartupVolume Mar 04 07:16:16 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:16 loe volumio[23061]: info: VolumeController:: Setting startup Volume 5 Mar 04 07:16:16 loe volumio[23061]: info: VolumeController::SetAlsaVolume5 Mar 04 07:16:16 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:16:16 loe volumio[23061]: info: CoreCommandRouter::Close All Modals sent Mar 04 07:16:16 loe volumio[23061]: info: CoreCommandRouter::Close All Modals sent Mar 04 07:16:16 loe volumio[23061]: info: CoreStateMachine::pushState Mar 04 07:16:16 loe volumio[23061]: info: CoreCommandRouter::volumioPushState Mar 04 07:16:16 loe volumio[23061]: info: MRS: Pushing multiroomSync output update for this device Mar 04 07:16:16 loe volumio[23061]: info: MRS: Pushing multiroomSync output Mar 04 07:16:16 loe volumio[23061]: info: CoreCommandRouter::volumioGetState Mar 04 07:16:16 loe volumio[23061]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.mjORZRjMx8YIlyGajvB2CXSYA5r2.a53384b16fd4d7a180fdac1b5068092c.state.status' Mar 04 07:16:16 loe volumio[23061]: info: Initializing connection to go-librespot Websocket Mar 04 07:16:16 loe volumio[23061]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 07:16:17 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:16:17 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:16:17 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:16:17 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Mar 04 07:16:17 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 04 07:16:17 loe volumio[23061]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Mar 04 07:16:18 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Mar 04 07:16:18 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:16:18 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:16:18 loe go-librespot[23688]: go-librespot daemon starting... Mar 04 07:16:18 loe go-librespot[23689]: time="2026-03-04T07:16:18+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 07:16:18 loe go-librespot[23689]: time="2026-03-04T07:16:18+01:00" level=debug msg="app state loaded" Mar 04 07:16:18 loe go-librespot[23689]: time="2026-03-04T07:16:18+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 07:16:19 loe go-librespot[23689]: time="2026-03-04T07:16:19+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 07:16:19 loe go-librespot[23689]: time="2026-03-04T07:16:19+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 07:16:19 loe go-librespot[23689]: time="2026-03-04T07:16:19+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 07:16:19 loe go-librespot[23689]: time="2026-03-04T07:16:19+01:00" level=info msg="zeroconf server listening on port 38525" Mar 04 07:16:19 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:16:19 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:16:19 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:16:19 loe go-librespot[23689]: time="2026-03-04T07:16:19+01:00" level=debug msg="obtained new client token: AAAncBXv/l4+pZn/FbGIMtrtPZySx293m0Xc+RrHAbSqnZ7wT7GTcbVqDB/5zMdVLsH6zif18/iDpJPR3LzA1EtaQJb3W2jD8Sab2IrutJu7YTIZmHq1QvpWpH0HV2ZO3yRNzgxN1bSs5oHmxCnGlN9R6oeuyTCy90UaL0lHBXLwRVPbjYFScrRwuMzi94MF60LgxD5mHKxS0FpTgBjXwwP2Wj6QM2Woaa48BklC1EFAIxfKB85/p+Y=" Mar 04 07:16:19 loe go-librespot[23689]: time="2026-03-04T07:16:19+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 07:16:19 loe go-librespot[23689]: time="2026-03-04T07:16:19+01:00" level=debug msg="completed keyexchange" Mar 04 07:16:19 loe go-librespot[23689]: time="2026-03-04T07:16:19+01:00" level=debug msg="completed challenge" Mar 04 07:16:19 loe go-librespot[23689]: time="2026-03-04T07:16:19+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 " Mar 04 07:16:19 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 07:16:19 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 07:16:19 loe volumio[23061]: info: Initializing connection to go-librespot Websocket Mar 04 07:16:19 loe volumio[23061]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 07:16:21 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:16:21 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:16:21 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:16:22 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Mar 04 07:16:22 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:16:22 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:16:22 loe go-librespot[23710]: go-librespot daemon starting... Mar 04 07:16:22 loe go-librespot[23711]: time="2026-03-04T07:16:22+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 07:16:22 loe go-librespot[23711]: time="2026-03-04T07:16:22+01:00" level=debug msg="app state loaded" Mar 04 07:16:22 loe go-librespot[23711]: time="2026-03-04T07:16:22+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 07:16:22 loe volumio[23061]: info: Initializing connection to go-librespot Websocket Mar 04 07:16:22 loe go-librespot[23711]: time="2026-03-04T07:16:22+01:00" level=debug msg="new websocket client" Mar 04 07:16:22 loe volumio[23061]: info: Connection to go-librespot Websocket established Mar 04 07:16:23 loe go-librespot[23711]: time="2026-03-04T07:16:23+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 07:16:23 loe go-librespot[23711]: time="2026-03-04T07:16:23+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 07:16:23 loe go-librespot[23711]: time="2026-03-04T07:16:23+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 07:16:23 loe go-librespot[23711]: time="2026-03-04T07:16:23+01:00" level=info msg="zeroconf server listening on port 37805" Mar 04 07:16:23 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:16:23 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:16:23 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:16:23 loe go-librespot[23711]: time="2026-03-04T07:16:23+01:00" level=debug msg="obtained new client token: AADz59OezMeCPt7JQ58MtarsR6WCnhXtNlIa8ZF9BrZVakFZZ8oz5FWdy1RvkcEL1HrNljNN0qCeoeYR0ITbFR9blfaY5TbopNmxpEbqwDeUki0cMfCdMtNBsVL4HibCSDUokxN9KGg2NSa84nfwxCNxKyfVOdWa3u9c1R1D1RT1f4frsR3zybyQ4QHQwMCgtFotOQhYzMJVUD93tVi1DogEfqDbitFK/+/oRUDmSR0C568wUE+IrTM=" Mar 04 07:16:23 loe go-librespot[23711]: time="2026-03-04T07:16:23+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 07:16:23 loe go-librespot[23711]: time="2026-03-04T07:16:23+01:00" level=debug msg="completed keyexchange" Mar 04 07:16:23 loe go-librespot[23711]: time="2026-03-04T07:16:23+01:00" level=debug msg="completed challenge" Mar 04 07:16:23 loe go-librespot[23711]: time="2026-03-04T07:16:23+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 " Mar 04 07:16:23 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 07:16:23 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 07:16:23 loe volumio[23061]: info: Connection to go-librespot Websocket closed Mar 04 07:16:23 loe volumio[23061]: info: BOOT COMPLETED Mar 04 07:16:25 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:16:25 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:16:25 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:16:25 loe volumio[23061]: info: Getting Spotify volume Mar 04 07:16:25 loe volumio[23061]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 07:16:25 loe volumio[23061]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 07:16:25 loe volumio[23061]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 04 07:16:25 loe volumio[23061]: errno: -111, Mar 04 07:16:25 loe volumio[23061]: code: 'ECONNREFUSED', Mar 04 07:16:25 loe volumio[23061]: syscall: 'connect', Mar 04 07:16:25 loe volumio[23061]: address: '127.0.0.1', Mar 04 07:16:25 loe volumio[23061]: port: 9879, Mar 04 07:16:25 loe volumio[23061]: response: undefined Mar 04 07:16:25 loe volumio[23061]: } Mar 04 07:16:25 loe volumio[23061]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 07:16:26 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Mar 04 07:16:26 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:16:26 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:16:26 loe go-librespot[23731]: go-librespot daemon starting... Mar 04 07:16:26 loe go-librespot[23732]: time="2026-03-04T07:16:26+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 07:16:26 loe go-librespot[23732]: time="2026-03-04T07:16:26+01:00" level=debug msg="app state loaded" Mar 04 07:16:26 loe go-librespot[23732]: time="2026-03-04T07:16:26+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 07:16:27 loe go-librespot[23732]: time="2026-03-04T07:16:27+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 07:16:27 loe go-librespot[23732]: time="2026-03-04T07:16:27+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 04 07:16:27 loe go-librespot[23732]: time="2026-03-04T07:16:27+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 04 07:16:27 loe go-librespot[23732]: time="2026-03-04T07:16:27+01:00" level=info msg="zeroconf server listening on port 43565" Mar 04 07:16:27 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:16:27 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:16:27 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:16:27 loe go-librespot[23732]: time="2026-03-04T07:16:27+01:00" level=debug msg="obtained new client token: AAAz9fzpUMkI6etyWufy8wEbNUXw5CPgpKIT/bdh8Hw1s0GBGIf5kV1gwpPGULrh75ggaub/3zT+/nhCpJKjprIuS/rVMFojFUMqtFi84Agk1qzrRYlY2pgdIDYP/sz6dkQFtUYy12sBlMBw9bKpTLget6rmKLBMrUbQxHkF1xGlm8MQxUTxRQYYuHyqCHTe9gYbXaDVMb13CmPfy0gvJ7WCl7oX1AA7AAzdWhUTDQmTeFNfCKJDG2o=" Mar 04 07:16:27 loe go-librespot[23732]: time="2026-03-04T07:16:27+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 07:16:27 loe sudo[23741]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-04 07:15' Mar 04 07:16:27 loe sudo[23741]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:16:27 loe go-librespot[23732]: time="2026-03-04T07:16:27+01:00" level=debug msg="completed keyexchange" Mar 04 07:16:27 loe go-librespot[23732]: time="2026-03-04T07:16:27+01:00" level=debug msg="completed challenge" Mar 04 07:16:27 loe go-librespot[23732]: time="2026-03-04T07:16:27+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 07:16:27 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 07:16:27 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 07:16:27 loe sudo[23741]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:27 loe qobuz-connect[23572]: 20260304 07:16:27.932 [23572.23572] INFO SampleApp: Socket closed Mar 04 07:16:27 loe vtcs[23661]: [2026-03-04 07:16:27.932] [tisoc] [error] [SpkconServer.cpp:378] recv error. socket disconnected Mar 04 07:16:27 loe volumio5-onboarding[2840]: time=2026-03-04T07:16:27.933+01:00 level=ERROR msg="failed reading message" component=volumio/socket error="read tcp 127.0.0.1:34694->127.0.0.1:3000: read: connection reset by peer" Mar 04 07:16:27 loe volumio5-onboarding[2840]: time=2026-03-04T07:16:27.936+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="read tcp 127.0.0.1:44526->127.0.0.1:3000: read: connection reset by peer" Mar 04 07:16:27 loe volumio-remote-updater[714]: [2026-03-04 07:16:27] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 04 07:16:27 loe volumio-remote-updater[714]: [2026-03-04 07:16:27] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 04 07:16:27 loe systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 04 07:16:27 loe systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 04 07:16:27 loe systemd[1]: volumio.service: Consumed 59.562s CPU time. Mar 04 07:16:28 loe systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 04 07:16:28 loe systemd[1]: dynamicswap.service: Deactivated successfully. Mar 04 07:16:28 loe systemd[1]: volumio.service: Scheduled restart job, restart counter is at 463. Mar 04 07:16:28 loe systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 04 07:16:28 loe systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 04 07:16:28 loe systemd[1]: volumio.service: Consumed 59.562s CPU time. Mar 04 07:16:28 loe systemd[1]: Started volumio.service - Volumio Backend Module. Mar 04 07:16:28 loe systemd[1]: dynamicswap.service: Deactivated successfully. Mar 04 07:16:28 loe volumio5-onboarding[2840]: time=2026-03-04T07:16:28.939+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Mar 04 07:16:29 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:16:29 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:16:29 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:16:29 loe volumio5-onboarding[2840]: time=2026-03-04T07:16:29.942+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Mar 04 07:16:30 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Mar 04 07:16:30 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:16:30 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:16:30 loe go-librespot[23770]: go-librespot daemon starting... Mar 04 07:16:30 loe go-librespot[23772]: time="2026-03-04T07:16:30+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 07:16:30 loe go-librespot[23772]: time="2026-03-04T07:16:30+01:00" level=debug msg="app state loaded" Mar 04 07:16:30 loe go-librespot[23772]: time="2026-03-04T07:16:30+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 07:16:30 loe volumio5-onboarding[2840]: time=2026-03-04T07:16:30.950+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Mar 04 07:16:31 loe go-librespot[23772]: time="2026-03-04T07:16:31+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 07:16:31 loe go-librespot[23772]: time="2026-03-04T07:16:31+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 04 07:16:31 loe go-librespot[23772]: time="2026-03-04T07:16:31+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 04 07:16:31 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:16:31 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:16:31 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:16:31 loe go-librespot[23772]: time="2026-03-04T07:16:31+01:00" level=info msg="zeroconf server listening on port 45809" Mar 04 07:16:31 loe go-librespot[23772]: time="2026-03-04T07:16:31+01:00" level=debug msg="obtained new client token: AACS/QvcIwtb7N9qpDz73tVJTRz3ZYGJDdqdyn7pddM3DNfey2oijaM/qbQyWA9QetdpvI+XP20j3KOu3uFTcQ8Rwjf45MxL4VUYplE3uMbT2cp5E9eAkeEmrGqzqwqTs7NzcbU47kjhAU4qsFrsPNdsAsRJRscjAUnk4eOjVhdRqFQ5yNC/4/ikRs2NwNDtNlcoknWQJVkGS/uyGb9NpbdbiJrJgoXX+xc9M1qETX7xbP/wHfEYcUiEJg==" Mar 04 07:16:31 loe go-librespot[23772]: time="2026-03-04T07:16:31+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Mar 04 07:16:31 loe go-librespot[23772]: time="2026-03-04T07:16:31+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 04 07:16:31 loe go-librespot[23772]: time="2026-03-04T07:16:31+01:00" level=debug msg="completed keyexchange" Mar 04 07:16:31 loe go-librespot[23772]: time="2026-03-04T07:16:31+01:00" level=debug msg="completed challenge" Mar 04 07:16:31 loe go-librespot[23772]: time="2026-03-04T07:16:31+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 " Mar 04 07:16:31 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 07:16:31 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 07:16:31 loe volumio[23755]: info: ------------------------------------------- Mar 04 07:16:31 loe volumio[23755]: info: ----- Volumio3 ---- Mar 04 07:16:31 loe volumio[23755]: info: ------------------------------------------- Mar 04 07:16:31 loe volumio[23755]: info: ----- System startup ---- Mar 04 07:16:31 loe volumio[23755]: info: ------------------------------------------- Mar 04 07:16:32 loe volumio-remote-updater[714]: [2026-03-04 07:16:32] [connect] Successful connection Mar 04 07:16:33 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:16:33 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:16:33 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:16:33 loe volumio[23755]: info: MYVOLUMIO Environment detected Mar 04 07:16:33 loe volumio[23755]: info: Plugin folders cleanup Mar 04 07:16:33 loe volumio[23755]: info: Scanning into folder /volumio/app/plugins/ Mar 04 07:16:33 loe volumio[23755]: info: Scanning category audio_interface Mar 04 07:16:33 loe volumio[23755]: info: Scanning category miscellanea Mar 04 07:16:33 loe volumio[23755]: info: Scanning category music_service Mar 04 07:16:33 loe volumio[23755]: info: Scanning category plugins.json Mar 04 07:16:33 loe volumio[23755]: info: Scanning category system_controller Mar 04 07:16:33 loe volumio[23755]: info: Scanning category user_interface Mar 04 07:16:33 loe volumio[23755]: info: Scanning into folder /data/plugins/ Mar 04 07:16:33 loe volumio[23755]: info: Scanning category music_service Mar 04 07:16:33 loe volumio[23755]: info: Plugin folders cleanup completed Mar 04 07:16:33 loe volumio[23755]: info: ------------------------------------------- Mar 04 07:16:33 loe volumio[23755]: info: ----- Core plugins startup ---- Mar 04 07:16:33 loe volumio[23755]: info: ------------------------------------------- Mar 04 07:16:33 loe volumio[23755]: info: Loading plugins from folder /volumio/app/plugins/ Mar 04 07:16:33 loe volumio[23755]: info: Adding plugin upnp to MyMusic Plugins Mar 04 07:16:33 loe volumio[23755]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 04 07:16:33 loe volumio[23755]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 04 07:16:33 loe volumio[23755]: info: Loading plugins from folder /data/plugins/ Mar 04 07:16:33 loe volumio[23755]: info: Loading plugin "system"... Mar 04 07:16:33 loe volumio[23755]: info: Loading plugin "appearance"... Mar 04 07:16:34 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Mar 04 07:16:34 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:16:34 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:16:34 loe go-librespot[23791]: go-librespot daemon starting... Mar 04 07:16:34 loe go-librespot[23792]: time="2026-03-04T07:16:34+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 07:16:34 loe go-librespot[23792]: time="2026-03-04T07:16:34+01:00" level=debug msg="app state loaded" Mar 04 07:16:34 loe go-librespot[23792]: time="2026-03-04T07:16:34+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 07:16:35 loe go-librespot[23792]: time="2026-03-04T07:16:35+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 07:16:35 loe go-librespot[23792]: time="2026-03-04T07:16:35+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 04 07:16:35 loe go-librespot[23792]: time="2026-03-04T07:16:35+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 04 07:16:35 loe go-librespot[23792]: time="2026-03-04T07:16:35+01:00" level=info msg="zeroconf server listening on port 43381" Mar 04 07:16:35 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:16:35 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:16:35 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:16:35 loe go-librespot[23792]: time="2026-03-04T07:16:35+01:00" level=debug msg="obtained new client token: AACwloQ9VynX/logq+5N7+e+6m7hzC5AFbIB9ucaQRFGTrYATcT/j4HxsKrXbidhBQxeb8WCyHCIp7cFTUwlz27QZtkPCFKA4Ax7mZ8lTHTOpUStCbQUNQjzyhTmtwa8Xya9AlHhT6VRP+DhAqpyFNT9HT3NDALNIc0j2ZwK1Oh737O6L4xH5hE9S75374Sosyf30lhEk5hmjtxh4AHxAy1i8Oh2sGf3AtpSCEuaezN9GtElC6fegyU=" Mar 04 07:16:35 loe go-librespot[23792]: time="2026-03-04T07:16:35+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 07:16:35 loe go-librespot[23792]: time="2026-03-04T07:16:35+01:00" level=debug msg="completed keyexchange" Mar 04 07:16:35 loe go-librespot[23792]: time="2026-03-04T07:16:35+01:00" level=debug msg="completed challenge" Mar 04 07:16:35 loe volumio[23755]: info: Loading plugin "network"... Mar 04 07:16:35 loe go-librespot[23792]: time="2026-03-04T07:16:35+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 " Mar 04 07:16:35 loe volumio[23755]: info: Refreshing Cached IP Addresses Mar 04 07:16:35 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 07:16:35 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 07:16:35 loe sudo[23800]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 04 07:16:35 loe sudo[23800]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:16:35 loe sudo[23802]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 04 07:16:35 loe sudo[23802]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:16:35 loe volumio[23755]: info: Loading plugin "services"... Mar 04 07:16:35 loe sudo[23800]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:35 loe volumio[23755]: info: Loading plugin "volumio5onboarding"... Mar 04 07:16:35 loe sudo[23802]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:35 loe sudo[23810]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 04 07:16:35 loe sudo[23810]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:16:35 loe volumio[23755]: info: Loading plugin "alsa_controller"... Mar 04 07:16:35 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 07:16:35 loe volumio[23755]: info: Loading plugin "wizard"... Mar 04 07:16:35 loe volumio[23755]: info: Loading plugin "networkfs"... Mar 04 07:16:35 loe volumio[23755]: info: Starting Udev Watcher for removable devices Mar 04 07:16:35 loe volumio[23755]: info: Ignoring mount for partition: boot Mar 04 07:16:35 loe volumio[23755]: info: Ignoring mount for partition: volumio Mar 04 07:16:35 loe volumio[23755]: info: Ignoring mount for partition: volumio_data Mar 04 07:16:35 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 07:16:35 loe volumio[23755]: info: Loading plugin "volumio_command_line_client"... Mar 04 07:16:35 loe volumio[23755]: info: Loading plugin "upnp"... Mar 04 07:16:35 loe volumio[23755]: info: [1772604995872] Starting Upmpd Daemon Mar 04 07:16:35 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 07:16:35 loe volumio[23755]: info: Loading plugin "my_music"... Mar 04 07:16:35 loe volumio[23755]: info: Loading plugin "mpd"... Mar 04 07:16:36 loe sudo[23810]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:36 loe volumio[23755]: info: Loading plugin "upnp_browser"... Mar 04 07:16:37 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:16:37 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:16:37 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:16:38 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Mar 04 07:16:38 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:16:38 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:16:38 loe go-librespot[23833]: go-librespot daemon starting... Mar 04 07:16:38 loe go-librespot[23834]: time="2026-03-04T07:16:38+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 07:16:38 loe go-librespot[23834]: time="2026-03-04T07:16:38+01:00" level=debug msg="app state loaded" Mar 04 07:16:38 loe go-librespot[23834]: time="2026-03-04T07:16:38+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 07:16:39 loe go-librespot[23834]: time="2026-03-04T07:16:39+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 07:16:39 loe go-librespot[23834]: time="2026-03-04T07:16:39+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 04 07:16:39 loe go-librespot[23834]: time="2026-03-04T07:16:39+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 04 07:16:39 loe go-librespot[23834]: time="2026-03-04T07:16:39+01:00" level=info msg="zeroconf server listening on port 36619" Mar 04 07:16:39 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:16:39 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:16:39 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:16:39 loe go-librespot[23834]: time="2026-03-04T07:16:39+01:00" level=debug msg="obtained new client token: AAC8XVO5UCo4PZMxYy38caUySjNPIWaaUsOO2EbWTSl9ozuOU7th+ddHt0EAm3ej36/s45CaA3j8LWjdP/wwbqXn+a3AYgUTMzXNVkarmmSBG0YmOgz1Kxt5C/yddmXPnCuDn63OXzx/pgKKghTsm9nLf/ZTAqIShJEeR9q1MFyGNtC50xJR+Xrz9hgIlCYoqcQUwWDQ6B3HI4aDhzoDsIzAuJ+gKMxh36p+ugOJyo0J2Bm+MlfPmeo=" Mar 04 07:16:39 loe go-librespot[23834]: time="2026-03-04T07:16:39+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 07:16:39 loe go-librespot[23834]: time="2026-03-04T07:16:39+01:00" level=debug msg="completed keyexchange" Mar 04 07:16:39 loe go-librespot[23834]: time="2026-03-04T07:16:39+01:00" level=debug msg="completed challenge" Mar 04 07:16:39 loe go-librespot[23834]: time="2026-03-04T07:16:39+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 " Mar 04 07:16:39 loe volumio[23755]: info: Starting UPNP Browser Mar 04 07:16:39 loe volumio[23755]: info: Loading plugin "alarm-clock"... Mar 04 07:16:39 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 07:16:39 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 07:16:39 loe volumio[23755]: info: Loading plugin "airplay_emulation"... Mar 04 07:16:39 loe volumio[23755]: info: Starting Shairport Sync Mar 04 07:16:39 loe volumio[23755]: info: Loading plugin "last_100"... Mar 04 07:16:39 loe volumio[23755]: info: Loading plugin "webradio"... Mar 04 07:16:39 loe volumio[23755]: info: Loading plugin "i2s_dacs"... Mar 04 07:16:39 loe volumio[23755]: info: Loading plugin "volumiodiscovery"... Mar 04 07:16:40 loe volumio[23755]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 04 07:16:40 loe volumio[23755]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 07:16:40 loe volumio[23755]: *** WARNING *** For more information see Mar 04 07:16:40 loe volumio[23755]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 04 07:16:40 loe volumio[23755]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 07:16:40 loe volumio[23755]: *** WARNING *** For more information see Mar 04 07:16:40 loe node[23755]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 04 07:16:40 loe node[23755]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 07:16:40 loe node[23755]: *** WARNING *** For more information see Mar 04 07:16:40 loe node[23755]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 04 07:16:40 loe node[23755]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 07:16:40 loe node[23755]: *** WARNING *** For more information see Mar 04 07:16:40 loe volumio[23755]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 04 07:16:40 loe volumio[23755]: info: Discovery: Started advertising with name: Loe Mar 04 07:16:40 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 07:16:40 loe volumio[23755]: info: Loading plugin "spop"... Mar 04 07:16:41 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:16:41 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:16:41 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:16:41 loe volumio[23755]: info: Loading plugin "outputs"... Mar 04 07:16:41 loe volumio[23755]: info: Loading plugin "albumart"... Mar 04 07:16:41 loe volumio5-onboarding[2840]: time=2026-03-04T07:16:41.952+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="read tcp 127.0.0.1:48242->127.0.0.1:3000: i/o timeout" Mar 04 07:16:42 loe volumio[23755]: info: Plugin example_plugin is not enabled Mar 04 07:16:42 loe volumio[23755]: info: Loading plugin "inputs"... Mar 04 07:16:42 loe volumio[23755]: info: Loading plugin "updater_comm"... Mar 04 07:16:42 loe volumio[23755]: info: Plugin mpdemulation is not enabled Mar 04 07:16:42 loe volumio[23755]: info: Loading plugin "rest_api"... Mar 04 07:16:42 loe volumio[23755]: info: Loading plugin "websocket"... Mar 04 07:16:42 loe volumio[23755]: info: Starting Socket.io Server version 1.7.4 Mar 04 07:16:42 loe volumio[23755]: info: Loading i18n strings for locale nl Mar 04 07:16:42 loe volumio[23755]: Updating browse sources language Mar 04 07:16:42 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 07:16:42 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Mar 04 07:16:42 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:16:42 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 07:16:42 loe volumio[23755]: info: CoreCommandRouter::initPlayerControls Mar 04 07:16:42 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:42 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:42 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:42 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:42 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:42 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:42 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:42 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:42 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 07:16:42 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:16:42 loe go-librespot[23853]: go-librespot daemon starting... Mar 04 07:16:42 loe volumio[23755]: Express server listening on port 3000 Mar 04 07:16:42 loe volumio[23755]: [Metrics] WebUI: 11s 621.57ms Mar 04 07:16:42 loe go-librespot[23854]: time="2026-03-04T07:16:42+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 07:16:42 loe go-librespot[23854]: time="2026-03-04T07:16:42+01:00" level=debug msg="app state loaded" Mar 04 07:16:42 loe go-librespot[23854]: time="2026-03-04T07:16:42+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 07:16:42 loe volumio[23755]: info: CoreStateMachine::resetVolumioState Mar 04 07:16:42 loe volumio[23755]: info: CoreStateMachine::getcurrentVolume Mar 04 07:16:42 loe volumio[23755]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 07:16:42 loe volumio[23755]: info: Volumio Network Manager: Network status updated: 1 Mar 04 07:16:42 loe volumio[23755]: info: VolumeController:: Volume=5 Mute =false Mar 04 07:16:42 loe volumio[23755]: info: CoreStateMachine::pushState Mar 04 07:16:43 loe volumio[23755]: info: CorePlayQueue::getTrack 0 Mar 04 07:16:43 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 07:16:43 loe volumio[23755]: info: CoreCommandRouter::volumioPushState Mar 04 07:16:43 loe volumio[23843]: Forking 3 albumart workers Mar 04 07:16:43 loe volumio[23755]: info: CoreStateMachine::updateTrackBlock Mar 04 07:16:43 loe volumio[23755]: info: CorePlayQueue::getTrackBlock Mar 04 07:16:43 loe volumio[23755]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 07:16:43 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:16:43 loe volumio[23755]: info: Reloading queue from file Mar 04 07:16:43 loe volumio[23755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Mar 04 07:16:43 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:16:43 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:16:43 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:16:43 loe volumio[23755]: info: CoreStateMachine::setRepeat false single undefined Mar 04 07:16:43 loe volumio[23755]: info: CoreStateMachine::pushState Mar 04 07:16:43 loe volumio[23755]: info: CorePlayQueue::getTrack 0 Mar 04 07:16:43 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 07:16:43 loe volumio[23755]: info: CoreCommandRouter::volumioPushState Mar 04 07:16:43 loe volumio[23755]: info: CoreStateMachine::setRandom undefined Mar 04 07:16:43 loe volumio[23755]: info: CoreStateMachine::pushState Mar 04 07:16:43 loe volumio[23755]: info: CorePlayQueue::getTrack 0 Mar 04 07:16:43 loe go-librespot[23854]: time="2026-03-04T07:16:43+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 07:16:43 loe go-librespot[23854]: time="2026-03-04T07:16:43+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 07:16:43 loe go-librespot[23854]: time="2026-03-04T07:16:43+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 07:16:43 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 07:16:43 loe volumio[23755]: info: CoreCommandRouter::volumioPushState Mar 04 07:16:43 loe volumio[23755]: info: Setting Device type: Raspberry PI Mar 04 07:16:43 loe volumio[23755]: info: Completed loading Core Plugins Mar 04 07:16:43 loe volumio[23755]: info: Preparing to generate the ALSA configuration file Mar 04 07:16:43 loe go-librespot[23854]: time="2026-03-04T07:16:43+01:00" level=info msg="zeroconf server listening on port 42919" Mar 04 07:16:43 loe volumio[23755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Mar 04 07:16:43 loe volumio[23755]: info: Received Get System Info Mar 04 07:16:43 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 07:16:43 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 07:16:43 loe volumio[23755]: info: Discovery: Getting this device information Mar 04 07:16:43 loe volumio[23755]: info: CoreCommandRouter::volumioGetState Mar 04 07:16:43 loe volumio[23755]: info: CorePlayQueue::getTrack 0 Mar 04 07:16:43 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 07:16:43 loe go-librespot[23854]: time="2026-03-04T07:16:43+01:00" level=debug msg="obtained new client token: AAB7zvHp5f2tQpS3enFLx1eRBpimmZ3hguxvYVIZZDTtRgm0FR/M9vTgfHOXnWmWn2kLW9sE/yZs9S29yGBMhnUjdf1HH3LUI22/7/2bn79JJHIodiF1g+kT77XyAjcKqJFnR628+jMNvPzDftUNjx3FWwinbauIAzf01jM82wrFopB8W89EGfTv0Zedv0D3GCtjtdqJDz/IMk3wqTrE44rL9+scUGlsHpx5Kd4vYkGBRhHKaC/hCMuGBA==" Mar 04 07:16:43 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 04 07:16:43 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 04 07:16:43 loe go-librespot[23854]: time="2026-03-04T07:16:43+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 07:16:43 loe volumio[23755]: info: VolumeController:: Volume=5 Mute =false Mar 04 07:16:43 loe volumio[23755]: info: CoreStateMachine::pushState Mar 04 07:16:43 loe volumio[23755]: info: CorePlayQueue::getTrack 0 Mar 04 07:16:43 loe volumio[23755]: info: CoreCommandRouter::volumioPushState Mar 04 07:16:43 loe go-librespot[23854]: time="2026-03-04T07:16:43+01:00" level=debug msg="completed keyexchange" Mar 04 07:16:43 loe go-librespot[23854]: time="2026-03-04T07:16:43+01:00" level=debug msg="completed challenge" Mar 04 07:16:43 loe volumio[23755]: info: Asound.conf file unchanged, so no further update is needed Mar 04 07:16:43 loe volumio[23755]: info: Output device has changed, restarting MPD Mar 04 07:16:43 loe go-librespot[23854]: time="2026-03-04T07:16:43+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 " Mar 04 07:16:43 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 07:16:43 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 07:16:43 loe volumio[23755]: info: Output device has changed, restarting Shairport Sync Mar 04 07:16:43 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:43 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:16:43 loe sudo[23907]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 07:16:43 loe sudo[23907]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:16:43 loe volumio[23755]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 07:16:43 loe volumio[23755]: info: ___________ START PLUGINS ___________ Mar 04 07:16:43 loe sudo[23909]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 07:16:43 loe sudo[23907]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:43 loe sudo[23909]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:16:43 loe volumio[23755]: info: ControllerMpd::onStart: Initializing MPD Mar 04 07:16:43 loe volumio[23755]: info: Creating MPD Configuration file Mar 04 07:16:43 loe systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 04 07:16:43 loe sudo[23917]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Mar 04 07:16:43 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 07:16:43 loe sudo[23917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:16:43 loe volumio[23755]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 07:16:43 loe volumio[23755]: info: [1772605003889] CoreMusicLibrary::Adding element Media Servers Mar 04 07:16:43 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 07:16:43 loe sudo[23919]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 07:16:43 loe sudo[23919]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:16:44 loe sudo[23919]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:44 loe volumio[23755]: info: UPNP Browser: Client initialized successfully Mar 04 07:16:44 loe systemd[1]: mpd.service: Deactivated successfully. Mar 04 07:16:44 loe sudo[23921]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 07:16:44 loe systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 04 07:16:44 loe sudo[23921]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:16:44 loe systemd[1]: mpd.service: Consumed 5.019s CPU time. Mar 04 07:16:44 loe systemd[1]: mpd.socket: Deactivated successfully. Mar 04 07:16:44 loe systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 04 07:16:44 loe systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 04 07:16:44 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:44 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:16:44 loe volumio[23755]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 07:16:44 loe systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 04 07:16:44 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:44 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:16:44 loe systemd[1]: Starting mpd.service - Music Player Daemon... Mar 04 07:16:44 loe sudo[23917]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:44 loe systemd[1]: mpd.service: Deactivated successfully. Mar 04 07:16:44 loe systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 04 07:16:44 loe systemd[1]: mpd.socket: Deactivated successfully. Mar 04 07:16:44 loe volumio[23755]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 07:16:44 loe volumio[23755]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 07:16:44 loe volumio[23755]: info: [1772605004293] CoreMusicLibrary::Adding element Last_100 Mar 04 07:16:44 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 07:16:44 loe systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 04 07:16:44 loe systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 04 07:16:44 loe volumio[23755]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 07:16:44 loe volumio[23755]: info: [1772605004313] CoreMusicLibrary::Adding element Webradio Mar 04 07:16:44 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 07:16:44 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 07:16:44 loe volumio[23755]: info: Initializing BBC Radios Mar 04 07:16:44 loe systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 04 07:16:44 loe systemd[1]: Starting mpd.service - Music Player Daemon... Mar 04 07:16:44 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 07:16:44 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:16:44 loe volumio[23755]: info: Creating Spotify config file Mar 04 07:16:44 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:44 loe sudo[23939]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 04 07:16:44 loe sudo[23939]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 04 07:16:44 loe sudo[23939]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:45 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:16:45 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:16:45 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:16:45 loe volumio-remote-updater[714]: [2026-03-04 07:16:45] [connect] Successful connection Mar 04 07:16:45 loe volumio[23755]: info: Volumio Calling Home Mar 04 07:16:46 loe volumio[23869]: Starting albumart workers Mar 04 07:16:46 loe volumio[23755]: info: Discovery: adding 07fbb113-343c-4b34-af49-444dc3d8fb26 Mar 04 07:16:46 loe volumio[23755]: info: Discovery: Found device Loe Mar 04 07:16:46 loe volumio[23755]: info: CoreCommandRouter::volumioGetState Mar 04 07:16:46 loe volumio[23755]: info: CorePlayQueue::getTrack 0 Mar 04 07:16:46 loe volumio[23755]: info: Discovery: this is already registered, 07fbb113-343c-4b34-af49-444dc3d8fb26 Mar 04 07:16:46 loe volumio[23755]: info: Discovery: Found device Loe Mar 04 07:16:46 loe volumio[23755]: info: CoreCommandRouter::volumioGetState Mar 04 07:16:46 loe volumio[23755]: info: CorePlayQueue::getTrack 0 Mar 04 07:16:46 loe sudo[23970]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 04 07:16:46 loe sudo[23972]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 04 07:16:46 loe sudo[23970]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:16:46 loe sudo[23972]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:16:46 loe sudo[23970]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:46 loe sudo[23972]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:46 loe volumio[23755]: info: MPD Permissions set Mar 04 07:16:46 loe volumio[23755]: info: MPD Permissions set Mar 04 07:16:46 loe volumio[23875]: Starting albumart workers Mar 04 07:16:46 loe volumio-remote-updater[714]: [2026-03-04 07:16:46] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1772605005 101 Mar 04 07:16:46 loe volumio[23755]: 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 Mar 04 07:16:46 loe volumio[23755]: info: Volumio called home Mar 04 07:16:46 loe volumio[23755]: info: Spotify config file written Mar 04 07:16:46 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Mar 04 07:16:46 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:16:46 loe sudo[23976]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 04 07:16:46 loe sudo[23976]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:16:46 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:16:46 loe go-librespot[23977]: go-librespot daemon starting... Mar 04 07:16:46 loe systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 04 07:16:47 loe systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 04 07:16:47 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:16:47 loe volumio[23873]: Starting albumart workers Mar 04 07:16:47 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:16:47 loe go-librespot[23985]: go-librespot daemon starting... Mar 04 07:16:47 loe sudo[23976]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:47 loe volumio[23755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Mar 04 07:16:47 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:47 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:47 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:47 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:47 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:47 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:47 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:47 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:47 loe go-librespot[23986]: time="2026-03-04T07:16:47+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 07:16:47 loe go-librespot[23986]: time="2026-03-04T07:16:47+01:00" level=debug msg="app state loaded" Mar 04 07:16:47 loe go-librespot[23986]: time="2026-03-04T07:16:47+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 07:16:47 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:16:47 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:16:47 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:16:47 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:16:47 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:47 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:47 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:47 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:47 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:47 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:47 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:47 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:47 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:47 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:16:47 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:16:47 loe volumio[23755]: info: No need to fix Spotify hosts Mar 04 07:16:47 loe go-librespot[23986]: time="2026-03-04T07:16:47+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 07:16:47 loe go-librespot[23986]: time="2026-03-04T07:16:47+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 07:16:47 loe go-librespot[23986]: time="2026-03-04T07:16:47+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 07:16:47 loe go-librespot[23986]: time="2026-03-04T07:16:47+01:00" level=info msg="zeroconf server listening on port 40369" Mar 04 07:16:47 loe go-librespot[23986]: time="2026-03-04T07:16:47+01:00" level=debug msg="obtained new client token: AACE9C2GInLBD+tCoa4brBxDmhvr/pAkNscHvuG+2rjMOsFnnirG1eyxobWCeJRzV7kU1oqEiGjlPxJJ//ayxLbVA6GQr6/yO7AsB+b8UbPQwoRXqd0xkZ9TWY3DOh97/Q6YGOaARxPhFaBSNpEM+HbRlzMgIgLAbgQZAR4dPktRkAMQOwtodRBAMp1FYH1Dy7bdMSAVw/m6uc2IMs1VhonwgsPxF2Cyl/PbH/nJPMJMNxOHtVipsylosw==" Mar 04 07:16:47 loe go-librespot[23986]: time="2026-03-04T07:16:47+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 07:16:48 loe go-librespot[23986]: time="2026-03-04T07:16:48+01:00" level=debug msg="completed keyexchange" Mar 04 07:16:48 loe go-librespot[23986]: time="2026-03-04T07:16:48+01:00" level=debug msg="completed challenge" Mar 04 07:16:48 loe go-librespot[23986]: time="2026-03-04T07:16:48+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 " Mar 04 07:16:48 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 07:16:48 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 07:16:48 loe volumio[23755]: info: Starting Shairport Sync Mar 04 07:16:48 loe volumio[23755]: info: Starting Shairport Sync Mar 04 07:16:48 loe sudo[24006]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 07:16:48 loe sudo[24006]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:16:48 loe volumio[23755]: info: Starting Shairport Sync Mar 04 07:16:48 loe systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 04 07:16:48 loe systemd[1]: shairport-sync.service: Deactivated successfully. Mar 04 07:16:48 loe systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 07:16:48 loe systemd[1]: shairport-sync.service: Consumed 2.137s CPU time. Mar 04 07:16:48 loe sudo[24009]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 07:16:48 loe sudo[24009]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:16:48 loe volumio[23755]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 04 07:16:48 loe sudo[24011]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 07:16:48 loe sudo[24011]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:16:48 loe systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 07:16:48 loe sudo[24006]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:48 loe sudo[24014]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 04 07:16:48 loe sudo[24014]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:16:48 loe systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 04 07:16:48 loe systemd[1]: shairport-sync.service: Deactivated successfully. Mar 04 07:16:48 loe systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 07:16:48 loe systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 07:16:48 loe volumio[23755]: info: Shairport-Sync Started Mar 04 07:16:48 loe sudo[24011]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:48 loe volumio[23755]: Error adding Membership: Error: addMembership EINVAL Mar 04 07:16:48 loe sudo[24009]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:48 loe volumio[23755]: info: Shairport-Sync Started Mar 04 07:16:48 loe volumio[23755]: info: Shairport-Sync Started Mar 04 07:16:48 loe sudo[24014]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:48 loe volumio[23755]: info: CoreCommandRouter::volumioGetState Mar 04 07:16:48 loe volumio[23755]: info: CorePlayQueue::getTrack 0 Mar 04 07:16:48 loe volumio[23755]: info: Upmpdcli Daemon Started Mar 04 07:16:49 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:16:49 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:16:49 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:16:50 loe volumio[23755]: info: go-librespot daemon successfully initialized Mar 04 07:16:51 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:16:51 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:16:51 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:16:51 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 04 07:16:51 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:16:51 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:16:51 loe go-librespot[24062]: go-librespot daemon starting... Mar 04 07:16:51 loe go-librespot[24063]: time="2026-03-04T07:16:51+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 07:16:51 loe go-librespot[24063]: time="2026-03-04T07:16:51+01:00" level=debug msg="app state loaded" Mar 04 07:16:51 loe go-librespot[24063]: time="2026-03-04T07:16:51+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 07:16:51 loe mpd[23951]: 2026-03-04T07:16:51 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 04 07:16:51 loe systemd[1]: Started mpd.service - Music Player Daemon. Mar 04 07:16:51 loe sudo[23909]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:51 loe sudo[23921]: pam_unix(sudo:session): session closed for user root Mar 04 07:16:51 loe volumio[23755]: info: Completed starting Core Plugins Mar 04 07:16:51 loe volumio[23755]: info: ------------------------------------------- Mar 04 07:16:51 loe volumio[23755]: info: ----- MyVolumio plugins startup ---- Mar 04 07:16:51 loe volumio[23755]: info: ------------------------------------------- Mar 04 07:16:51 loe volumio[23755]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 04 07:16:51 loe volumio[23755]: error: MPD error: The expression evaluated to a falsy value: Mar 04 07:16:51 loe volumio[23755]: assert.ok(self.idling) Mar 04 07:16:51 loe volumio[23755]: error: The expression evaluated to a falsy value: Mar 04 07:16:51 loe volumio[23755]: assert.ok(self.idling) Mar 04 07:16:51 loe volumio[23755]: info: MPD running with PID23951 Mar 04 07:16:51 loe volumio[23755]: ,establishing connection Mar 04 07:16:51 loe volumio[23755]: error: updateQueue error: null Mar 04 07:16:51 loe volumio[23755]: error: updateQueue error: null Mar 04 07:16:51 loe go-librespot[24063]: time="2026-03-04T07:16:51+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 07:16:51 loe go-librespot[24063]: time="2026-03-04T07:16:51+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 07:16:51 loe go-librespot[24063]: time="2026-03-04T07:16:51+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 07:16:51 loe go-librespot[24063]: time="2026-03-04T07:16:51+01:00" level=info msg="zeroconf server listening on port 40775" Mar 04 07:16:52 loe go-librespot[24063]: time="2026-03-04T07:16:52+01:00" level=debug msg="obtained new client token: AAAGQBVrNj7Ji/a0X1biUBAlfEoQpqqKPIUJt6xaZwc5e6MlmlmtEYSsoBq2lXQh0awgO153Op1AzZhgGEc0ZzobLtGWC6p4coiCwVTstM+A+ZRamtIFOzxMIPGYqb9iFRrN2CtDas4glZFdiLa/o8QfmvsvFpLIN0jIBGfqNGv1drTX0XsAgos5oo/z99J2YcQ0T3xCdrUKqcvlxEtVlgBm3gcBB0ozC8nYCo0MrD4dCjus6P7G9PAnFw==" Mar 04 07:16:52 loe go-librespot[24063]: time="2026-03-04T07:16:52+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 07:16:52 loe go-librespot[24063]: time="2026-03-04T07:16:52+01:00" level=debug msg="completed keyexchange" Mar 04 07:16:52 loe go-librespot[24063]: time="2026-03-04T07:16:52+01:00" level=debug msg="completed challenge" Mar 04 07:16:52 loe go-librespot[24063]: time="2026-03-04T07:16:52+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 " Mar 04 07:16:52 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 07:16:52 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 07:16:53 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:16:53 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:16:53 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:16:53 loe volumio[23755]: info: Initializing connection to go-librespot Websocket Mar 04 07:16:53 loe volumio[23755]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 07:16:55 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:16:55 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:16:55 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:16:55 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 04 07:16:55 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:16:55 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:16:55 loe go-librespot[24075]: go-librespot daemon starting... Mar 04 07:16:55 loe go-librespot[24076]: time="2026-03-04T07:16:55+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 07:16:55 loe go-librespot[24076]: time="2026-03-04T07:16:55+01:00" level=debug msg="app state loaded" Mar 04 07:16:55 loe go-librespot[24076]: time="2026-03-04T07:16:55+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 07:16:55 loe go-librespot[24076]: time="2026-03-04T07:16:55+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 07:16:55 loe go-librespot[24076]: time="2026-03-04T07:16:55+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 07:16:55 loe go-librespot[24076]: time="2026-03-04T07:16:55+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 07:16:55 loe go-librespot[24076]: time="2026-03-04T07:16:55+01:00" level=info msg="zeroconf server listening on port 45215" Mar 04 07:16:55 loe go-librespot[24076]: time="2026-03-04T07:16:55+01:00" level=debug msg="obtained new client token: AABt2on87nyJS6dRCrHa0NVt+417thZUZUVlsrrzK8yCMzGypFgeSwav+PiualKO6HETTLe1SLOy2rx86t0A4cfBkZBosrjHAZ6OxTqK9gDcyf78oG3f+uZ5PuwaEvrFYDsYxaoruphMI6QUJTZC0/tOvx8pUTpxLTB4wQpE2pDpzfG+5rdYQ8rdK1NONSp/kwl68pGkx2KW9CG2NXPbF95u/JkwfD14yvXne3Dye0UMSeqrR4ONVI1Ixg==" Mar 04 07:16:56 loe go-librespot[24076]: time="2026-03-04T07:16:56+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 07:16:56 loe go-librespot[24076]: time="2026-03-04T07:16:56+01:00" level=debug msg="completed keyexchange" Mar 04 07:16:56 loe go-librespot[24076]: time="2026-03-04T07:16:56+01:00" level=debug msg="completed challenge" Mar 04 07:16:56 loe go-librespot[24076]: time="2026-03-04T07:16:56+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 " Mar 04 07:16:56 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 07:16:56 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 07:16:56 loe volumio[23755]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 04 07:16:56 loe volumio[23755]: info: Initializing connection to go-librespot Websocket Mar 04 07:16:56 loe volumio[23755]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 07:16:57 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:16:57 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:16:57 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:16:59 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:16:59 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:16:59 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:16:59 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 04 07:16:59 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:16:59 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:16:59 loe go-librespot[24098]: go-librespot daemon starting... Mar 04 07:16:59 loe go-librespot[24099]: time="2026-03-04T07:16:59+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 07:16:59 loe go-librespot[24099]: time="2026-03-04T07:16:59+01:00" level=debug msg="app state loaded" Mar 04 07:16:59 loe go-librespot[24099]: time="2026-03-04T07:16:59+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 07:16:59 loe go-librespot[24099]: time="2026-03-04T07:16:59+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 07:16:59 loe go-librespot[24099]: time="2026-03-04T07:16:59+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 07:16:59 loe go-librespot[24099]: time="2026-03-04T07:16:59+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 07:16:59 loe go-librespot[24099]: time="2026-03-04T07:16:59+01:00" level=info msg="zeroconf server listening on port 34359" Mar 04 07:16:59 loe go-librespot[24099]: time="2026-03-04T07:16:59+01:00" level=debug msg="obtained new client token: AACg0E3eYE+GFkuB0SCxTTIzS3vmu0Q7MH51JOp+ydlYlLF4aovVtqa5pukgl8ttJoM4/XufaAjdEgUdTl97UqLx/QZAo75dPCx0T+RpuDKlks4rV+gQ/aUiIIsbEvYx1vFsE7rOg/8pAWBfwHXaguJZEs0IJDKn5cpC2IzwvBVPHWkXiITZbY6eOtNaRASWCDfl90VZ9bg6mFVbnM5Sd4upw4gwVukcUocgxzxtW5ZI8XBQNF8NnoWSeg==" Mar 04 07:16:59 loe volumio[23755]: info: Initializing connection to go-librespot Websocket Mar 04 07:16:59 loe go-librespot[24099]: time="2026-03-04T07:16:59+01:00" level=debug msg="new websocket client" Mar 04 07:16:59 loe volumio[23755]: info: Connection to go-librespot Websocket established Mar 04 07:16:59 loe go-librespot[24099]: time="2026-03-04T07:16:59+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 07:17:00 loe volumio[23755]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 04 07:17:00 loe volumio[23755]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 04 07:17:00 loe volumio[23755]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 04 07:17:00 loe volumio[23755]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 04 07:17:00 loe volumio[23755]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 04 07:17:00 loe volumio[23755]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 04 07:17:00 loe volumio[23755]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 04 07:17:00 loe volumio[23755]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 04 07:17:00 loe volumio[23755]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 04 07:17:00 loe volumio[23755]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 04 07:17:00 loe volumio[23755]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 04 07:17:00 loe volumio[23755]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 04 07:17:00 loe volumio[23755]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 04 07:17:00 loe volumio[23755]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 04 07:17:00 loe volumio[23755]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 04 07:17:00 loe volumio[23755]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 04 07:17:00 loe volumio[23755]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 04 07:17:00 loe volumio[23755]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 04 07:17:00 loe volumio[23755]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 04 07:17:00 loe volumio[23755]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 04 07:17:00 loe volumio[23755]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 04 07:17:00 loe volumio[23755]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 04 07:17:00 loe volumio[23755]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 04 07:17:00 loe volumio[23755]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 04 07:17:00 loe volumio[23755]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 04 07:17:00 loe volumio[23755]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 04 07:17:00 loe volumio[23755]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 04 07:17:00 loe volumio[23755]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 04 07:17:00 loe volumio[23755]: info: Adding plugin bluetooth to MyMusic Plugins Mar 04 07:17:00 loe volumio[23755]: info: Adding plugin multiroom to MyMusic Plugins Mar 04 07:17:00 loe volumio[23755]: info: Adding plugin metavolumio to MyMusic Plugins Mar 04 07:17:00 loe go-librespot[24099]: time="2026-03-04T07:17:00+01:00" level=debug msg="completed keyexchange" Mar 04 07:17:00 loe go-librespot[24099]: time="2026-03-04T07:17:00+01:00" level=debug msg="completed challenge" Mar 04 07:17:00 loe volumio[23755]: info: Adding plugin cd_controller to MyMusic Plugins Mar 04 07:17:00 loe volumio[23755]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 04 07:17:00 loe volumio[23755]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 04 07:17:00 loe volumio[23755]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 04 07:17:00 loe volumio[23755]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 04 07:17:00 loe go-librespot[24099]: time="2026-03-04T07:17:00+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 07:17:00 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 07:17:00 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 07:17:01 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:17:01 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:17:01 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:17:01 loe volumio[23755]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 04 07:17:01 loe volumio[23755]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 04 07:17:01 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:17:01 loe volumio[23755]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:17:01 loe volumio[23755]: info: Starting MyVolumio Remote Streaming Endpoints Mar 04 07:17:01 loe volumio[23755]: info: MyVolumio login type: Token Mar 04 07:17:02 loe volumio[23755]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 04 07:17:02 loe volumio[23755]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 04 07:17:03 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:17:03 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:17:03 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:17:03 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 04 07:17:03 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:17:03 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:17:03 loe go-librespot[24106]: go-librespot daemon starting... Mar 04 07:17:03 loe go-librespot[24107]: time="2026-03-04T07:17:03+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 07:17:03 loe go-librespot[24107]: time="2026-03-04T07:17:03+01:00" level=debug msg="app state loaded" Mar 04 07:17:03 loe go-librespot[24107]: time="2026-03-04T07:17:03+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 07:17:03 loe volumio[23755]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 04 07:17:03 loe volumio[23755]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 04 07:17:03 loe volumio[23755]: info: Streaming services startup Mar 04 07:17:03 loe volumio[23755]: info: Starting Streaming Daemon Mar 04 07:17:03 loe sudo[24115]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 04 07:17:03 loe sudo[24115]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:17:03 loe volumio[23755]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 04 07:17:03 loe sudo[24115]: pam_unix(sudo:session): session closed for user root Mar 04 07:17:03 loe volumio[23755]: info: Getting Spotify volume Mar 04 07:17:03 loe volumio[23755]: info: Connection to go-librespot Websocket closed Mar 04 07:17:03 loe volumio[23755]: error: Cannot start Volumio Streaming Daemon Mar 04 07:17:03 loe volumio[23755]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 04 07:17:03 loe volumio[23755]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 04 07:17:03 loe volumio[23755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Mar 04 07:17:03 loe go-librespot[24107]: time="2026-03-04T07:17:03+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 07:17:03 loe go-librespot[24107]: time="2026-03-04T07:17:03+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 07:17:03 loe go-librespot[24107]: time="2026-03-04T07:17:03+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 07:17:03 loe go-librespot[24107]: time="2026-03-04T07:17:03+01:00" level=info msg="zeroconf server listening on port 36891" Mar 04 07:17:04 loe volumio[23755]: info: CoreCommandRouter::volumioGetState Mar 04 07:17:04 loe volumio[23755]: info: CorePlayQueue::getTrack 0 Mar 04 07:17:04 loe go-librespot[24107]: time="2026-03-04T07:17:04+01:00" level=debug msg="obtained new client token: AAD3JHZ6ZWbmtYLj7r67HMBoz6/9v4JTnVeSo/l95qS59g3BBWtpyxlX9h5iC8HLLWQ9bNzZTq+oymZrjyQwxPqL+5gqtfXLGyPmKbCRf0jWijlbL928K6ycZgl9+ojDMZO4B3fUKFNrbfsctGcVSlqQq8IbFZs22azsHr9nAlNT9UULGCZXLQMV3nfnlFFaDzMaLxerJjkVgs0vySdvJWd8CqG+nU4Df47cWk5ZwdpR6xkGq+xRkrw=" Mar 04 07:17:04 loe volumio[23755]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5 Mar 04 07:17:04 loe volumio[23755]: SPOTIFY: SPOTIFY VOLUME undefined Mar 04 07:17:04 loe volumio[23755]: SPOTIFY: VOLUMIO VOLUME 5 Mar 04 07:17:04 loe volumio[23755]: info: Aligning Spotify Volume to Volumio Volume Mar 04 07:17:04 loe volumio[23755]: info: CoreCommandRouter::volumioGetState Mar 04 07:17:04 loe volumio[23755]: info: CorePlayQueue::getTrack 0 Mar 04 07:17:04 loe volumio[23755]: info: Setting Spotify Volume from Volumio: 5 Mar 04 07:17:04 loe go-librespot[24107]: time="2026-03-04T07:17:04+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Mar 04 07:17:04 loe go-librespot[24107]: time="2026-03-04T07:17:04+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 04 07:17:04 loe go-librespot[24107]: time="2026-03-04T07:17:04+01:00" level=debug msg="completed keyexchange" Mar 04 07:17:04 loe go-librespot[24107]: time="2026-03-04T07:17:04+01:00" level=debug msg="completed challenge" Mar 04 07:17:04 loe go-librespot[24107]: time="2026-03-04T07:17: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 " Mar 04 07:17:04 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 07:17:04 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 07:17:04 loe volumio[23755]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 07:17:04 loe volumio[23755]: Error: socket hang up Mar 04 07:17:04 loe volumio[23755]: at connResetException (node:internal/errors:720:14) Mar 04 07:17:04 loe volumio[23755]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 04 07:17:04 loe volumio[23755]: at Socket.emit (node:events:526:35) Mar 04 07:17:04 loe volumio[23755]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 04 07:17:04 loe volumio[23755]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 04 07:17:04 loe volumio[23755]: code: 'ECONNRESET', Mar 04 07:17:04 loe volumio[23755]: response: undefined Mar 04 07:17:04 loe volumio[23755]: } Mar 04 07:17:04 loe volumio[23755]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 07:17:05 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:17:05 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:17:05 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:17:05 loe sudo[24136]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-04 07:16' Mar 04 07:17:05 loe sudo[24136]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:17:06 loe sudo[24136]: pam_unix(sudo:session): session closed for user root Mar 04 07:17:06 loe volumio-remote-updater[714]: [2026-03-04 07:17:06] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 04 07:17:06 loe volumio-remote-updater[714]: [2026-03-04 07:17:06] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 04 07:17:06 loe volumio5-onboarding[2840]: time=2026-03-04T07:17:06.553+01:00 level=ERROR msg="failed reading message" component=volumio/socket error="websocket: close 1006 (abnormal closure): unexpected EOF" Mar 04 07:17:06 loe volumio5-onboarding[2840]: time=2026-03-04T07:17:06.557+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="write tcp 127.0.0.1:50996->127.0.0.1:3000: write: connection reset by peer" Mar 04 07:17:06 loe systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 04 07:17:06 loe systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 04 07:17:06 loe systemd[1]: volumio.service: Consumed 44.939s CPU time. Mar 04 07:17:06 loe systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 04 07:17:06 loe systemd[1]: dynamicswap.service: Deactivated successfully. Mar 04 07:17:06 loe systemd[1]: volumio.service: Scheduled restart job, restart counter is at 464. Mar 04 07:17:06 loe systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 04 07:17:06 loe systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 04 07:17:06 loe systemd[1]: volumio.service: Consumed 44.939s CPU time. Mar 04 07:17:06 loe systemd[1]: Started volumio.service - Volumio Backend Module. Mar 04 07:17:06 loe systemd[1]: dynamicswap.service: Deactivated successfully. Mar 04 07:17:07 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:17:07 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:17:07 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:17:07 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Mar 04 07:17:07 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:17:07 loe volumio5-onboarding[2840]: time=2026-03-04T07:17:07.560+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Mar 04 07:17:07 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:17:07 loe go-librespot[24180]: go-librespot daemon starting... Mar 04 07:17:07 loe go-librespot[24181]: time="2026-03-04T07:17:07+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 07:17:07 loe go-librespot[24181]: time="2026-03-04T07:17:07+01:00" level=debug msg="app state loaded" Mar 04 07:17:07 loe go-librespot[24181]: time="2026-03-04T07:17:07+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 07:17:08 loe go-librespot[24181]: time="2026-03-04T07:17:08+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 07:17:08 loe go-librespot[24181]: time="2026-03-04T07:17:08+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 07:17:08 loe go-librespot[24181]: time="2026-03-04T07:17:08+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 07:17:08 loe go-librespot[24181]: time="2026-03-04T07:17:08+01:00" level=info msg="zeroconf server listening on port 46569" Mar 04 07:17:08 loe go-librespot[24181]: time="2026-03-04T07:17:08+01:00" level=debug msg="obtained new client token: AABup11v1C0zNG1M0zFUqOdOsXw2PklEY5mcwphqZzOJZDD9ZpqfQuL9N6mgvh/1rzuHSp/d78pPKPyhnwlPq5N6mU1uCEm2pGYqTM93dPgvvUy/n8Ec4yQzsyw2q4LxBGYnTCjXkvb9hyDpSqSobaMk5lmQIVETP2t4/OM1pReOo8n+e9vmjkZqZ6dXHmtVTpaLhurY8u0+ja99VOrLMwPjmUic9Yc1ejc46HPdxkWZ5Z5S/JVmQXU=" Mar 04 07:17:08 loe go-librespot[24181]: time="2026-03-04T07:17:08+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 07:17:08 loe go-librespot[24181]: time="2026-03-04T07:17:08+01:00" level=debug msg="completed keyexchange" Mar 04 07:17:08 loe go-librespot[24181]: time="2026-03-04T07:17:08+01:00" level=debug msg="completed challenge" Mar 04 07:17:08 loe go-librespot[24181]: time="2026-03-04T07:17:08+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 " Mar 04 07:17:08 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 07:17:08 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 07:17:08 loe volumio5-onboarding[2840]: time=2026-03-04T07:17:08.562+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Mar 04 07:17:09 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:17:09 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:17:09 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:17:10 loe volumio[24165]: info: ------------------------------------------- Mar 04 07:17:10 loe volumio[24165]: info: ----- Volumio3 ---- Mar 04 07:17:10 loe volumio[24165]: info: ------------------------------------------- Mar 04 07:17:10 loe volumio[24165]: info: ----- System startup ---- Mar 04 07:17:10 loe volumio[24165]: info: ------------------------------------------- Mar 04 07:17:11 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:17:11 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:17:11 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:17:11 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Mar 04 07:17:11 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:17:11 loe volumio-remote-updater[714]: [2026-03-04 07:17:11] [connect] Successful connection Mar 04 07:17:11 loe volumio[24165]: info: MYVOLUMIO Environment detected Mar 04 07:17:11 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:17:11 loe go-librespot[24194]: go-librespot daemon starting... Mar 04 07:17:11 loe go-librespot[24198]: time="2026-03-04T07:17:11+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 07:17:11 loe go-librespot[24198]: time="2026-03-04T07:17:11+01:00" level=debug msg="app state loaded" Mar 04 07:17:11 loe go-librespot[24198]: time="2026-03-04T07:17:11+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 07:17:11 loe volumio[24165]: info: Plugin folders cleanup Mar 04 07:17:11 loe volumio[24165]: info: Scanning into folder /volumio/app/plugins/ Mar 04 07:17:11 loe volumio[24165]: info: Scanning category audio_interface Mar 04 07:17:11 loe volumio[24165]: info: Scanning category miscellanea Mar 04 07:17:11 loe volumio[24165]: info: Scanning category music_service Mar 04 07:17:11 loe volumio[24165]: info: Scanning category plugins.json Mar 04 07:17:11 loe volumio[24165]: info: Scanning category system_controller Mar 04 07:17:11 loe volumio[24165]: info: Scanning category user_interface Mar 04 07:17:11 loe volumio[24165]: info: Scanning into folder /data/plugins/ Mar 04 07:17:11 loe volumio[24165]: info: Scanning category music_service Mar 04 07:17:11 loe volumio[24165]: info: Plugin folders cleanup completed Mar 04 07:17:11 loe volumio[24165]: info: ------------------------------------------- Mar 04 07:17:11 loe volumio[24165]: info: ----- Core plugins startup ---- Mar 04 07:17:11 loe volumio[24165]: info: ------------------------------------------- Mar 04 07:17:11 loe volumio[24165]: info: Loading plugins from folder /volumio/app/plugins/ Mar 04 07:17:11 loe volumio[24165]: info: Adding plugin upnp to MyMusic Plugins Mar 04 07:17:11 loe volumio[24165]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 04 07:17:11 loe volumio[24165]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 04 07:17:11 loe volumio[24165]: info: Loading plugins from folder /data/plugins/ Mar 04 07:17:11 loe volumio[24165]: info: Loading plugin "system"... Mar 04 07:17:11 loe volumio[24165]: info: Loading plugin "appearance"... Mar 04 07:17:12 loe go-librespot[24198]: time="2026-03-04T07:17:12+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 07:17:12 loe go-librespot[24198]: time="2026-03-04T07:17:12+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 07:17:12 loe go-librespot[24198]: time="2026-03-04T07:17:12+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 07:17:12 loe go-librespot[24198]: time="2026-03-04T07:17:12+01:00" level=info msg="zeroconf server listening on port 37379" Mar 04 07:17:12 loe go-librespot[24198]: time="2026-03-04T07:17:12+01:00" level=debug msg="obtained new client token: AABDLaimEEKIVxPnIFb64hRSu87SMsNtTe7Cr06fVBEQINyGtr5Tj9PC0ub0CwWsrhRPeU1WFoo+kIpM2HnQeNLbioyA6ceMJehbtDUBIlozmUVYPG0qaaHIcN5jZ9pkWr1l27E9hLrPHy+YVkfjOSenmgtTdHFEDJMgD7WPCb3hJBaHB3ZFp/Zk2G2Mtp5CW+AUarQmK7qyVUaVe6GgZqFPvTq9NvPpfu90fIvz2Ef3kbF4muSF/9g=" Mar 04 07:17:12 loe go-librespot[24198]: time="2026-03-04T07:17:12+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 07:17:12 loe go-librespot[24198]: time="2026-03-04T07:17:12+01:00" level=debug msg="completed keyexchange" Mar 04 07:17:12 loe go-librespot[24198]: time="2026-03-04T07:17:12+01:00" level=debug msg="completed challenge" Mar 04 07:17:12 loe go-librespot[24198]: time="2026-03-04T07:17: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 " Mar 04 07:17:12 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 07:17:12 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 07:17:13 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:17:13 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:17:13 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:17:13 loe volumio[24165]: info: Loading plugin "network"... Mar 04 07:17:13 loe volumio[24165]: info: Refreshing Cached IP Addresses Mar 04 07:17:13 loe sudo[24209]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 04 07:17:13 loe sudo[24209]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:17:13 loe volumio[24165]: info: Loading plugin "services"... Mar 04 07:17:13 loe sudo[24211]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 04 07:17:13 loe sudo[24209]: pam_unix(sudo:session): session closed for user root Mar 04 07:17:13 loe sudo[24211]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:17:13 loe volumio[24165]: info: Loading plugin "volumio5onboarding"... Mar 04 07:17:13 loe sudo[24211]: pam_unix(sudo:session): session closed for user root Mar 04 07:17:13 loe volumio[24165]: info: Loading plugin "alsa_controller"... Mar 04 07:17:13 loe sudo[24219]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 04 07:17:13 loe sudo[24219]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:17:13 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 07:17:13 loe volumio[24165]: info: Loading plugin "wizard"... Mar 04 07:17:13 loe volumio[24165]: info: Loading plugin "networkfs"... Mar 04 07:17:13 loe volumio[24165]: info: Starting Udev Watcher for removable devices Mar 04 07:17:13 loe volumio[24165]: info: Ignoring mount for partition: boot Mar 04 07:17:14 loe volumio[24165]: info: Ignoring mount for partition: volumio Mar 04 07:17:14 loe volumio[24165]: info: Ignoring mount for partition: volumio_data Mar 04 07:17:14 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 07:17:14 loe volumio[24165]: info: Loading plugin "volumio_command_line_client"... Mar 04 07:17:14 loe volumio[24165]: info: Loading plugin "upnp"... Mar 04 07:17:14 loe volumio[24165]: info: [1772605034024] Starting Upmpd Daemon Mar 04 07:17:14 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 07:17:14 loe volumio[24165]: info: Loading plugin "my_music"... Mar 04 07:17:14 loe volumio[24165]: info: Loading plugin "mpd"... Mar 04 07:17:14 loe sudo[24219]: pam_unix(sudo:session): session closed for user root Mar 04 07:17:14 loe volumio[24165]: info: Loading plugin "upnp_browser"... Mar 04 07:17:15 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:17:15 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:17:15 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:17:15 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Mar 04 07:17:15 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:17:15 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:17:15 loe go-librespot[24243]: go-librespot daemon starting... Mar 04 07:17:15 loe go-librespot[24244]: time="2026-03-04T07:17:15+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 07:17:15 loe go-librespot[24244]: time="2026-03-04T07:17:15+01:00" level=debug msg="app state loaded" Mar 04 07:17:15 loe go-librespot[24244]: time="2026-03-04T07:17:15+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 07:17:16 loe go-librespot[24244]: time="2026-03-04T07:17:16+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 07:17:16 loe go-librespot[24244]: time="2026-03-04T07:17:16+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 07:17:16 loe go-librespot[24244]: time="2026-03-04T07:17:16+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 07:17:16 loe go-librespot[24244]: time="2026-03-04T07:17:16+01:00" level=info msg="zeroconf server listening on port 37161" Mar 04 07:17:16 loe go-librespot[24244]: time="2026-03-04T07:17:16+01:00" level=debug msg="obtained new client token: AAB+xPwAa1yKeR7CqNC1VlAZvJeXyWp3uR9yfKy7w1j+rDHpaiSfNKxfy7TB09GJ2rysoGRBT1ui1L2YIT1ZqTAxmjB7ekzdvITgYB8ml3kIVq1hmBnmk8qVQK8jYr5JOWc8NaCHbbWWr01fIyGt8xn8nXtn1cKPmogLNsi9UmHIYYdy9zdKh9SIJwnAejI8oBtdcN55Z8MG9x3xgnpmeG1J5eXdLhG36nIsCYENwdTILq5qtiiitH0=" Mar 04 07:17:16 loe go-librespot[24244]: time="2026-03-04T07:17:16+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Mar 04 07:17:16 loe go-librespot[24244]: time="2026-03-04T07:17:16+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 04 07:17:16 loe go-librespot[24244]: time="2026-03-04T07:17:16+01:00" level=debug msg="completed keyexchange" Mar 04 07:17:16 loe go-librespot[24244]: time="2026-03-04T07:17:16+01:00" level=debug msg="completed challenge" Mar 04 07:17:16 loe go-librespot[24244]: time="2026-03-04T07:17:16+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 " Mar 04 07:17:16 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 07:17:16 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 07:17:17 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:17:17 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:17:17 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:17:17 loe volumio[24165]: info: Starting UPNP Browser Mar 04 07:17:17 loe volumio[24165]: info: Loading plugin "alarm-clock"... Mar 04 07:17:17 loe volumio[24165]: info: Loading plugin "airplay_emulation"... Mar 04 07:17:17 loe volumio[24165]: info: Starting Shairport Sync Mar 04 07:17:17 loe volumio[24165]: info: Loading plugin "last_100"... Mar 04 07:17:17 loe volumio[24165]: info: Loading plugin "webradio"... Mar 04 07:17:17 loe volumio[24165]: info: Loading plugin "i2s_dacs"... Mar 04 07:17:18 loe volumio[24165]: info: Loading plugin "volumiodiscovery"... Mar 04 07:17:18 loe volumio[24165]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 04 07:17:18 loe volumio[24165]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 07:17:18 loe volumio[24165]: *** WARNING *** For more information see Mar 04 07:17:18 loe volumio[24165]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 04 07:17:18 loe volumio[24165]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 07:17:18 loe volumio[24165]: *** WARNING *** For more information see Mar 04 07:17:18 loe node[24165]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 04 07:17:18 loe node[24165]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 07:17:18 loe node[24165]: *** WARNING *** For more information see Mar 04 07:17:18 loe node[24165]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 04 07:17:18 loe node[24165]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 07:17:18 loe node[24165]: *** WARNING *** For more information see Mar 04 07:17:18 loe volumio[24165]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 04 07:17:18 loe volumio[24165]: info: Discovery: Started advertising with name: Loe Mar 04 07:17:18 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 07:17:18 loe volumio[24165]: info: Loading plugin "spop"... Mar 04 07:17:19 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:17:19 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:17:19 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:17:19 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Mar 04 07:17:19 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:17:19 loe volumio5-onboarding[2840]: time=2026-03-04T07:17:19.564+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="read tcp 127.0.0.1:43040->127.0.0.1:3000: i/o timeout" Mar 04 07:17:19 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:17:19 loe go-librespot[24254]: go-librespot daemon starting... Mar 04 07:17:19 loe go-librespot[24255]: time="2026-03-04T07:17:19+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 07:17:19 loe go-librespot[24255]: time="2026-03-04T07:17:19+01:00" level=debug msg="app state loaded" Mar 04 07:17:19 loe go-librespot[24255]: time="2026-03-04T07:17:19+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 07:17:19 loe volumio[24165]: info: Loading plugin "outputs"... Mar 04 07:17:19 loe volumio[24165]: info: Loading plugin "albumart"... Mar 04 07:17:20 loe volumio[24165]: info: Plugin example_plugin is not enabled Mar 04 07:17:20 loe volumio[24165]: info: Loading plugin "inputs"... Mar 04 07:17:20 loe volumio[24165]: info: Loading plugin "updater_comm"... Mar 04 07:17:20 loe go-librespot[24255]: time="2026-03-04T07:17:20+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 07:17:20 loe go-librespot[24255]: time="2026-03-04T07:17:20+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 07:17:20 loe go-librespot[24255]: time="2026-03-04T07:17:20+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 07:17:20 loe go-librespot[24255]: time="2026-03-04T07:17:20+01:00" level=info msg="zeroconf server listening on port 35523" Mar 04 07:17:20 loe go-librespot[24255]: time="2026-03-04T07:17:20+01:00" level=debug msg="obtained new client token: AAA8HeFNlRsmSyexbqdW9OLtl/xgRVtaFNRvb31ZD4+rgUOapGY4t4153Fp0jcOvGY9xdlwDEvWX5gSkPF50V8N8oZVr52aMRVqfRCdhZpB2MTTdrGdyK+HI39zuDJ8mTl0o4ujeGmAixK7TBmPjWoUk4y8ZNNUdMsyGopD/8fsWLKLUvr6o1YD/9KGgfwv8W4iV1PSLJ/PhwdYiYlOimZcms7y0BKcBd6TUrY8o0NyLZuTuXlSUZ/mSXw==" Mar 04 07:17:20 loe volumio[24165]: info: Plugin mpdemulation is not enabled Mar 04 07:17:20 loe volumio[24165]: info: Loading plugin "rest_api"... Mar 04 07:17:20 loe volumio[24165]: info: Loading plugin "websocket"... Mar 04 07:17:20 loe go-librespot[24255]: time="2026-03-04T07:17:20+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 07:17:20 loe volumio[24165]: info: Starting Socket.io Server version 1.7.4 Mar 04 07:17:20 loe volumio[24165]: info: Loading i18n strings for locale nl Mar 04 07:17:20 loe go-librespot[24255]: time="2026-03-04T07:17:20+01:00" level=debug msg="completed keyexchange" Mar 04 07:17:20 loe go-librespot[24255]: time="2026-03-04T07:17:20+01:00" level=debug msg="completed challenge" Mar 04 07:17:20 loe volumio[24165]: Updating browse sources language Mar 04 07:17:20 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 07:17:20 loe go-librespot[24255]: time="2026-03-04T07:17:20+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 07:17:20 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 07:17:20 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 07:17:20 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 07:17:20 loe volumio[24165]: info: CoreCommandRouter::initPlayerControls Mar 04 07:17:20 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:17:20 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:17:20 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:17:20 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:17:20 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:17:20 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:17:20 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:17:20 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:17:20 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 07:17:20 loe volumio[24165]: Express server listening on port 3000 Mar 04 07:17:20 loe volumio[24165]: [Metrics] WebUI: 11s 384.01ms Mar 04 07:17:20 loe volumio[24165]: info: CoreStateMachine::resetVolumioState Mar 04 07:17:20 loe volumio[24165]: info: CoreStateMachine::getcurrentVolume Mar 04 07:17:20 loe volumio[24165]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 07:17:20 loe volumio[24165]: info: Volumio Network Manager: Network status updated: 1 Mar 04 07:17:20 loe volumio[24262]: Forking 3 albumart workers Mar 04 07:17:21 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:17:21 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:17:21 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:17:21 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:17:21 loe volumio[24165]: info: Reloading queue from file Mar 04 07:17:21 loe volumio[24165]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Mar 04 07:17:21 loe volumio[24165]: info: VolumeController:: Volume=5 Mute =false Mar 04 07:17:21 loe volumio[24165]: info: CoreStateMachine::pushState Mar 04 07:17:21 loe volumio[24165]: info: CorePlayQueue::getTrack 0 Mar 04 07:17:21 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 07:17:21 loe volumio[24165]: info: CoreCommandRouter::volumioPushState Mar 04 07:17:21 loe volumio[24165]: info: CoreStateMachine::updateTrackBlock Mar 04 07:17:21 loe volumio[24165]: info: CorePlayQueue::getTrackBlock Mar 04 07:17:21 loe volumio[24165]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 07:17:21 loe volumio[24165]: info: CoreStateMachine::setRepeat false single undefined Mar 04 07:17:21 loe volumio[24165]: info: CoreStateMachine::pushState Mar 04 07:17:21 loe volumio[24165]: info: CorePlayQueue::getTrack 0 Mar 04 07:17:21 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 07:17:21 loe volumio[24165]: info: CoreCommandRouter::volumioPushState Mar 04 07:17:21 loe volumio[24165]: info: CoreStateMachine::setRandom undefined Mar 04 07:17:21 loe volumio[24165]: info: CoreStateMachine::pushState Mar 04 07:17:21 loe volumio[24165]: info: CorePlayQueue::getTrack 0 Mar 04 07:17:21 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 07:17:21 loe volumio[24165]: info: CoreCommandRouter::volumioPushState Mar 04 07:17:21 loe volumio[24165]: info: Setting Device type: Raspberry PI Mar 04 07:17:21 loe volumio[24165]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Mar 04 07:17:21 loe volumio[24165]: info: Received Get System Info Mar 04 07:17:21 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 07:17:21 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 07:17:21 loe volumio[24165]: info: Discovery: Getting this device information Mar 04 07:17:21 loe volumio[24165]: info: CoreCommandRouter::volumioGetState Mar 04 07:17:21 loe volumio[24165]: info: CorePlayQueue::getTrack 0 Mar 04 07:17:21 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 07:17:21 loe volumio[24165]: info: Completed loading Core Plugins Mar 04 07:17:21 loe volumio[24165]: info: Preparing to generate the ALSA configuration file Mar 04 07:17:21 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 04 07:17:21 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 04 07:17:21 loe volumio[24165]: info: Asound.conf file unchanged, so no further update is needed Mar 04 07:17:21 loe volumio[24165]: info: Output device has changed, restarting MPD Mar 04 07:17:21 loe volumio[24165]: info: Output device has changed, restarting Shairport Sync Mar 04 07:17:21 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:17:21 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:17:21 loe sudo[24317]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 07:17:21 loe sudo[24317]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:17:21 loe sudo[24317]: pam_unix(sudo:session): session closed for user root Mar 04 07:17:21 loe sudo[24319]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 07:17:21 loe sudo[24319]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:17:21 loe volumio[24165]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 07:17:21 loe volumio[24165]: info: ___________ START PLUGINS ___________ Mar 04 07:17:21 loe volumio[24165]: info: ControllerMpd::onStart: Initializing MPD Mar 04 07:17:21 loe volumio[24165]: info: Creating MPD Configuration file Mar 04 07:17:22 loe systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 04 07:17:22 loe sudo[24329]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 07:17:22 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 07:17:22 loe volumio[24165]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 07:17:22 loe sudo[24329]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:17:22 loe sudo[24327]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Mar 04 07:17:22 loe volumio[24165]: info: [1772605042121] CoreMusicLibrary::Adding element Media Servers Mar 04 07:17:22 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 07:17:22 loe sudo[24327]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:17:22 loe sudo[24329]: pam_unix(sudo:session): session closed for user root Mar 04 07:17:22 loe systemd[1]: mpd.service: Deactivated successfully. Mar 04 07:17:22 loe systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 04 07:17:22 loe systemd[1]: mpd.service: Consumed 6.777s CPU time. Mar 04 07:17:22 loe systemd[1]: mpd.socket: Deactivated successfully. Mar 04 07:17:22 loe systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 04 07:17:22 loe systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 04 07:17:22 loe volumio[24165]: info: UPNP Browser: Client initialized successfully Mar 04 07:17:22 loe sudo[24331]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 07:17:22 loe sudo[24331]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:17:22 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:17:22 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:17:22 loe systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 04 07:17:22 loe systemd[1]: Starting mpd.service - Music Player Daemon... Mar 04 07:17:22 loe volumio[24165]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 07:17:22 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:17:22 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:17:22 loe systemd[1]: mpd.service: Deactivated successfully. Mar 04 07:17:22 loe systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 04 07:17:22 loe systemd[1]: mpd.socket: Deactivated successfully. Mar 04 07:17:22 loe systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 04 07:17:22 loe systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 04 07:17:22 loe volumio[24165]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 07:17:22 loe volumio[24165]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 07:17:22 loe volumio[24165]: info: [1772605042475] CoreMusicLibrary::Adding element Last_100 Mar 04 07:17:22 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 07:17:22 loe volumio[24165]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 07:17:22 loe volumio[24165]: info: [1772605042496] CoreMusicLibrary::Adding element Webradio Mar 04 07:17:22 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 07:17:22 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 07:17:22 loe volumio[24165]: info: Initializing BBC Radios Mar 04 07:17:22 loe systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 04 07:17:22 loe systemd[1]: Starting mpd.service - Music Player Daemon... Mar 04 07:17:22 loe sudo[24327]: pam_unix(sudo:session): session closed for user root Mar 04 07:17:22 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 07:17:22 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:17:22 loe volumio[24165]: info: Creating Spotify config file Mar 04 07:17:22 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:17:23 loe sudo[24349]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 04 07:17:23 loe sudo[24349]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 04 07:17:23 loe sudo[24349]: pam_unix(sudo:session): session closed for user root Mar 04 07:17:23 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:17:23 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:17:23 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:17:23 loe volumio[24165]: info: Volumio Calling Home Mar 04 07:17:23 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Mar 04 07:17:23 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:17:23 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:17:23 loe go-librespot[24367]: go-librespot daemon starting... Mar 04 07:17:23 loe go-librespot[24370]: time="2026-03-04T07:17:23+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 07:17:24 loe volumio-remote-updater[714]: [2026-03-04 07:17:24] [connect] Successful connection Mar 04 07:17:24 loe volumio[24279]: Starting albumart workers Mar 04 07:17:24 loe volumio[24278]: Starting albumart workers Mar 04 07:17:24 loe volumio[24277]: Starting albumart workers Mar 04 07:17:24 loe go-librespot[24370]: time="2026-03-04T07:17:24+01:00" level=info msg="zeroconf server listening on port 32861" Mar 04 07:17:25 loe sudo[24391]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 04 07:17:25 loe sudo[24389]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 04 07:17:25 loe sudo[24391]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:17:25 loe sudo[24389]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:17:25 loe sudo[24391]: pam_unix(sudo:session): session closed for user root Mar 04 07:17:25 loe sudo[24389]: pam_unix(sudo:session): session closed for user root Mar 04 07:17:25 loe volumio[24165]: info: Discovery: adding 07fbb113-343c-4b34-af49-444dc3d8fb26 Mar 04 07:17:25 loe volumio[24165]: info: Discovery: Found device Loe Mar 04 07:17:25 loe volumio[24165]: info: CoreCommandRouter::volumioGetState Mar 04 07:17:25 loe volumio[24165]: info: CorePlayQueue::getTrack 0 Mar 04 07:17:25 loe volumio[24165]: info: Discovery: this is already registered, 07fbb113-343c-4b34-af49-444dc3d8fb26 Mar 04 07:17:25 loe volumio[24165]: info: Discovery: Found device Loe Mar 04 07:17:25 loe volumio[24165]: info: CoreCommandRouter::volumioGetState Mar 04 07:17:25 loe volumio[24165]: info: CorePlayQueue::getTrack 0 Mar 04 07:17:25 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:17:25 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:17:25 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:17:25 loe volumio[24165]: info: MPD Permissions set Mar 04 07:17:25 loe volumio[24165]: info: MPD Permissions set Mar 04 07:17:25 loe volumio[24165]: info: VolumeController:: Volume=5 Mute =false Mar 04 07:17:25 loe volumio[24165]: info: CoreStateMachine::pushState Mar 04 07:17:25 loe volumio[24165]: info: CorePlayQueue::getTrack 0 Mar 04 07:17:25 loe volumio[24165]: info: CoreCommandRouter::volumioPushState Mar 04 07:17:25 loe volumio-remote-updater[714]: [2026-03-04 07:17:25] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1772605044 101 Mar 04 07:17:25 loe volumio[24165]: 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 Mar 04 07:17:25 loe volumio[24165]: info: Spotify config file written Mar 04 07:17:25 loe sudo[24395]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 04 07:17:25 loe sudo[24395]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:17:25 loe systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 04 07:17:25 loe systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 04 07:17:25 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:17:25 loe volumio[24165]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Mar 04 07:17:25 loe volumio[24165]: info: Volumio called home Mar 04 07:17:25 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:17:25 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:17:25 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:17:25 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:17:25 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:17:25 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:17:25 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:17:25 loe go-librespot[24397]: go-librespot daemon starting... Mar 04 07:17:25 loe sudo[24395]: pam_unix(sudo:session): session closed for user root Mar 04 07:17:25 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:17:25 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:17:25 loe go-librespot[24398]: time="2026-03-04T07:17:25+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 07:17:25 loe go-librespot[24398]: time="2026-03-04T07:17:25+01:00" level=debug msg="app state loaded" Mar 04 07:17:25 loe go-librespot[24398]: time="2026-03-04T07:17:25+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 07:17:25 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:17:25 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:17:25 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:17:25 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:17:25 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:17:25 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:17:25 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:17:25 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:17:25 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:17:25 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:17:26 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:17:26 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 07:17:26 loe volumio[24165]: info: No need to fix Spotify hosts Mar 04 07:17:26 loe go-librespot[24398]: time="2026-03-04T07:17:26+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 07:17:26 loe go-librespot[24398]: time="2026-03-04T07:17:26+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 07:17:26 loe go-librespot[24398]: time="2026-03-04T07:17:26+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 07:17:26 loe go-librespot[24398]: time="2026-03-04T07:17:26+01:00" level=info msg="zeroconf server listening on port 38265" Mar 04 07:17:26 loe volumio[24165]: info: Starting Shairport Sync Mar 04 07:17:26 loe go-librespot[24398]: time="2026-03-04T07:17:26+01:00" level=debug msg="obtained new client token: AAAFUkSoR5L2pC3QoE7r45mO1h/780qAuOXdUxKv5iMGNo7KMrbTyir3/Z9xePzCppDjoDzzy+xi0kGP9j3sQq3WFJ0dX+b9CLqwjCwY4z1yWueOZng5gHSYzradavCFzDHBcvWDs04KFsKDGb43oAm1zfLJONlvNQVJ5LyDFEFc5f6yzp1RCDEzeP/JMPLEE2vcUbEoiIRKA7sE8yc1Rud+pfs0hj9ua4OaJIl3Fk9Aua07PL6wcJHDvQ==" Mar 04 07:17:26 loe volumio[24165]: info: Starting Shairport Sync Mar 04 07:17:26 loe volumio[24165]: info: Starting Shairport Sync Mar 04 07:17:26 loe go-librespot[24398]: time="2026-03-04T07:17:26+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 07:17:26 loe sudo[24431]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 07:17:26 loe sudo[24431]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:17:26 loe go-librespot[24398]: time="2026-03-04T07:17:26+01:00" level=debug msg="completed keyexchange" Mar 04 07:17:26 loe go-librespot[24398]: time="2026-03-04T07:17:26+01:00" level=debug msg="completed challenge" Mar 04 07:17:26 loe volumio[24165]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 04 07:17:26 loe sudo[24435]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 07:17:26 loe sudo[24435]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:17:26 loe go-librespot[24398]: time="2026-03-04T07:17:26+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 " Mar 04 07:17:26 loe sudo[24442]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 04 07:17:26 loe sudo[24442]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:17:26 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 07:17:26 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 07:17:26 loe sudo[24440]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 07:17:26 loe sudo[24440]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:17:27 loe systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 04 07:17:27 loe sudo[24442]: pam_unix(sudo:session): session closed for user root Mar 04 07:17:27 loe systemd[1]: shairport-sync.service: Deactivated successfully. Mar 04 07:17:27 loe systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 07:17:27 loe systemd[1]: shairport-sync.service: Consumed 2.156s CPU time. Mar 04 07:17:27 loe volumio[24165]: info: Upmpdcli Daemon Started Mar 04 07:17:27 loe volumio[24165]: info: CoreCommandRouter::volumioGetState Mar 04 07:17:27 loe volumio[24165]: info: CorePlayQueue::getTrack 0 Mar 04 07:17:27 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:17:27 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:17:27 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:17:27 loe systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 07:17:27 loe sudo[24435]: pam_unix(sudo:session): session closed for user root Mar 04 07:17:27 loe volumio[24165]: info: Shairport-Sync Started Mar 04 07:17:27 loe volumio[24165]: Error adding Membership: Error: addMembership EINVAL Mar 04 07:17:27 loe sudo[24431]: pam_unix(sudo:session): session closed for user root Mar 04 07:17:27 loe sudo[24440]: pam_unix(sudo:session): session closed for user root Mar 04 07:17:27 loe volumio[24165]: info: Shairport-Sync Started Mar 04 07:17:27 loe volumio[24165]: info: Shairport-Sync Started Mar 04 07:17:29 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:17:29 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:17:29 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:17:29 loe volumio[24165]: info: go-librespot daemon successfully initialized Mar 04 07:17:29 loe mpd[24361]: 2026-03-04T07:17:29 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 04 07:17:29 loe systemd[1]: Started mpd.service - Music Player Daemon. Mar 04 07:17:29 loe sudo[24319]: pam_unix(sudo:session): session closed for user root Mar 04 07:17:29 loe sudo[24331]: pam_unix(sudo:session): session closed for user root Mar 04 07:17:29 loe volumio[24165]: info: Completed starting Core Plugins Mar 04 07:17:29 loe volumio[24165]: info: ------------------------------------------- Mar 04 07:17:29 loe volumio[24165]: info: ----- MyVolumio plugins startup ---- Mar 04 07:17:29 loe volumio[24165]: info: ------------------------------------------- Mar 04 07:17:29 loe volumio[24165]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 04 07:17:29 loe volumio[24165]: error: MPD error: The expression evaluated to a falsy value: Mar 04 07:17:29 loe volumio[24165]: assert.ok(self.idling) Mar 04 07:17:29 loe volumio[24165]: error: The expression evaluated to a falsy value: Mar 04 07:17:29 loe volumio[24165]: assert.ok(self.idling) Mar 04 07:17:29 loe volumio[24165]: info: MPD running with PID24361 Mar 04 07:17:29 loe volumio[24165]: ,establishing connection Mar 04 07:17:29 loe volumio[24165]: error: updateQueue error: null Mar 04 07:17:29 loe volumio[24165]: error: updateQueue error: null Mar 04 07:17:30 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 04 07:17:30 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:17:30 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:17:30 loe go-librespot[24466]: go-librespot daemon starting... Mar 04 07:17:30 loe go-librespot[24467]: time="2026-03-04T07:17:30+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 07:17:30 loe go-librespot[24467]: time="2026-03-04T07:17:30+01:00" level=debug msg="app state loaded" Mar 04 07:17:30 loe go-librespot[24467]: time="2026-03-04T07:17:30+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 07:17:30 loe go-librespot[24467]: time="2026-03-04T07:17:30+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 07:17:30 loe go-librespot[24467]: time="2026-03-04T07:17:30+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 07:17:30 loe go-librespot[24467]: time="2026-03-04T07:17:30+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 07:17:30 loe go-librespot[24467]: time="2026-03-04T07:17:30+01:00" level=info msg="zeroconf server listening on port 36313" Mar 04 07:17:30 loe go-librespot[24467]: time="2026-03-04T07:17:30+01:00" level=debug msg="obtained new client token: AADR5YjWjwoF8jVAs1U8lvtcjLExMI223zV+kmwvi4s9Gc5F94jqCLWoG0ZSIezxAwXL7FM8wFDUJfFL6TKa3qyeJYCMExgKC2joYI0lS849LrGI798oK/PMkNUL8Mat7bNU8e1kKu2gO4+lBFKrcdj0FRa0dj5JJNBDWY8a/cvtRTydr5M2o2/rlXItwxXpmsfmPr+Ykc8XlszfslZPB9wvRIquYwv00Y603licy3LqCToiOdHX9A7VMQ==" Mar 04 07:17:30 loe go-librespot[24467]: time="2026-03-04T07:17:30+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 07:17:30 loe go-librespot[24467]: time="2026-03-04T07:17:30+01:00" level=debug msg="completed keyexchange" Mar 04 07:17:30 loe go-librespot[24467]: time="2026-03-04T07:17:30+01:00" level=debug msg="completed challenge" Mar 04 07:17:30 loe go-librespot[24467]: time="2026-03-04T07:17:30+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 " Mar 04 07:17:30 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 07:17:30 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 07:17:31 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:17:31 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:17:31 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:17:32 loe volumio[24165]: info: Initializing connection to go-librespot Websocket Mar 04 07:17:32 loe volumio[24165]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 07:17:33 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:17:33 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:17:33 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:17:33 loe kernel: hwmon hwmon1: Voltage normalised Mar 04 07:17:34 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 04 07:17:34 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:17:34 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:17:34 loe go-librespot[24475]: go-librespot daemon starting... Mar 04 07:17:34 loe go-librespot[24490]: time="2026-03-04T07:17:34+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 07:17:34 loe go-librespot[24490]: time="2026-03-04T07:17:34+01:00" level=debug msg="app state loaded" Mar 04 07:17:34 loe go-librespot[24490]: time="2026-03-04T07:17:34+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 07:17:34 loe go-librespot[24490]: time="2026-03-04T07:17:34+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 07:17:34 loe go-librespot[24490]: time="2026-03-04T07:17:34+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 04 07:17:34 loe go-librespot[24490]: time="2026-03-04T07:17:34+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 04 07:17:34 loe go-librespot[24490]: time="2026-03-04T07:17:34+01:00" level=info msg="zeroconf server listening on port 39785" Mar 04 07:17:34 loe go-librespot[24490]: time="2026-03-04T07:17:34+01:00" level=debug msg="obtained new client token: AABj0pEJdLuUmzxyxeiQdU316TbLkzrs7D5f1nRatZKpNBfxc3A2EjnwTUPIlqq1WBAUtZM7D+63rWz5n+zYt4FBzo7KKxB9M6q5rmtnm/M104kvm94eZz5NSwbdtfQ0t2Bc/zSTt6YgSkzMfIEZdw9d+W2bI2XqDKVy4PGL4T7o/bGWHhmeg6Wp7aANGmFKZWzLIRhaOcSJj9zA7+O9Ga9IFLA/gJys93p+wbdaYDGokv8y1OCk94AZKQ==" Mar 04 07:17:34 loe go-librespot[24490]: time="2026-03-04T07:17:34+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 07:17:34 loe volumio[24165]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 04 07:17:34 loe go-librespot[24490]: time="2026-03-04T07:17:34+01:00" level=debug msg="completed keyexchange" Mar 04 07:17:34 loe go-librespot[24490]: time="2026-03-04T07:17:34+01:00" level=debug msg="completed challenge" Mar 04 07:17:34 loe go-librespot[24490]: time="2026-03-04T07:17:34+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 " Mar 04 07:17:34 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 07:17:34 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 07:17:35 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:17:35 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:17:35 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:17:35 loe kernel: hwmon hwmon1: Undervoltage detected! Mar 04 07:17:35 loe volumio[24165]: info: Initializing connection to go-librespot Websocket Mar 04 07:17:35 loe volumio[24165]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 07:17:37 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:17:37 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:17:37 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:17:38 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 04 07:17:38 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:17:38 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:17:38 loe go-librespot[24498]: go-librespot daemon starting... Mar 04 07:17:38 loe go-librespot[24499]: time="2026-03-04T07:17:38+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 07:17:38 loe go-librespot[24499]: time="2026-03-04T07:17:38+01:00" level=debug msg="app state loaded" Mar 04 07:17:38 loe go-librespot[24499]: time="2026-03-04T07:17:38+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 07:17:38 loe volumio[24165]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 04 07:17:38 loe volumio[24165]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 04 07:17:38 loe volumio[24165]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 04 07:17:38 loe volumio[24165]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 04 07:17:38 loe volumio[24165]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 04 07:17:38 loe volumio[24165]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 04 07:17:38 loe volumio[24165]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 04 07:17:38 loe volumio[24165]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 04 07:17:38 loe volumio[24165]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 04 07:17:38 loe volumio[24165]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 04 07:17:38 loe volumio[24165]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 04 07:17:38 loe volumio[24165]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 04 07:17:38 loe volumio[24165]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 04 07:17:38 loe volumio[24165]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 04 07:17:38 loe volumio[24165]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 04 07:17:38 loe volumio[24165]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 04 07:17:38 loe volumio[24165]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 04 07:17:38 loe volumio[24165]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 04 07:17:38 loe volumio[24165]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 04 07:17:38 loe volumio[24165]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 04 07:17:38 loe volumio[24165]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 04 07:17:38 loe volumio[24165]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 04 07:17:38 loe volumio[24165]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 04 07:17:38 loe volumio[24165]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 04 07:17:38 loe volumio[24165]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 04 07:17:38 loe volumio[24165]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 04 07:17:38 loe volumio[24165]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 04 07:17:38 loe volumio[24165]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 04 07:17:38 loe volumio[24165]: info: Adding plugin bluetooth to MyMusic Plugins Mar 04 07:17:38 loe volumio[24165]: info: Adding plugin multiroom to MyMusic Plugins Mar 04 07:17:38 loe volumio[24165]: info: Adding plugin metavolumio to MyMusic Plugins Mar 04 07:17:38 loe volumio[24165]: info: Adding plugin cd_controller to MyMusic Plugins Mar 04 07:17:38 loe volumio[24165]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 04 07:17:38 loe volumio[24165]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 04 07:17:38 loe volumio[24165]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 04 07:17:38 loe volumio[24165]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 04 07:17:38 loe go-librespot[24499]: time="2026-03-04T07:17:38+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 07:17:38 loe go-librespot[24499]: time="2026-03-04T07:17:38+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 07:17:38 loe go-librespot[24499]: time="2026-03-04T07:17:38+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 07:17:38 loe go-librespot[24499]: time="2026-03-04T07:17:38+01:00" level=info msg="zeroconf server listening on port 45011" Mar 04 07:17:38 loe go-librespot[24499]: time="2026-03-04T07:17:38+01:00" level=debug msg="obtained new client token: AADkuf38LNs0IMkC4d8yCiob911dX4t4aeO3okAufT0Pw/PQ3NvyjCTTWs9VQtkhkvwCvgw4w7aEH3AfXZUosn5nDMQ3uNE/00k54+uAZnEsWvQWD9j4IJpYuIOBllczGlKFozG4Af1rclUrDe8gGCuDwA1KYbu2/icAM+l7bhtwuHIpdtx77kIQ4qMKtxO9KPaURXINrVKgJN1zrnEUHSD5FQKwYgRrAalQHGT3TGxMeqGnQlqPI13wPg==" Mar 04 07:17:38 loe go-librespot[24499]: time="2026-03-04T07:17:38+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 07:17:38 loe go-librespot[24499]: time="2026-03-04T07:17:38+01:00" level=debug msg="completed keyexchange" Mar 04 07:17:38 loe go-librespot[24499]: time="2026-03-04T07:17:38+01:00" level=debug msg="completed challenge" Mar 04 07:17:38 loe go-librespot[24499]: time="2026-03-04T07:17:38+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 " Mar 04 07:17:38 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 07:17:38 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 07:17:39 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:17:39 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:17:39 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:17:40 loe volumio[24165]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 04 07:17:40 loe volumio[24165]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 04 07:17:40 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:17:40 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:17:40 loe volumio[24165]: info: Starting MyVolumio Remote Streaming Endpoints Mar 04 07:17:40 loe volumio[24165]: info: MyVolumio login type: Token Mar 04 07:17:40 loe volumio[24165]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 04 07:17:40 loe volumio[24165]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 04 07:17:41 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:17:41 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:17:41 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:17:41 loe volumio[24165]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 04 07:17:42 loe volumio[24165]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 04 07:17:42 loe volumio[24165]: info: Streaming services startup Mar 04 07:17:42 loe volumio[24165]: info: Starting Streaming Daemon Mar 04 07:17:42 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 04 07:17:42 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:17:42 loe sudo[24507]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 04 07:17:42 loe sudo[24507]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:17:42 loe volumio[24165]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 04 07:17:42 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:17:42 loe go-librespot[24512]: go-librespot daemon starting... Mar 04 07:17:42 loe sudo[24507]: pam_unix(sudo:session): session closed for user root Mar 04 07:17:42 loe go-librespot[24514]: time="2026-03-04T07:17:42+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 07:17:42 loe go-librespot[24514]: time="2026-03-04T07:17:42+01:00" level=debug msg="app state loaded" Mar 04 07:17:42 loe volumio[24165]: info: Initializing connection to go-librespot Websocket Mar 04 07:17:42 loe go-librespot[24514]: time="2026-03-04T07:17:42+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 07:17:42 loe volumio[24165]: error: Cannot start Volumio Streaming Daemon Mar 04 07:17:42 loe volumio[24165]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 04 07:17:42 loe volumio[24165]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 04 07:17:42 loe go-librespot[24514]: time="2026-03-04T07:17:42+01:00" level=debug msg="new websocket client" Mar 04 07:17:42 loe volumio[24165]: info: Connection to go-librespot Websocket established Mar 04 07:17:42 loe go-librespot[24514]: time="2026-03-04T07:17:42+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 07:17:42 loe go-librespot[24514]: time="2026-03-04T07:17:42+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 04 07:17:42 loe go-librespot[24514]: time="2026-03-04T07:17:42+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 04 07:17:42 loe go-librespot[24514]: time="2026-03-04T07:17:42+01:00" level=info msg="zeroconf server listening on port 35187" Mar 04 07:17:42 loe go-librespot[24514]: time="2026-03-04T07:17:42+01:00" level=debug msg="obtained new client token: AAANiy5kzXg15qLqntymyUsplu0Qa2nw9+uhCthuGAmKBl1qml3TF1rGTbiSBEr6z8nvvSg8sV0X/m0lONDm46lTEUvDwEYPeep654wNyDmDnD+SpV2+DLZ94k+Gl8jxb9zKEod62vRYVNppN0Tb5ASVB10CpyWN/eu+SyHoIqiRMB0dbp6U+Y3jvsxVEa1Zhl/13gV/DgEGJVe7qeXmk22ek9HhMTqgX+CZad+HByHNR1ZN++8JsuxRfQ==" Mar 04 07:17:42 loe go-librespot[24514]: time="2026-03-04T07:17:42+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 07:17:42 loe volumio[24165]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 04 07:17:42 loe go-librespot[24514]: time="2026-03-04T07:17:42+01:00" level=debug msg="completed keyexchange" Mar 04 07:17:42 loe go-librespot[24514]: time="2026-03-04T07:17:42+01:00" level=debug msg="completed challenge" Mar 04 07:17:42 loe go-librespot[24514]: time="2026-03-04T07:17:42+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 " Mar 04 07:17:42 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 07:17:42 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 07:17:42 loe volumio[24165]: info: Connection to go-librespot Websocket closed Mar 04 07:17:43 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:17:43 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:17:43 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:17:43 loe volumio[24165]: info: MyVolumio token set successfully Mar 04 07:17:43 loe volumio[24165]: info: MYVOLUMIO: Adding device Mar 04 07:17:43 loe volumio[24165]: info: MYVOLUMIO: Evaluating Server Mar 04 07:17:43 loe volumio[24165]: info: MyVolumio Plan changed: premium Mar 04 07:17:43 loe volumio[24165]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Mar 04 07:17:43 loe volumio[24165]: info: Removing browser output: myVolumio user plan is not superstar Mar 04 07:17:43 loe volumio[24165]: info: Removing audio output: Mar 04 07:17:43 loe volumio[24165]: info: MYVOLUMIO: Adding device Mar 04 07:17:43 loe volumio[24165]: info: MYVOLUMIO: Evaluating Server Mar 04 07:17:43 loe volumio[24165]: info: Remote config written successfully Mar 04 07:17:43 loe volumio[24165]: info: Starting Tunnel 1 Mar 04 07:17:43 loe volumio[24165]: info: Starting Tunnel Connection Checker Mar 04 07:17:43 loe volumio[24165]: info: Completed starting MyVolumio Plugin Mar 04 07:17:44 loe volumio[24165]: info: MYVolumio Device enabled Mar 04 07:17:44 loe volumio[24165]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Mar 04 07:17:44 loe volumio[24165]: info: MyVolumio status changed Mar 04 07:17:44 loe volumio[24165]: info: Streaming services startup Mar 04 07:17:44 loe volumio[24165]: info: Starting Streaming Daemon Mar 04 07:17:44 loe sudo[24574]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 04 07:17:44 loe sudo[24574]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:17:44 loe volumio[24165]: info: Setting Geolocation for MyVolumio to eu8 Mar 04 07:17:44 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:17:44 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:17:44 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:17:44 loe sudo[24574]: pam_unix(sudo:session): session closed for user root Mar 04 07:17:44 loe volumio[24165]: error: Cannot start Volumio Streaming Daemon Mar 04 07:17:44 loe volumio[24165]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 04 07:17:44 loe volumio[24165]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 04 07:17:44 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Mar 04 07:17:44 loe volumio[24165]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Mar 04 07:17:44 loe volumio[24165]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Mar 04 07:17:44 loe volumio[24165]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Mar 04 07:17:45 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:17:45 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:17:45 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:17:46 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Mar 04 07:17:46 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:17:46 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 07:17:46 loe go-librespot[24576]: go-librespot daemon starting... Mar 04 07:17:46 loe go-librespot[24577]: time="2026-03-04T07:17:46+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 07:17:46 loe go-librespot[24577]: time="2026-03-04T07:17:46+01:00" level=debug msg="app state loaded" Mar 04 07:17:46 loe go-librespot[24577]: time="2026-03-04T07:17:46+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 07:17:46 loe go-librespot[24577]: time="2026-03-04T07:17:46+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 07:17:46 loe go-librespot[24577]: time="2026-03-04T07:17:46+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 04 07:17:46 loe go-librespot[24577]: time="2026-03-04T07:17:46+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 04 07:17:46 loe go-librespot[24577]: time="2026-03-04T07:17:46+01:00" level=info msg="zeroconf server listening on port 45059" Mar 04 07:17:46 loe go-librespot[24577]: time="2026-03-04T07:17:46+01:00" level=debug msg="obtained new client token: AABUgWIHjM/HOVY8NQQ1/77Mi6x/LiekElYy8FPHtJBMt/L49/eO/EXzB82kbk5giMczrXBjvOTgyfhQLAsDWAlmm9EMCPH4YC/jbWKi+tcB++ZkWCKOptJQdbtmO6tDw2ISXVr6x/O1ZLyZvTQYQ9O1WaTn9flu90d0i4oIOb5ZGJ0FJ5IWC0sfWAg6dYxL3wHBnkuIPZ+l9aSTGCntxtW/SBv1LGsGHirqHwPLAJ8zYWejKoly9D8J0A==" Mar 04 07:17:46 loe go-librespot[24577]: time="2026-03-04T07:17:46+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 07:17:46 loe go-librespot[24577]: time="2026-03-04T07:17:46+01:00" level=debug msg="completed keyexchange" Mar 04 07:17:46 loe go-librespot[24577]: time="2026-03-04T07:17:46+01:00" level=debug msg="completed challenge" Mar 04 07:17:46 loe go-librespot[24577]: time="2026-03-04T07:17:46+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 " Mar 04 07:17:46 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 07:17:46 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 07:17:47 loe volumio[24165]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Mar 04 07:17:47 loe sudo[24586]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Mar 04 07:17:47 loe sudo[24586]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:17:47 loe sudo[24586]: pam_unix(sudo:session): session closed for user root Mar 04 07:17:47 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:17:47 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:17:47 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:17:47 loe volumio[24165]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Mar 04 07:17:47 loe volumio[24165]: info: MRS: MultiRoom plugin initialized Mar 04 07:17:47 loe volumio[24165]: info: MRS: STOPPING SNAPCLIENT Mar 04 07:17:47 loe volumio[24165]: info: MRS: Snap server stop Mar 04 07:17:47 loe volumio[24165]: info: MRS: STOPPING volumioStreaming Mar 04 07:17:47 loe sudo[24603]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Mar 04 07:17:47 loe sudo[24603]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:17:47 loe volumio[24165]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Mar 04 07:17:47 loe sudo[24605]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Mar 04 07:17:47 loe sudo[24605]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:17:47 loe sudo[24607]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Mar 04 07:17:47 loe sudo[24607]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:17:47 loe volumio[24165]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Mar 04 07:17:47 loe sudo[24610]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Mar 04 07:17:47 loe sudo[24610]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 07:17:47 loe volumio[24165]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Mar 04 07:17:47 loe sudo[24610]: pam_unix(sudo:session): session closed for user root Mar 04 07:17:47 loe volumio[24165]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Mar 04 07:17:47 loe volumio[24165]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Mar 04 07:17:47 loe volumio[24165]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Mar 04 07:17:47 loe volumio[24165]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Mar 04 07:17:47 loe volumio[24165]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Mar 04 07:17:47 loe volumio[24165]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Mar 04 07:17:47 loe sudo[24603]: pam_unix(sudo:session): session closed for user root Mar 04 07:17:47 loe volumio[24165]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Mar 04 07:17:47 loe sudo[24607]: pam_unix(sudo:session): session closed for user root Mar 04 07:17:47 loe sudo[24605]: pam_unix(sudo:session): session closed for user root Mar 04 07:17:47 loe volumio[24165]: info: Preparing to generate the ALSA configuration file Mar 04 07:17:47 loe volumio[24165]: info: Getting Spotify volume Mar 04 07:17:47 loe volumio[24165]: info: Initializing connection to go-librespot Websocket Mar 04 07:17:47 loe volumio[24165]: info: Updating MyVolumio device info Mar 04 07:17:47 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:17:47 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:17:47 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:17:47 loe volumio[24165]: info: Setting Geolocation for MyVolumio to eu8 Mar 04 07:17:47 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:17:47 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:17:47 loe volumio[24165]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 07:17:47 loe volumio[24165]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Mar 04 07:17:47 loe volumio[24165]: info: Reading ALSA contributions from plugins. Mar 04 07:17:47 loe volumio[24165]: info: Successfully Added MyVolumio device Mar 04 07:17:47 loe volumio[24165]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 07:17:47 loe volumio[24165]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 07:17:47 loe volumio[24165]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 04 07:17:47 loe volumio[24165]: errno: -111, Mar 04 07:17:47 loe volumio[24165]: code: 'ECONNREFUSED', Mar 04 07:17:47 loe volumio[24165]: syscall: 'connect', Mar 04 07:17:47 loe volumio[24165]: address: '127.0.0.1', Mar 04 07:17:47 loe volumio[24165]: port: 9879, Mar 04 07:17:47 loe volumio[24165]: response: undefined Mar 04 07:17:47 loe volumio[24165]: } Mar 04 07:17:47 loe volumio[24165]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 07:17:49 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 07:17:49 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 07:17:49 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 07:17:49 loe sudo[24629]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-04 07:16' Mar 04 07:17:49 loe sudo[24629]: 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="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"