Jan 27 15:42:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:42:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:42:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:42:01 volumio volumio[13332]: info: Initializing connection to go-librespot Websocket Jan 27 15:42:01 volumio volumio[13332]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 15:42:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:42:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:42:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:42:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 27 15:42:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:42:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:42:02 volumio go-librespot[13662]: go-librespot daemon starting... Jan 27 15:42:02 volumio go-librespot[13663]: time="2026-01-27T15:42:02+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 15:42:02 volumio go-librespot[13663]: time="2026-01-27T15:42:02+07:00" level=debug msg="app state loaded" Jan 27 15:42:02 volumio go-librespot[13663]: time="2026-01-27T15:42:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 15:42:03 volumio go-librespot[13663]: time="2026-01-27T15:42:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 15:42:03 volumio go-librespot[13663]: time="2026-01-27T15:42:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 15:42:03 volumio go-librespot[13663]: time="2026-01-27T15:42:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 15:42:03 volumio go-librespot[13663]: time="2026-01-27T15:42:03+07:00" level=info msg="zeroconf server listening on port 44007" Jan 27 15:42:03 volumio go-librespot[13663]: time="2026-01-27T15:42:03+07:00" level=debug msg="obtained new client token: AADD+ppze+fJ6cf/JIYZyURHnidB6U7FUjLRoZqdhZHR/J+nHAHIwNVFKlDW7oRd4tvUNbGkee+bMRnNodOLIPHJqoSKdw4YhbzMTy1ENM4sv3zPG4v3vbpLzFnRCgKKnGRQ6+EtZX1kIFBTUs5/r2sCdSi5sW+REWwVx4iEaJt42geP58SBedQ3hz28FliBNT0S9+SSJgeFLxAnbcUQSiLQcOGdaXDlqqI1TL0P7UAJxlHgk0i+kyMQoFI=" Jan 27 15:42:03 volumio go-librespot[13663]: time="2026-01-27T15:42:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 15:42:03 volumio go-librespot[13663]: time="2026-01-27T15:42:03+07:00" level=debug msg="completed keyexchange" Jan 27 15:42:03 volumio go-librespot[13663]: time="2026-01-27T15:42:03+07:00" level=debug msg="completed challenge" Jan 27 15:42:04 volumio go-librespot[13663]: time="2026-01-27T15:42:04+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 15:42:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 15:42:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 15:42:04 volumio volumio[13332]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 27 15:42:04 volumio volumio[13332]: info: Initializing connection to go-librespot Websocket Jan 27 15:42:04 volumio volumio[13332]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 15:42:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:42:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:42:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:42:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:42:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:42:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:42:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 27 15:42:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:42:07 volumio volumio[13332]: info: Initializing connection to go-librespot Websocket Jan 27 15:42:07 volumio volumio[13332]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 15:42:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:42:07 volumio go-librespot[13671]: go-librespot daemon starting... Jan 27 15:42:07 volumio go-librespot[13672]: time="2026-01-27T15:42:07+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 15:42:07 volumio go-librespot[13672]: time="2026-01-27T15:42:07+07:00" level=debug msg="app state loaded" Jan 27 15:42:07 volumio go-librespot[13672]: time="2026-01-27T15:42:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 15:42:07 volumio go-librespot[13672]: time="2026-01-27T15:42:07+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 15:42:07 volumio go-librespot[13672]: time="2026-01-27T15:42:07+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 15:42:07 volumio go-librespot[13672]: time="2026-01-27T15:42:07+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 15:42:07 volumio go-librespot[13672]: time="2026-01-27T15:42:07+07:00" level=info msg="zeroconf server listening on port 41221" Jan 27 15:42:08 volumio go-librespot[13672]: time="2026-01-27T15:42:08+07:00" level=debug msg="obtained new client token: AAAhH5WBjb8zL1xn3mHTPGRTR4oAToKkyPbvH+dYpdrJL/Kzo5uz9gO1la14FwBUTcfsxKAXnVBMFtc7lt23JV4FQK9uHKOH0JSCBHcMv0iSCF6RKCVJs5uaE80K42QswX0wMOiIK09Cjmiq7BKcrchgbjBXaaS/UExUA0myIBnk580yQKdGLuDTfcQ4/9BfVdG7VleLtA7Qrvkf+DrWh4ARGjmRfIThhmdaZPmZY/wwQzCIKHIiHUYy" Jan 27 15:42:08 volumio go-librespot[13672]: time="2026-01-27T15:42:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 15:42:08 volumio go-librespot[13672]: time="2026-01-27T15:42:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 15:42:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 15:42:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 15:42:08 volumio volumio[13332]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 27 15:42:08 volumio volumio[13332]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 27 15:42:08 volumio volumio[13332]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 27 15:42:08 volumio volumio[13332]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 27 15:42:08 volumio volumio[13332]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 27 15:42:08 volumio volumio[13332]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 27 15:42:08 volumio volumio[13332]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 27 15:42:08 volumio volumio[13332]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 27 15:42:08 volumio volumio[13332]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 27 15:42:08 volumio volumio[13332]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 27 15:42:08 volumio volumio[13332]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 27 15:42:08 volumio volumio[13332]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 27 15:42:08 volumio volumio[13332]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 27 15:42:08 volumio volumio[13332]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 27 15:42:08 volumio volumio[13332]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 27 15:42:08 volumio volumio[13332]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 27 15:42:08 volumio volumio[13332]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 27 15:42:08 volumio volumio[13332]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 27 15:42:08 volumio volumio[13332]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 27 15:42:08 volumio volumio[13332]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 27 15:42:08 volumio volumio[13332]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 27 15:42:08 volumio volumio[13332]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 27 15:42:08 volumio volumio[13332]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 27 15:42:08 volumio volumio[13332]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 27 15:42:08 volumio volumio[13332]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 27 15:42:08 volumio volumio[13332]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 27 15:42:08 volumio volumio[13332]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 27 15:42:08 volumio volumio[13332]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 27 15:42:08 volumio volumio[13332]: info: Adding plugin bluetooth to MyMusic Plugins Jan 27 15:42:08 volumio volumio[13332]: info: Adding plugin multiroom to MyMusic Plugins Jan 27 15:42:08 volumio volumio[13332]: info: Adding plugin metavolumio to MyMusic Plugins Jan 27 15:42:08 volumio volumio[13332]: info: Adding plugin cd_controller to MyMusic Plugins Jan 27 15:42:08 volumio volumio[13332]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 27 15:42:08 volumio volumio[13332]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 27 15:42:08 volumio volumio[13332]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 27 15:42:08 volumio volumio[13332]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 27 15:42:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:42:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:42:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:42:10 volumio volumio[13332]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 27 15:42:10 volumio volumio[13332]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 27 15:42:10 volumio volumio[13332]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:42:10 volumio volumio[13332]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:42:10 volumio volumio[13332]: info: Starting MyVolumio Remote Streaming Endpoints Jan 27 15:42:10 volumio volumio[13332]: info: MyVolumio login type: Token Jan 27 15:42:10 volumio volumio[13332]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 27 15:42:10 volumio volumio[13332]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 27 15:42:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:42:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:42:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:42:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 27 15:42:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:42:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:42:11 volumio go-librespot[13695]: go-librespot daemon starting... Jan 27 15:42:11 volumio go-librespot[13696]: time="2026-01-27T15:42:11+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 15:42:11 volumio go-librespot[13696]: time="2026-01-27T15:42:11+07:00" level=debug msg="app state loaded" Jan 27 15:42:11 volumio go-librespot[13696]: time="2026-01-27T15:42:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 15:42:12 volumio go-librespot[13696]: time="2026-01-27T15:42:12+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 15:42:12 volumio go-librespot[13696]: time="2026-01-27T15:42:12+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 27 15:42:12 volumio go-librespot[13696]: time="2026-01-27T15:42:12+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 27 15:42:12 volumio go-librespot[13696]: time="2026-01-27T15:42:12+07:00" level=info msg="zeroconf server listening on port 46107" Jan 27 15:42:12 volumio volumio[13332]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 27 15:42:12 volumio volumio[13332]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 27 15:42:12 volumio volumio[13332]: info: Streaming services startup Jan 27 15:42:12 volumio volumio[13332]: info: Starting Streaming Daemon Jan 27 15:42:12 volumio sudo[13704]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 15:42:12 volumio sudo[13704]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:42:12 volumio volumio[13332]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 27 15:42:12 volumio sudo[13704]: pam_unix(sudo:session): session closed for user root Jan 27 15:42:12 volumio volumio[13332]: info: Initializing connection to go-librespot Websocket Jan 27 15:42:12 volumio go-librespot[13696]: time="2026-01-27T15:42:12+07:00" level=debug msg="obtained new client token: AACjneF0OcxTI3mvXWLMeezWryGmNx15U1agOOV5fFe1pKMslWcSnd+/uoMUyLUb3BpIuhHU+aAfBd4PWjyRdee1dT9iLRY9XMGgoOnLtEv8GDlh2UAuTeWSqM2STvKJgr+rzGirv9CI0AovjWb+jGUzlt/Dpj1bb5TOa6dQmyL3zK6U/3ZGagU9xJEZ24SFF3Kr4OTofJrkKDAdvI3LDiA7olG37X1WIfo6mtwpQG5UL4hJgWG1BlYHo9o=" Jan 27 15:42:12 volumio volumio[13332]: error: Cannot start Volumio Streaming Daemon Jan 27 15:42:12 volumio volumio[13332]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 15:42:12 volumio volumio[13332]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 15:42:12 volumio go-librespot[13696]: time="2026-01-27T15:42:12+07:00" level=debug msg="new websocket client" Jan 27 15:42:12 volumio volumio[13332]: info: Connection to go-librespot Websocket established Jan 27 15:42:12 volumio go-librespot[13696]: time="2026-01-27T15:42:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 15:42:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:42:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:42:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:42:12 volumio go-librespot[13696]: time="2026-01-27T15:42:12+07:00" level=debug msg="completed keyexchange" Jan 27 15:42:12 volumio go-librespot[13696]: time="2026-01-27T15:42:12+07:00" level=debug msg="completed challenge" Jan 27 15:42:12 volumio go-librespot[13696]: time="2026-01-27T15:42:12+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 15:42:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 15:42:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 15:42:12 volumio volumio[13332]: info: Connection to go-librespot Websocket closed Jan 27 15:42:13 volumio volumio[13332]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 27 15:42:14 volumio volumio[13332]: info: MyVolumio token set successfully Jan 27 15:42:14 volumio volumio[13332]: info: MYVOLUMIO: Adding device Jan 27 15:42:14 volumio volumio[13332]: info: MYVOLUMIO: Evaluating Server Jan 27 15:42:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:42:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:42:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:42:15 volumio volumio[13332]: info: MyVolumio status changed Jan 27 15:42:15 volumio volumio[13332]: info: Streaming services startup Jan 27 15:42:15 volumio volumio[13332]: info: Starting Streaming Daemon Jan 27 15:42:15 volumio volumio[13332]: info: Removing browser output: myVolumio user plan is not superstar Jan 27 15:42:15 volumio volumio[13332]: info: Removing audio output: Jan 27 15:42:15 volumio volumio[13332]: info: Stoppping Tunnel 1 Jan 27 15:42:15 volumio sudo[13732]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 15:42:15 volumio sudo[13732]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:42:15 volumio sudo[13735]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 27 15:42:15 volumio sudo[13735]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:42:15 volumio sudo[13732]: pam_unix(sudo:session): session closed for user root Jan 27 15:42:15 volumio volumio[13332]: error: Cannot start Volumio Streaming Daemon Jan 27 15:42:15 volumio volumio[13332]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 15:42:15 volumio volumio[13332]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 15:42:15 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 15:42:15 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 15:42:15 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 15:42:15 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 15:42:15 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 15:42:15 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 15:42:15 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 15:42:15 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 15:42:15 volumio sudo[13735]: pam_unix(sudo:session): session closed for user root Jan 27 15:42:15 volumio volumio[13332]: info: Remote SSH Stopped Jan 27 15:42:15 volumio volumio[13332]: info: Setting Geolocation for MyVolumio to as1 Jan 27 15:42:15 volumio volumio[13332]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:42:15 volumio volumio[13332]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:42:15 volumio volumio[13332]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:42:15 volumio volumio[13332]: info: Getting Spotify volume Jan 27 15:42:15 volumio volumio[13332]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 15:42:15 volumio volumio[13332]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 15:42:15 volumio volumio[13332]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 27 15:42:15 volumio volumio[13332]: errno: -111, Jan 27 15:42:15 volumio volumio[13332]: code: 'ECONNREFUSED', Jan 27 15:42:15 volumio volumio[13332]: syscall: 'connect', Jan 27 15:42:15 volumio volumio[13332]: address: '127.0.0.1', Jan 27 15:42:15 volumio volumio[13332]: port: 9879, Jan 27 15:42:15 volumio volumio[13332]: response: undefined Jan 27 15:42:15 volumio volumio[13332]: } Jan 27 15:42:15 volumio volumio[13332]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 15:42:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 27 15:42:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:42:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:42:16 volumio go-librespot[13749]: go-librespot daemon starting... Jan 27 15:42:16 volumio go-librespot[13750]: time="2026-01-27T15:42:16+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 15:42:16 volumio go-librespot[13750]: time="2026-01-27T15:42:16+07:00" level=debug msg="app state loaded" Jan 27 15:42:16 volumio go-librespot[13750]: time="2026-01-27T15:42:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 15:42:16 volumio go-librespot[13750]: time="2026-01-27T15:42:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 15:42:16 volumio go-librespot[13750]: time="2026-01-27T15:42:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 15:42:16 volumio go-librespot[13750]: time="2026-01-27T15:42:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 15:42:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:42:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:42:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:42:16 volumio go-librespot[13750]: time="2026-01-27T15:42:16+07:00" level=info msg="zeroconf server listening on port 45829" Jan 27 15:42:16 volumio go-librespot[13750]: time="2026-01-27T15:42:16+07:00" level=debug msg="obtained new client token: AABSJh66yYzXlNSSVhOIufy1eFcqPm/a3ugP0v7kH4UXTfigJX/9P89wvmoFoUVtqypXmts9shgQm6t9+CJZLTXi2mC1AuriC7GFYj/VaZnT+5UOZuZkYAsURG7QmtW8vvfmWk/6nAxSL4Ry2lC4yUQB1ZM4jm3e0SpDaWl3EzrsMEBddJkUKSftWhEWmsC0uUOqlivskSJZsy0Qf/hBR/ZGJv/8+0gUOqFKCBqbSHO5ke4+BUbXSMRsbSo=" Jan 27 15:42:17 volumio go-librespot[13750]: time="2026-01-27T15:42:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 15:42:17 volumio sudo[13761]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 15:41' Jan 27 15:42:17 volumio sudo[13761]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:42:17 volumio go-librespot[13750]: time="2026-01-27T15:42:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 15:42:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 15:42:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 15:42:17 volumio sudo[13761]: pam_unix(sudo:session): session closed for user root Jan 27 15:42:17 volumio volumio-remote-updater[628]: [2026-01-27 15:42:17] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 27 15:42:17 volumio volumio-remote-updater[628]: [2026-01-27 15:42:17] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 27 15:42:17 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 27 15:42:17 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 27 15:42:17 volumio systemd[1]: volumio.service: Consumed 1min 13.771s CPU time. Jan 27 15:42:17 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 15:42:17 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8761. Jan 27 15:42:17 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 15:42:17 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 27 15:42:17 volumio systemd[1]: volumio.service: Consumed 1min 13.771s CPU time. Jan 27 15:42:17 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 27 15:42:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:42:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:42:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:42:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 27 15:42:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:42:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:42:20 volumio go-librespot[13788]: go-librespot daemon starting... Jan 27 15:42:20 volumio go-librespot[13789]: time="2026-01-27T15:42:20+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 15:42:20 volumio go-librespot[13789]: time="2026-01-27T15:42:20+07:00" level=debug msg="app state loaded" Jan 27 15:42:20 volumio go-librespot[13789]: time="2026-01-27T15:42:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 15:42:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:42:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:42:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:42:20 volumio go-librespot[13789]: time="2026-01-27T15:42:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 15:42:20 volumio go-librespot[13789]: time="2026-01-27T15:42:20+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 27 15:42:20 volumio go-librespot[13789]: time="2026-01-27T15:42:20+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 27 15:42:20 volumio go-librespot[13789]: time="2026-01-27T15:42:20+07:00" level=info msg="zeroconf server listening on port 45501" Jan 27 15:42:21 volumio go-librespot[13789]: time="2026-01-27T15:42:21+07:00" level=debug msg="obtained new client token: AACierBJq8sUFVAS9kGSB392rn20SywCudQCDbr+ky/ZIJUbuO3+s/GF37S+LaPM8m5gfxjEEfO0yI84aj+oL01d0A8S8aruK7IsBtI7WQN1IYoJlGxXC2B/x+3HOBPk9Gym6fwlCz/rgeKNy2FceJGoJ6ROxHTMbrza+XRjPAJXDjGPp7jod1nTWGl1V638ABTysbuTOAiyJd5wxjCSP12QUXshb54ey6MHATojF6vnl0wLLdpOWavG" Jan 27 15:42:21 volumio go-librespot[13789]: time="2026-01-27T15:42:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 15:42:21 volumio go-librespot[13789]: time="2026-01-27T15:42:21+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 15:42:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 15:42:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 15:42:21 volumio volumio[13778]: info: ------------------------------------------- Jan 27 15:42:21 volumio volumio[13778]: info: ----- Volumio3 ---- Jan 27 15:42:21 volumio volumio[13778]: info: ------------------------------------------- Jan 27 15:42:21 volumio volumio[13778]: info: ----- System startup ---- Jan 27 15:42:21 volumio volumio[13778]: info: ------------------------------------------- Jan 27 15:42:22 volumio volumio-remote-updater[628]: [2026-01-27 15:42:22] [connect] Successful connection Jan 27 15:42:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:42:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:42:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:42:22 volumio volumio[13778]: info: MYVOLUMIO Environment detected Jan 27 15:42:22 volumio volumio[13778]: info: Plugin folders cleanup Jan 27 15:42:22 volumio volumio[13778]: info: Scanning into folder /volumio/app/plugins/ Jan 27 15:42:22 volumio volumio[13778]: info: Scanning category audio_interface Jan 27 15:42:22 volumio volumio[13778]: info: Scanning category miscellanea Jan 27 15:42:22 volumio volumio[13778]: info: Scanning category music_service Jan 27 15:42:22 volumio volumio[13778]: info: Scanning category plugins.json Jan 27 15:42:22 volumio volumio[13778]: info: Scanning category system_controller Jan 27 15:42:22 volumio volumio[13778]: info: Scanning category user_interface Jan 27 15:42:22 volumio volumio[13778]: info: Scanning into folder /data/plugins/ Jan 27 15:42:22 volumio volumio[13778]: info: Scanning category music_service Jan 27 15:42:22 volumio volumio[13778]: info: Plugin folders cleanup completed Jan 27 15:42:22 volumio volumio[13778]: info: ------------------------------------------- Jan 27 15:42:22 volumio volumio[13778]: info: ----- Core plugins startup ---- Jan 27 15:42:22 volumio volumio[13778]: info: ------------------------------------------- Jan 27 15:42:22 volumio volumio[13778]: info: Loading plugins from folder /volumio/app/plugins/ Jan 27 15:42:22 volumio volumio[13778]: info: Adding plugin upnp to MyMusic Plugins Jan 27 15:42:22 volumio volumio[13778]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 27 15:42:22 volumio volumio[13778]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 27 15:42:22 volumio volumio[13778]: info: Loading plugins from folder /data/plugins/ Jan 27 15:42:22 volumio volumio[13778]: info: Loading plugin "system"... Jan 27 15:42:23 volumio volumio[13778]: info: Loading plugin "appearance"... Jan 27 15:42:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 27 15:42:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:42:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:42:24 volumio go-librespot[13808]: go-librespot daemon starting... Jan 27 15:42:24 volumio go-librespot[13809]: time="2026-01-27T15:42:24+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 15:42:24 volumio go-librespot[13809]: time="2026-01-27T15:42:24+07:00" level=debug msg="app state loaded" Jan 27 15:42:24 volumio go-librespot[13809]: time="2026-01-27T15:42:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 15:42:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:42:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:42:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:42:24 volumio volumio[13778]: info: Loading plugin "network"... Jan 27 15:42:24 volumio volumio[13778]: info: Refreshing Cached IP Addresses Jan 27 15:42:25 volumio sudo[13817]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 15:42:25 volumio sudo[13817]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:42:25 volumio sudo[13819]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 15:42:25 volumio sudo[13819]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:42:25 volumio volumio[13778]: info: Loading plugin "services"... Jan 27 15:42:25 volumio sudo[13817]: pam_unix(sudo:session): session closed for user root Jan 27 15:42:25 volumio go-librespot[13809]: time="2026-01-27T15:42:25+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 15:42:25 volumio go-librespot[13809]: time="2026-01-27T15:42:25+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 15:42:25 volumio go-librespot[13809]: time="2026-01-27T15:42:25+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 15:42:25 volumio volumio[13778]: info: Loading plugin "alsa_controller"... Jan 27 15:42:25 volumio sudo[13819]: pam_unix(sudo:session): session closed for user root Jan 27 15:42:25 volumio go-librespot[13809]: time="2026-01-27T15:42:25+07:00" level=info msg="zeroconf server listening on port 41295" Jan 27 15:42:25 volumio sudo[13828]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 27 15:42:25 volumio sudo[13828]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:42:25 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 15:42:25 volumio volumio[13778]: info: Loading plugin "wizard"... Jan 27 15:42:25 volumio volumio[13778]: info: Loading plugin "networkfs"... Jan 27 15:42:25 volumio go-librespot[13809]: time="2026-01-27T15:42:25+07:00" level=debug msg="obtained new client token: AADtFEUdqKOhUhdgQ7Rd7AARCmpcRs4bjlEU6p8FajQq1/+oonuTJIalErGsn8hBD3eo3rWT46Opzhlg+WUq0Vl0GQ3QipAPcY+EWa+TtFRgqo1bB4g1V9fTwDvuyXVg81VTndL+5nBWLPsp6rPmba+fY9qZE02SOPhR7f834ftxwLRqh/LNCXFPuGo/sVJmnCKpk2Yr4Z15kK/GFfRCtarbW9P3isbVSrKIydgk58n4VMUd0HYLslw76xo=" Jan 27 15:42:25 volumio volumio[13778]: info: Starting Udev Watcher for removable devices Jan 27 15:42:25 volumio volumio[13778]: info: Ignoring mount for partition: boot Jan 27 15:42:25 volumio volumio[13778]: info: Ignoring mount for partition: volumio Jan 27 15:42:25 volumio volumio[13778]: info: Ignoring mount for partition: volumio_data Jan 27 15:42:25 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 15:42:25 volumio volumio[13778]: info: Loading plugin "volumio_command_line_client"... Jan 27 15:42:25 volumio volumio[13778]: info: Loading plugin "upnp"... Jan 27 15:42:25 volumio volumio[13778]: info: [1769503345411] Starting Upmpd Daemon Jan 27 15:42:25 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 15:42:25 volumio volumio[13778]: info: Loading plugin "my_music"... Jan 27 15:42:25 volumio go-librespot[13809]: time="2026-01-27T15:42:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 15:42:25 volumio volumio[13778]: info: Loading plugin "mpd"... Jan 27 15:42:25 volumio go-librespot[13809]: time="2026-01-27T15:42:25+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 15:42:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 15:42:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 15:42:26 volumio volumio[13778]: info: Loading plugin "upnp_browser"... Jan 27 15:42:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:42:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:42:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:42:27 volumio sudo[13828]: pam_unix(sudo:session): session closed for user root Jan 27 15:42:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:42:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:42:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:42:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 27 15:42:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:42:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:42:28 volumio go-librespot[13851]: go-librespot daemon starting... Jan 27 15:42:28 volumio go-librespot[13852]: time="2026-01-27T15:42:28+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 15:42:28 volumio go-librespot[13852]: time="2026-01-27T15:42:28+07:00" level=debug msg="app state loaded" Jan 27 15:42:28 volumio go-librespot[13852]: time="2026-01-27T15:42:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 15:42:29 volumio volumio[13778]: info: Starting UPNP Browser Jan 27 15:42:29 volumio volumio[13778]: info: Loading plugin "alarm-clock"... Jan 27 15:42:29 volumio volumio[13778]: info: Loading plugin "airplay_emulation"... Jan 27 15:42:29 volumio volumio[13778]: info: Starting Shairport Sync Jan 27 15:42:29 volumio volumio[13778]: info: Loading plugin "last_100"... Jan 27 15:42:29 volumio volumio[13778]: info: Loading plugin "webradio"... Jan 27 15:42:29 volumio go-librespot[13852]: time="2026-01-27T15:42:29+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 15:42:29 volumio go-librespot[13852]: time="2026-01-27T15:42:29+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 15:42:29 volumio go-librespot[13852]: time="2026-01-27T15:42:29+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 15:42:29 volumio go-librespot[13852]: time="2026-01-27T15:42:29+07:00" level=info msg="zeroconf server listening on port 37007" Jan 27 15:42:29 volumio volumio[13778]: info: Loading plugin "i2s_dacs"... Jan 27 15:42:29 volumio volumio[13778]: info: Loading plugin "volumiodiscovery"... Jan 27 15:42:29 volumio go-librespot[13852]: time="2026-01-27T15:42:29+07:00" level=debug msg="obtained new client token: AAA4O7GTYEY6wU8ggUdM6VJoXEccjDj1ggGWXZeMpGQ+DPKgBQ3MFQfBhsUcvwPqBEa5nrluQMNh6wuRoZ6qt5kJvk7pN8Oom+EuE0ilddmFq2WaQPLM1aqb9euD0UsfdYYDDA9glBmPMK0uPwS7NFc1xUnqop3t5pmVKTe1+xsFperQAUhznIDKAXvWcedVhTL34dU6/u2ZaG4TAw9Uwgv2E1Y5QBsrpN3DcMv0Z8L8lwaNn0kRHWMhgSY=" Jan 27 15:42:29 volumio volumio[13778]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 15:42:29 volumio volumio[13778]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 15:42:29 volumio volumio[13778]: *** WARNING *** For more information see Jan 27 15:42:29 volumio volumio[13778]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 15:42:29 volumio volumio[13778]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 15:42:29 volumio node[13778]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 15:42:29 volumio volumio[13778]: *** WARNING *** For more information see Jan 27 15:42:29 volumio node[13778]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 15:42:29 volumio node[13778]: *** WARNING *** For more information see Jan 27 15:42:29 volumio node[13778]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 15:42:29 volumio node[13778]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 15:42:29 volumio node[13778]: *** WARNING *** For more information see Jan 27 15:42:29 volumio volumio[13778]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 27 15:42:29 volumio volumio[13778]: info: Discovery: Started advertising with name: Volumio Jan 27 15:42:29 volumio go-librespot[13852]: time="2026-01-27T15:42:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 15:42:29 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 15:42:29 volumio volumio[13778]: info: Loading plugin "spop"... Jan 27 15:42:29 volumio go-librespot[13852]: time="2026-01-27T15:42:29+07:00" level=debug msg="completed keyexchange" Jan 27 15:42:29 volumio go-librespot[13852]: time="2026-01-27T15:42:29+07:00" level=debug msg="completed challenge" Jan 27 15:42:29 volumio go-librespot[13852]: time="2026-01-27T15:42:29+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 15:42:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 15:42:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 15:42:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:42:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:42:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:42:31 volumio volumio[13778]: info: Loading plugin "ytcr"... Jan 27 15:42:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:42:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:42:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:42:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 27 15:42:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:42:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:42:33 volumio go-librespot[13861]: go-librespot daemon starting... Jan 27 15:42:33 volumio go-librespot[13862]: time="2026-01-27T15:42:33+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 15:42:33 volumio go-librespot[13862]: time="2026-01-27T15:42:33+07:00" level=debug msg="app state loaded" Jan 27 15:42:33 volumio go-librespot[13862]: time="2026-01-27T15:42:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 15:42:33 volumio go-librespot[13862]: time="2026-01-27T15:42:33+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 15:42:33 volumio go-librespot[13862]: time="2026-01-27T15:42:33+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 15:42:33 volumio go-librespot[13862]: time="2026-01-27T15:42:33+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 15:42:33 volumio go-librespot[13862]: time="2026-01-27T15:42:33+07:00" level=info msg="zeroconf server listening on port 40541" Jan 27 15:42:33 volumio go-librespot[13862]: time="2026-01-27T15:42:33+07:00" level=debug msg="obtained new client token: AAAjKjClg1NQOsAbvSjEs3pITw18OqS2IdqGDyNz1poy9DOlP/gYdGabe8WwTUe4YwSgf+2jsrDTu54lLB+IQc0mfmO5ZfL5YdmdpXnkquWD8FoXtsYO8lyFXTPh8AecdV+WHYrYPYVu2Me0ZLBO7aaua1/JsDmi/WCj1FELMNowJLu1ZiSLUVzy8WNRZzQjBCGf3bcLTKunv/VzCxY/Y1JPvKqs4fVYamJubBcNh/BUPU6N5N3dQxz/7s4=" Jan 27 15:42:34 volumio go-librespot[13862]: time="2026-01-27T15:42:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 15:42:34 volumio go-librespot[13862]: time="2026-01-27T15:42:34+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 15:42:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 15:42:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 15:42:34 volumio volumio[13778]: info: Loading plugin "ytmusic"... Jan 27 15:42:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:42:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:42:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:42:35 volumio volumio-remote-updater[628]: [2026-01-27 15:42:35] [connect] Successful connection Jan 27 15:42:35 volumio volumio[13778]: info: Loading plugin "outputs"... Jan 27 15:42:35 volumio volumio[13778]: info: Loading plugin "albumart"... Jan 27 15:42:35 volumio volumio[13778]: info: Plugin example_plugin is not enabled Jan 27 15:42:35 volumio volumio[13778]: info: Loading plugin "inputs"... Jan 27 15:42:35 volumio volumio[13778]: info: Loading plugin "updater_comm"... Jan 27 15:42:35 volumio volumio[13778]: info: Plugin mpdemulation is not enabled Jan 27 15:42:35 volumio volumio[13778]: info: Loading plugin "rest_api"... Jan 27 15:42:35 volumio volumio[13778]: info: Loading plugin "websocket"... Jan 27 15:42:35 volumio volumio[13778]: info: Starting Socket.io Server version 1.7.4 Jan 27 15:42:35 volumio volumio[13778]: info: Loading plugin "RoonBridge"... Jan 27 15:42:36 volumio volumio[13778]: info: Applying required configuration parameters for plugin RoonBridge Jan 27 15:42:36 volumio volumio[13778]: info: Loading i18n strings for locale en Jan 27 15:42:36 volumio volumio[13778]: Updating browse sources language Jan 27 15:42:36 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 15:42:36 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 15:42:36 volumio volumio[13883]: Forking 3 albumart workers Jan 27 15:42:36 volumio volumio[13778]: info: CoreCommandRouter::initPlayerControls Jan 27 15:42:36 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:42:36 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:42:36 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:42:36 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:42:36 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:42:36 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:42:36 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:42:36 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:42:36 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 15:42:36 volumio volumio[13778]: Express server listening on port 3000 Jan 27 15:42:36 volumio volumio[13778]: [Metrics] WebUI: 16s 150.10ms Jan 27 15:42:36 volumio volumio[13778]: info: CoreStateMachine::resetVolumioState Jan 27 15:42:36 volumio volumio[13778]: info: CoreStateMachine::getcurrentVolume Jan 27 15:42:36 volumio volumio[13778]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 15:42:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:42:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:42:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:42:36 volumio sudo[13927]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 15:42:36 volumio sudo[13927]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:42:36 volumio sudo[13925]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 15:42:36 volumio sudo[13925]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:42:36 volumio sudo[13927]: pam_unix(sudo:session): session closed for user root Jan 27 15:42:36 volumio sudo[13925]: pam_unix(sudo:session): session closed for user root Jan 27 15:42:36 volumio volumio[13778]: info: Volumio Network Manager: Network status updated: 1 Jan 27 15:42:37 volumio volumio-remote-updater[628]: [2026-01-27 15:42:37] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769503355 101 Jan 27 15:42:37 volumio volumio[13778]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 27 15:42:37 volumio volumio[13778]: info: VolumeController:: Volume=100 Mute =false Jan 27 15:42:37 volumio volumio[13778]: info: CoreStateMachine::pushState Jan 27 15:42:37 volumio volumio[13778]: info: CorePlayQueue::getTrack 0 Jan 27 15:42:37 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 15:42:37 volumio volumio[13778]: info: CoreCommandRouter::volumioPushState Jan 27 15:42:37 volumio volumio[13778]: info: CoreStateMachine::updateTrackBlock Jan 27 15:42:37 volumio volumio[13778]: info: CorePlayQueue::getTrackBlock Jan 27 15:42:37 volumio volumio[13778]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 15:42:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 27 15:42:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:42:37 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:42:37 volumio volumio[13778]: info: Reloading queue from file Jan 27 15:42:37 volumio volumio[13778]: info: CoreStateMachine::setRepeat null single undefined Jan 27 15:42:37 volumio volumio[13778]: info: CoreStateMachine::pushState Jan 27 15:42:37 volumio volumio[13778]: info: CorePlayQueue::getTrack 0 Jan 27 15:42:37 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 15:42:37 volumio volumio[13778]: info: CoreCommandRouter::volumioPushState Jan 27 15:42:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:42:37 volumio go-librespot[13937]: go-librespot daemon starting... Jan 27 15:42:37 volumio volumio[13778]: info: CoreStateMachine::setRandom null Jan 27 15:42:37 volumio volumio[13778]: info: CoreStateMachine::pushState Jan 27 15:42:37 volumio volumio[13778]: info: CorePlayQueue::getTrack 0 Jan 27 15:42:37 volumio volumio[13778]: info: CoreCommandRouter::volumioPushState Jan 27 15:42:37 volumio volumio[13778]: info: Setting Device type: Raspberry PI Jan 27 15:42:37 volumio volumio[13778]: info: Completed loading Core Plugins Jan 27 15:42:37 volumio volumio[13778]: info: Preparing to generate the ALSA configuration file Jan 27 15:42:37 volumio go-librespot[13940]: time="2026-01-27T15:42:37+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 15:42:37 volumio go-librespot[13940]: time="2026-01-27T15:42:37+07:00" level=debug msg="app state loaded" Jan 27 15:42:37 volumio go-librespot[13940]: time="2026-01-27T15:42:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 15:42:37 volumio volumio[13778]: info: VolumeController:: Volume=100 Mute =false Jan 27 15:42:37 volumio volumio[13778]: info: CoreStateMachine::pushState Jan 27 15:42:37 volumio volumio[13778]: info: CorePlayQueue::getTrack 0 Jan 27 15:42:37 volumio volumio[13778]: info: CoreCommandRouter::volumioPushState Jan 27 15:42:37 volumio volumio[13778]: info: Asound.conf file unchanged, so no further update is needed Jan 27 15:42:37 volumio volumio[13778]: info: Output device has changed, restarting MPD Jan 27 15:42:37 volumio sudo[13950]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 27 15:42:37 volumio sudo[13950]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:42:37 volumio sudo[13952]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 15:42:37 volumio sudo[13952]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:42:37 volumio sudo[13952]: pam_unix(sudo:session): session closed for user root Jan 27 15:42:37 volumio volumio[13778]: info: Output device has changed, restarting Shairport Sync Jan 27 15:42:37 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:42:37 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:42:37 volumio sudo[13956]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 15:42:37 volumio sudo[13956]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:42:37 volumio sudo[13950]: pam_unix(sudo:session): session closed for user root Jan 27 15:42:37 volumio volumio[13778]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 15:42:37 volumio volumio[13778]: info: ___________ START PLUGINS ___________ Jan 27 15:42:37 volumio volumio[13778]: info: ControllerMpd::onStart: Initializing MPD Jan 27 15:42:37 volumio volumio[13778]: info: Creating MPD Configuration file Jan 27 15:42:37 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 27 15:42:38 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 15:42:38 volumio volumio[13778]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 15:42:38 volumio volumio[13778]: info: [1769503358059] CoreMusicLibrary::Adding element Media Servers Jan 27 15:42:38 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 15:42:38 volumio sudo[13965]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 15:42:38 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 15:42:38 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 15:42:38 volumio systemd[1]: mpd.service: Consumed 7.535s CPU time. Jan 27 15:42:38 volumio volumio[13778]: info: UPNP Browser: Client initialized successfully Jan 27 15:42:38 volumio sudo[13965]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:42:38 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 15:42:38 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 15:42:38 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 15:42:38 volumio sudo[13967]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 15:42:38 volumio sudo[13967]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:42:38 volumio sudo[13965]: pam_unix(sudo:session): session closed for user root Jan 27 15:42:38 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:42:38 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:42:38 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 15:42:38 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 15:42:38 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 15:42:38 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 15:42:38 volumio go-librespot[13940]: time="2026-01-27T15:42:38+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 15:42:38 volumio go-librespot[13940]: time="2026-01-27T15:42:38+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 27 15:42:38 volumio go-librespot[13940]: time="2026-01-27T15:42:38+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 27 15:42:38 volumio volumio[13778]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 15:42:38 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 15:42:38 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 15:42:38 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 15:42:38 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:42:38 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:42:38 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 15:42:38 volumio go-librespot[13940]: time="2026-01-27T15:42:38+07:00" level=info msg="zeroconf server listening on port 46697" Jan 27 15:42:38 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 15:42:38 volumio volumio[13778]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 15:42:38 volumio volumio[13778]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 15:42:38 volumio volumio[13778]: info: [1769503358431] CoreMusicLibrary::Adding element Last_100 Jan 27 15:42:38 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 15:42:38 volumio volumio[13778]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 15:42:38 volumio volumio[13778]: info: [1769503358446] CoreMusicLibrary::Adding element Webradio Jan 27 15:42:38 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 15:42:38 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 15:42:38 volumio volumio[13778]: info: Initializing BBC Radios Jan 27 15:42:38 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 15:42:38 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:42:38 volumio go-librespot[13940]: time="2026-01-27T15:42:38+07:00" level=debug msg="obtained new client token: AACthhVbuKGZNmlbqXtmuaHPnQNgPdG06tNZdQChXrdNmXUbmOG0kqzxAdKd+6OrhYWkoMcMsHFwBPSoPeFntWIVOg0Hzn4KepQMhLgYZGR8v5KP0r8wyBBI5hhgBf5c9jw+u/v/IsEj8L+hs/rvq5icD3lEiX2v0lQWNcLj7lLefZZuLDXGXjmFwjmbB+6X/7LTRkctLK1JzaPto9DnZHDTnzk74P7wOZ0a1K3jbeKhIL4AHozdkFhGkCE=" Jan 27 15:42:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:42:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:42:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:42:38 volumio volumio[13778]: info: Creating Spotify config file Jan 27 15:42:38 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:42:38 volumio go-librespot[13940]: time="2026-01-27T15:42:38+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 27 15:42:38 volumio go-librespot[13940]: time="2026-01-27T15:42:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 15:42:38 volumio sudo[13978]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 27 15:42:38 volumio sudo[13978]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 27 15:42:38 volumio go-librespot[13940]: time="2026-01-27T15:42:38+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 15:42:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 15:42:38 volumio sudo[13978]: pam_unix(sudo:session): session closed for user root Jan 27 15:42:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 15:42:39 volumio volumio[13778]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 15:42:39 volumio volumio[13778]: info: [1769503359653] CoreMusicLibrary::Adding element YouTube Music Jan 27 15:42:39 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 15:42:39 volumio volumio[13778]: Cannot find translation for source YouTube Music Jan 27 15:42:39 volumio volumio[13778]: info: Volumio Calling Home Jan 27 15:42:39 volumio sudo[13998]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 27 15:42:39 volumio sudo[13998]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:42:39 volumio sudo[13998]: pam_unix(sudo:session): session closed for user root Jan 27 15:42:40 volumio volumio[13895]: Starting albumart workers Jan 27 15:42:40 volumio volumio[13778]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 15:42:40 volumio volumio[13778]: info: Discovery: Found device Volumio Jan 27 15:42:40 volumio volumio[13778]: info: CoreCommandRouter::volumioGetState Jan 27 15:42:40 volumio volumio[13778]: info: CorePlayQueue::getTrack 0 Jan 27 15:42:40 volumio volumio[13893]: Starting albumart workers Jan 27 15:42:40 volumio volumio[13894]: Starting albumart workers Jan 27 15:42:40 volumio volumio[13778]: info: MPD Permissions set Jan 27 15:42:40 volumio volumio[13778]: info: MPD Permissions set Jan 27 15:42:40 volumio volumio[13778]: info: Upmpdcli Daemon Started Jan 27 15:42:40 volumio volumio[13778]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 15:42:40 volumio volumio[13778]: info: Discovery: Found device Volumio Jan 27 15:42:40 volumio volumio[13778]: info: CoreCommandRouter::volumioGetState Jan 27 15:42:40 volumio volumio[13778]: info: CorePlayQueue::getTrack 0 Jan 27 15:42:40 volumio volumio[13778]: info: Volumio called home Jan 27 15:42:40 volumio volumio[13778]: info: Spotify config file written Jan 27 15:42:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:42:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:42:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:42:40 volumio sudo[14004]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 15:42:40 volumio sudo[14004]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:42:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:42:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:42:41 volumio go-librespot[14006]: go-librespot daemon starting... Jan 27 15:42:41 volumio sudo[14004]: pam_unix(sudo:session): session closed for user root Jan 27 15:42:41 volumio go-librespot[14007]: time="2026-01-27T15:42:41+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 15:42:41 volumio go-librespot[14007]: time="2026-01-27T15:42:41+07:00" level=debug msg="app state loaded" Jan 27 15:42:41 volumio go-librespot[14007]: time="2026-01-27T15:42:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 15:42:41 volumio volumio[13778]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 27 15:42:41 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:42:41 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:42:41 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:42:41 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:42:41 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:42:41 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:42:41 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:42:41 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:42:41 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:42:41 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:42:41 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:42:41 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:42:41 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:42:41 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:42:41 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:42:41 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:42:41 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:42:41 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:42:41 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:42:41 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:42:41 volumio volumio[13778]: info: No need to fix Spotify hosts Jan 27 15:42:41 volumio go-librespot[14007]: time="2026-01-27T15:42:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 15:42:41 volumio go-librespot[14007]: time="2026-01-27T15:42:41+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 15:42:41 volumio go-librespot[14007]: time="2026-01-27T15:42:41+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 15:42:41 volumio go-librespot[14007]: time="2026-01-27T15:42:41+07:00" level=info msg="zeroconf server listening on port 38411" Jan 27 15:42:42 volumio go-librespot[14007]: time="2026-01-27T15:42:42+07:00" level=debug msg="obtained new client token: AADYlJFlFU7FPgdS3zl1HQ9aHkz62z2RMdOypbA/5+2CbA1mhKi3TEmbOUMiLOEOSGY/vOfwB/TKIeiRrDWx1Y1/oNpvrw9vuKqGvTtzQLnZHAZwQffqxXQ8U8frm+JMY+pc/btpZDx9Zelsh3AD3lnQDgbg0dUa35ssEZ1F3KRGOf77HKPnmOSYaWFz/CDn2CC2Mq9qNKQl8epHnDcjYd8lLuPeAgVC1lqZSinB+wRStf417g2SiW+u" Jan 27 15:42:42 volumio go-librespot[14007]: time="2026-01-27T15:42:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 15:42:42 volumio go-librespot[14007]: time="2026-01-27T15:42:42+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 15:42:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 15:42:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 15:42:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:42:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:42:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:42:42 volumio volumio[13778]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 15:42:42 volumio volumio[13778]: SPOTIFY: BQA4s-Tr74YRnLG8Ejme-7FMShfZFDCTe5hvHZZScD3XA40hq-CtiwSe27YFQG5gvROav2EJ5wrbkT2xBIjY-JPf3EL3-gU9oXL2Jb6aK8WHDH_c4TPIbPt8MfgYGTfyrfn7PGQ8yQ5YvrVuErUi50XYjTR_Ux7O9gye4eYj0OThDGCPm_GaRE2DODHmO8EIIY-KIS3VDWdziIKwi7EVHkpuLh8-NtkUPEOYNuUkUG_bzjQYBTEQkGCDboA6zCzxIqSQsjbnv1CaXt8PAuETM7916FmqbLrs4CbUy9ornkQGb7blD5mt-sAw Jan 27 15:42:42 volumio volumio[13778]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 15:42:42 volumio volumio[13778]: info: New Spotify access token = BQA4s-Tr74YRnLG8Ejme-7FMShfZFDCTe5hvHZZScD3XA40hq-CtiwSe27YFQG5gvROav2EJ5wrbkT2xBIjY-JPf3EL3-gU9oXL2Jb6aK8WHDH_c4TPIbPt8MfgYGTfyrfn7PGQ8yQ5YvrVuErUi50XYjTR_Ux7O9gye4eYj0OThDGCPm_GaRE2DODHmO8EIIY-KIS3VDWdziIKwi7EVHkpuLh8-NtkUPEOYNuUkUG_bzjQYBTEQkGCDboA6zCzxIqSQsjbnv1CaXt8PAuETM7916FmqbLrs4CbUy9ornkQGb7blD5mt-sAw Jan 27 15:42:42 volumio volumio[13778]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 27 15:42:42 volumio volumio[13778]: info: Starting Shairport Sync Jan 27 15:42:42 volumio volumio[13778]: info: Starting Shairport Sync Jan 27 15:42:42 volumio volumio[13778]: info: Starting Shairport Sync Jan 27 15:42:43 volumio sudo[14043]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 15:42:43 volumio sudo[14043]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:42:43 volumio sudo[14045]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 15:42:43 volumio sudo[14045]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:42:43 volumio sudo[14047]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 15:42:43 volumio sudo[14047]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:42:43 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 15:42:43 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 15:42:43 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 15:42:43 volumio systemd[1]: shairport-sync.service: Consumed 2.498s CPU time. Jan 27 15:42:43 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 15:42:43 volumio sudo[14045]: pam_unix(sudo:session): session closed for user root Jan 27 15:42:43 volumio sudo[14043]: pam_unix(sudo:session): session closed for user root Jan 27 15:42:43 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 15:42:43 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 15:42:43 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 15:42:43 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 15:42:43 volumio sudo[14047]: pam_unix(sudo:session): session closed for user root Jan 27 15:42:43 volumio volumio[13778]: info: Shairport-Sync Started Jan 27 15:42:43 volumio volumio[13778]: Error adding Membership: Error: addMembership EINVAL Jan 27 15:42:43 volumio volumio[13778]: info: Shairport-Sync Started Jan 27 15:42:43 volumio volumio[13778]: info: Shairport-Sync Started Jan 27 15:42:43 volumio volumio[13778]: info: CoreCommandRouter::volumioGetState Jan 27 15:42:43 volumio volumio[13778]: info: CorePlayQueue::getTrack 0 Jan 27 15:42:43 volumio volumio[13778]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Jan 27 15:42:43 volumio volumio[13778]: info: Spotify Successfully logged in Jan 27 15:42:43 volumio volumio[13778]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 15:42:43 volumio volumio[13778]: info: [1769503363786] CoreMusicLibrary::Adding element Spotify Jan 27 15:42:43 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 15:42:43 volumio volumio[13778]: Cannot find translation for source YouTube Music Jan 27 15:42:43 volumio volumio[13778]: Cannot find translation for source Spotify Jan 27 15:42:44 volumio volumio[13778]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 27 15:42:44 volumio volumio[13778]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 15:42:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:42:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:42:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:42:44 volumio volumio[13778]: info: VolumeController:: Volume=100 Mute =false Jan 27 15:42:44 volumio volumio[13778]: info: CoreCommandRouter::volumioGetState Jan 27 15:42:44 volumio volumio[13778]: info: CorePlayQueue::getTrack 0 Jan 27 15:42:44 volumio volumio[13778]: info: CoreStateMachine::pushState Jan 27 15:42:44 volumio volumio[13778]: info: CorePlayQueue::getTrack 0 Jan 27 15:42:44 volumio volumio[13778]: info: CoreCommandRouter::volumioPushState Jan 27 15:42:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Jan 27 15:42:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:42:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:42:45 volumio go-librespot[14084]: go-librespot daemon starting... Jan 27 15:42:45 volumio go-librespot[14085]: time="2026-01-27T15:42:45+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 15:42:45 volumio go-librespot[14085]: time="2026-01-27T15:42:45+07:00" level=debug msg="app state loaded" Jan 27 15:42:45 volumio go-librespot[14085]: time="2026-01-27T15:42:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 15:42:45 volumio volumio[13778]: info: go-librespot daemon successfully initialized Jan 27 15:42:46 volumio go-librespot[14085]: time="2026-01-27T15:42:46+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 15:42:46 volumio go-librespot[14085]: time="2026-01-27T15:42:46+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 15:42:46 volumio go-librespot[14085]: time="2026-01-27T15:42:46+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 15:42:46 volumio go-librespot[14085]: time="2026-01-27T15:42:46+07:00" level=info msg="zeroconf server listening on port 44547" Jan 27 15:42:46 volumio mpd[13996]: 2026-01-27T15:42:46 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 27 15:42:46 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 27 15:42:46 volumio sudo[13956]: pam_unix(sudo:session): session closed for user root Jan 27 15:42:46 volumio sudo[13967]: pam_unix(sudo:session): session closed for user root Jan 27 15:42:46 volumio go-librespot[14085]: time="2026-01-27T15:42:46+07:00" level=debug msg="obtained new client token: AABFizlmjp91iE6hX264gsesUHGC8zRFMC64vDJoQY0f+RspLmhIs2OMLHLjTmQq6JGYRYIxMsXn0O5W6ocDB0FF6n1EpTfR3sASYK6jN2QmhmS9HWQAhmr+Y+zo2l51zROlAkQNE1Voz/q+evsss/vwDbO3KOY8yBkVj2Lb/jgnHxHo962onMPVs0reYVHbqVXuDHEAWZpcnQ0FrwgwJB1nVawc9As83RuxdmfiklAHNFKdEQzULBvpgas=" Jan 27 15:42:46 volumio go-librespot[14085]: time="2026-01-27T15:42:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 15:42:46 volumio volumio[13778]: error: MPD error: The expression evaluated to a falsy value: Jan 27 15:42:46 volumio volumio[13778]: assert.ok(self.idling) Jan 27 15:42:46 volumio volumio[13778]: error: The expression evaluated to a falsy value: Jan 27 15:42:46 volumio volumio[13778]: assert.ok(self.idling) Jan 27 15:42:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:42:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:42:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:42:46 volumio go-librespot[14085]: time="2026-01-27T15:42:46+07:00" level=debug msg="completed keyexchange" Jan 27 15:42:46 volumio go-librespot[14085]: time="2026-01-27T15:42:46+07:00" level=debug msg="completed challenge" Jan 27 15:42:46 volumio volumio[13778]: info: Completed starting Core Plugins Jan 27 15:42:46 volumio volumio[13778]: info: ------------------------------------------- Jan 27 15:42:46 volumio volumio[13778]: info: ----- MyVolumio plugins startup ---- Jan 27 15:42:46 volumio volumio[13778]: info: ------------------------------------------- Jan 27 15:42:46 volumio volumio[13778]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 27 15:42:46 volumio volumio[13778]: error: updateQueue error: null Jan 27 15:42:46 volumio volumio[13778]: info: MPD running with PID13996 Jan 27 15:42:46 volumio volumio[13778]: ,establishing connection Jan 27 15:42:46 volumio go-librespot[14085]: time="2026-01-27T15:42:46+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 15:42:46 volumio volumio[13778]: error: updateQueue error: null Jan 27 15:42:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 15:42:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 15:42:48 volumio volumio[13778]: info: Initializing connection to go-librespot Websocket Jan 27 15:42:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:42:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:42:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:42:48 volumio volumio[13778]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 15:42:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jan 27 15:42:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:42:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:42:50 volumio go-librespot[14100]: go-librespot daemon starting... Jan 27 15:42:50 volumio go-librespot[14101]: time="2026-01-27T15:42:50+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 15:42:50 volumio go-librespot[14101]: time="2026-01-27T15:42:50+07:00" level=debug msg="app state loaded" Jan 27 15:42:50 volumio go-librespot[14101]: time="2026-01-27T15:42:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 15:42:50 volumio go-librespot[14101]: time="2026-01-27T15:42:50+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 15:42:50 volumio go-librespot[14101]: time="2026-01-27T15:42:50+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 15:42:50 volumio go-librespot[14101]: time="2026-01-27T15:42:50+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 15:42:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:42:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:42:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:42:50 volumio go-librespot[14101]: time="2026-01-27T15:42:50+07:00" level=info msg="zeroconf server listening on port 45559" Jan 27 15:42:50 volumio go-librespot[14101]: time="2026-01-27T15:42:50+07:00" level=debug msg="obtained new client token: AAAjjBw+ZK8S9MgyaeA7aXxYrBpD1qmSBTq6NZHG5ZByheP1wxoT91aCd1Suwe6hb37wC8pX52/SBdMBP4owCrn4CVnCZrgZo9L2xsJ8NtylMiLizi9IujEw7QmSSxtS60pFSUk8TGS4psk2dMLhqkQvQp6FonQ/jvR2UYEpFBSJd1Pm6iJqyx90TQdKsT+9O30+km3MUo++oLrRiS+RE8BE6kYPmsE5SboS0NHT3Zm1fxxhaAqYAn+qVQo=" Jan 27 15:42:50 volumio go-librespot[14101]: time="2026-01-27T15:42:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 15:42:51 volumio go-librespot[14101]: time="2026-01-27T15:42:51+07:00" level=debug msg="completed keyexchange" Jan 27 15:42:51 volumio go-librespot[14101]: time="2026-01-27T15:42:51+07:00" level=debug msg="completed challenge" Jan 27 15:42:51 volumio go-librespot[14101]: time="2026-01-27T15:42:51+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 15:42:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 15:42:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 15:42:51 volumio volumio[13778]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 27 15:42:51 volumio volumio[13778]: info: Initializing connection to go-librespot Websocket Jan 27 15:42:51 volumio volumio[13778]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 15:42:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:42:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:42:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:42:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Jan 27 15:42:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:42:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:42:54 volumio go-librespot[14109]: go-librespot daemon starting... Jan 27 15:42:54 volumio go-librespot[14110]: time="2026-01-27T15:42:54+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 15:42:54 volumio go-librespot[14110]: time="2026-01-27T15:42:54+07:00" level=debug msg="app state loaded" Jan 27 15:42:54 volumio go-librespot[14110]: time="2026-01-27T15:42:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 15:42:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:42:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:42:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:42:54 volumio volumio[13778]: info: Initializing connection to go-librespot Websocket Jan 27 15:42:54 volumio go-librespot[14110]: time="2026-01-27T15:42:54+07:00" level=debug msg="new websocket client" Jan 27 15:42:54 volumio volumio[13778]: info: Connection to go-librespot Websocket established Jan 27 15:42:54 volumio go-librespot[14110]: time="2026-01-27T15:42:54+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 15:42:54 volumio go-librespot[14110]: time="2026-01-27T15:42:54+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 15:42:54 volumio go-librespot[14110]: time="2026-01-27T15:42:54+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 15:42:54 volumio go-librespot[14110]: time="2026-01-27T15:42:54+07:00" level=info msg="zeroconf server listening on port 37767" Jan 27 15:42:55 volumio go-librespot[14110]: time="2026-01-27T15:42:55+07:00" level=debug msg="obtained new client token: AADOpt9nO7rBqsab55BRCyo7x9FHflNLfb2dldAnyLiAT7PD/hzOw7rxlD6RYV5RGOAz4PJM6bwOR36A2juwgzFO9PubHrZmeiSp4htGI5qZr6GIBi6e1KNVdJNii63nDzXqtczk+yYeXVawictdM+tx8m5aWcYu4QuI8olHVnnaLor8G+QERc3zYj31j9ZUzcgDfq98/DVhulwOV0fs+OMm4G6raejo6Qitm/7ilAS582KLYPkqUhbn" Jan 27 15:42:55 volumio go-librespot[14110]: time="2026-01-27T15:42:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 15:42:55 volumio volumio[13778]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 27 15:42:55 volumio volumio[13778]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 27 15:42:55 volumio volumio[13778]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 27 15:42:55 volumio volumio[13778]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 27 15:42:55 volumio volumio[13778]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 27 15:42:55 volumio volumio[13778]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 27 15:42:55 volumio volumio[13778]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 27 15:42:55 volumio volumio[13778]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 27 15:42:55 volumio volumio[13778]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 27 15:42:55 volumio volumio[13778]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 27 15:42:55 volumio volumio[13778]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 27 15:42:55 volumio volumio[13778]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 27 15:42:55 volumio volumio[13778]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 27 15:42:55 volumio volumio[13778]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 27 15:42:55 volumio volumio[13778]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 27 15:42:55 volumio volumio[13778]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 27 15:42:55 volumio volumio[13778]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 27 15:42:55 volumio volumio[13778]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 27 15:42:55 volumio volumio[13778]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 27 15:42:55 volumio volumio[13778]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 27 15:42:55 volumio volumio[13778]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 27 15:42:55 volumio volumio[13778]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 27 15:42:55 volumio volumio[13778]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 27 15:42:55 volumio volumio[13778]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 27 15:42:55 volumio volumio[13778]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 27 15:42:55 volumio volumio[13778]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 27 15:42:55 volumio volumio[13778]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 27 15:42:55 volumio volumio[13778]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 27 15:42:55 volumio volumio[13778]: info: Adding plugin bluetooth to MyMusic Plugins Jan 27 15:42:55 volumio volumio[13778]: info: Adding plugin multiroom to MyMusic Plugins Jan 27 15:42:55 volumio volumio[13778]: info: Adding plugin metavolumio to MyMusic Plugins Jan 27 15:42:55 volumio volumio[13778]: info: Adding plugin cd_controller to MyMusic Plugins Jan 27 15:42:55 volumio volumio[13778]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 27 15:42:55 volumio volumio[13778]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 27 15:42:55 volumio volumio[13778]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 27 15:42:55 volumio volumio[13778]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 27 15:42:55 volumio go-librespot[14110]: time="2026-01-27T15:42:55+07:00" level=debug msg="completed keyexchange" Jan 27 15:42:55 volumio go-librespot[14110]: time="2026-01-27T15:42:55+07:00" level=debug msg="completed challenge" Jan 27 15:42:55 volumio go-librespot[14110]: time="2026-01-27T15:42:55+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 15:42:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 15:42:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 15:42:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:42:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:42:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:42:57 volumio volumio[13778]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 27 15:42:57 volumio volumio[13778]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 27 15:42:57 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:42:57 volumio volumio[13778]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:42:57 volumio volumio[13778]: info: Starting MyVolumio Remote Streaming Endpoints Jan 27 15:42:57 volumio volumio[13778]: info: MyVolumio login type: Token Jan 27 15:42:57 volumio volumio[13778]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 27 15:42:57 volumio volumio[13778]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 27 15:42:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:42:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:42:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:42:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Jan 27 15:42:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:42:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:42:59 volumio go-librespot[14132]: go-librespot daemon starting... Jan 27 15:42:59 volumio go-librespot[14133]: time="2026-01-27T15:42:59+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 15:42:59 volumio go-librespot[14133]: time="2026-01-27T15:42:59+07:00" level=debug msg="app state loaded" Jan 27 15:42:59 volumio go-librespot[14133]: time="2026-01-27T15:42:59+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 15:42:59 volumio volumio[13778]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 27 15:42:59 volumio volumio[13778]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 27 15:42:59 volumio volumio[13778]: info: Streaming services startup Jan 27 15:42:59 volumio volumio[13778]: info: Starting Streaming Daemon Jan 27 15:42:59 volumio sudo[14140]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 15:42:59 volumio sudo[14140]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:42:59 volumio volumio[13778]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 27 15:42:59 volumio sudo[14140]: pam_unix(sudo:session): session closed for user root Jan 27 15:42:59 volumio volumio[13778]: info: Getting Spotify volume Jan 27 15:42:59 volumio volumio[13778]: info: Connection to go-librespot Websocket closed Jan 27 15:42:59 volumio volumio[13778]: error: Cannot start Volumio Streaming Daemon Jan 27 15:42:59 volumio volumio[13778]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 15:42:59 volumio volumio[13778]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 15:42:59 volumio volumio[13778]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 27 15:42:59 volumio go-librespot[14133]: time="2026-01-27T15:42:59+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 15:42:59 volumio go-librespot[14133]: time="2026-01-27T15:42:59+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 15:42:59 volumio go-librespot[14133]: time="2026-01-27T15:42:59+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 15:42:59 volumio go-librespot[14133]: time="2026-01-27T15:42:59+07:00" level=info msg="zeroconf server listening on port 35497" Jan 27 15:42:59 volumio go-librespot[14133]: time="2026-01-27T15:42:59+07:00" level=debug msg="obtained new client token: AADRdH6JBTQvE0/TNmjrN9PfTX0F+/RyueIKWlFhEgfrs26tZa2x/XdRFLm9ZqQPVobthjv0GkHqdMKEwwGRaRXatpzVYSFVxGgLAIVXq+DIaZCXGZojgQ/xZwlrrQR49a9HqtQiDBYqQ0Mr15vAZiB5DeEPI8uHfhO8ASCy9mBsigIDNsylQdZnQUz+QEvafPu0LO5rBhc2DXwmYhMLq7dI/qo/ZvPMPUTMBlWtMtYVtrsJYJqef+enkOA=" Jan 27 15:42:59 volumio volumio[13778]: info: CoreCommandRouter::volumioGetState Jan 27 15:42:59 volumio volumio[13778]: info: CorePlayQueue::getTrack 0 Jan 27 15:42:59 volumio volumio[13778]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 27 15:42:59 volumio volumio[13778]: SPOTIFY: SPOTIFY VOLUME undefined Jan 27 15:42:59 volumio volumio[13778]: SPOTIFY: VOLUMIO VOLUME 100 Jan 27 15:42:59 volumio volumio[13778]: info: Aligning Spotify Volume to Volumio Volume Jan 27 15:42:59 volumio volumio[13778]: info: CoreCommandRouter::volumioGetState Jan 27 15:42:59 volumio volumio[13778]: info: CorePlayQueue::getTrack 0 Jan 27 15:42:59 volumio volumio[13778]: info: Setting Spotify Volume from Volumio: 100 Jan 27 15:42:59 volumio go-librespot[14133]: time="2026-01-27T15:42:59+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 27 15:43:00 volumio go-librespot[14133]: time="2026-01-27T15:43:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 15:43:00 volumio go-librespot[14133]: time="2026-01-27T15:43:00+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 15:43:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 15:43:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 15:43:00 volumio volumio[13778]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 15:43:00 volumio volumio[13778]: Error: socket hang up Jan 27 15:43:00 volumio volumio[13778]: at connResetException (node:internal/errors:720:14) Jan 27 15:43:00 volumio volumio[13778]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 27 15:43:00 volumio volumio[13778]: at Socket.emit (node:events:526:35) Jan 27 15:43:00 volumio volumio[13778]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 27 15:43:00 volumio volumio[13778]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 27 15:43:00 volumio volumio[13778]: code: 'ECONNRESET', Jan 27 15:43:00 volumio volumio[13778]: response: undefined Jan 27 15:43:00 volumio volumio[13778]: } Jan 27 15:43:00 volumio volumio[13778]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 15:43:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:43:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:43:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:43:01 volumio sudo[14161]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 15:42' Jan 27 15:43:01 volumio sudo[14161]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:43:01 volumio sudo[14161]: pam_unix(sudo:session): session closed for user root Jan 27 15:43:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:43:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:43:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:43:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Jan 27 15:43:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:43:03 volumio volumio-remote-updater[628]: [2026-01-27 15:43:03] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Jan 27 15:43:03 volumio volumio-remote-updater[628]: [2026-01-27 15:43:03] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Jan 27 15:43:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:43:03 volumio go-librespot[14169]: go-librespot daemon starting... Jan 27 15:43:03 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 27 15:43:03 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 27 15:43:03 volumio systemd[1]: volumio.service: Consumed 1min 10.616s CPU time. Jan 27 15:43:03 volumio go-librespot[14170]: time="2026-01-27T15:43:03+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 15:43:03 volumio go-librespot[14170]: time="2026-01-27T15:43:03+07:00" level=debug msg="app state loaded" Jan 27 15:43:03 volumio go-librespot[14170]: time="2026-01-27T15:43:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 15:43:03 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 15:43:03 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 15:43:03 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8762. Jan 27 15:43:03 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 15:43:03 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 27 15:43:03 volumio systemd[1]: volumio.service: Consumed 1min 10.616s CPU time. Jan 27 15:43:03 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 27 15:43:03 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 15:43:03 volumio go-librespot[14170]: time="2026-01-27T15:43:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 15:43:03 volumio go-librespot[14170]: time="2026-01-27T15:43:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 15:43:03 volumio go-librespot[14170]: time="2026-01-27T15:43:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 15:43:03 volumio go-librespot[14170]: time="2026-01-27T15:43:03+07:00" level=info msg="zeroconf server listening on port 36693" Jan 27 15:43:04 volumio go-librespot[14170]: time="2026-01-27T15:43:04+07:00" level=debug msg="obtained new client token: AABD6RlDJ7fVbDq8n7DxqwkveOEi36Uz4f7melp3yy0Eg3j6qJRMesSSKzQGLHK1pxn/Oc+H6A6VXxumLHUIdIdLkIBU90B+16kxDC83QtmhNkK2hhK04UniYOs0t5wk21xIBj5EnHOahiRVcQ0Q0VpE4uSOSCb8a6FI1tsms9dpL2oSSQzSrF8TOIUNCXB8Kc6GU2PREADZwhSLy+8RuhHKRPF2TB8TT+jPGfgCZjhJ0+cBl07RVuvV" Jan 27 15:43:04 volumio go-librespot[14170]: time="2026-01-27T15:43:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 15:43:04 volumio go-librespot[14170]: time="2026-01-27T15:43:04+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 15:43:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 15:43:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 15:43:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:43:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:43:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:43:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:43:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:43:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:43:07 volumio volumio[14183]: info: ------------------------------------------- Jan 27 15:43:07 volumio volumio[14183]: info: ----- Volumio3 ---- Jan 27 15:43:07 volumio volumio[14183]: info: ------------------------------------------- Jan 27 15:43:07 volumio volumio[14183]: info: ----- System startup ---- Jan 27 15:43:07 volumio volumio[14183]: info: ------------------------------------------- Jan 27 15:43:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Jan 27 15:43:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:43:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:43:07 volumio go-librespot[14206]: go-librespot daemon starting... Jan 27 15:43:07 volumio go-librespot[14208]: time="2026-01-27T15:43:07+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 15:43:07 volumio go-librespot[14208]: time="2026-01-27T15:43:07+07:00" level=debug msg="app state loaded" Jan 27 15:43:07 volumio go-librespot[14208]: time="2026-01-27T15:43:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 15:43:08 volumio go-librespot[14208]: time="2026-01-27T15:43:08+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 15:43:08 volumio go-librespot[14208]: time="2026-01-27T15:43:08+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 15:43:08 volumio go-librespot[14208]: time="2026-01-27T15:43:08+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 15:43:08 volumio go-librespot[14208]: time="2026-01-27T15:43:08+07:00" level=info msg="zeroconf server listening on port 44453" Jan 27 15:43:08 volumio volumio-remote-updater[628]: [2026-01-27 15:43:08] [connect] Successful connection Jan 27 15:43:08 volumio go-librespot[14208]: time="2026-01-27T15:43:08+07:00" level=debug msg="obtained new client token: AABUZtwJ1PxXqgrKGyQojJmcyAVCrSbUZ7QmEQz0ZUXA2YiRaGzdmY9axYirpmZT6VPUDG75b/BAyzmoiZy+K4sLgs8UwXioqGQM09KoaOp73WqVjYGgMZYHVHJ6AaCwyNn9pqA5v4PP1NrKMj1k7s/GLdM4tRRe8OwMHqV9CSb+d1AJCM0JjwJjuexjrUPbzFmSMghMPXOVV3dkcS1vWejN1Z4PQRZxBmaOmwgntV3CZ+9E6NIy9fxa9dE=" Jan 27 15:43:08 volumio volumio[14183]: info: MYVOLUMIO Environment detected Jan 27 15:43:08 volumio go-librespot[14208]: time="2026-01-27T15:43:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 15:43:08 volumio volumio[14183]: info: Plugin folders cleanup Jan 27 15:43:08 volumio volumio[14183]: info: Scanning into folder /volumio/app/plugins/ Jan 27 15:43:08 volumio volumio[14183]: info: Scanning category audio_interface Jan 27 15:43:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:43:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:43:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:43:08 volumio volumio[14183]: info: Scanning category miscellanea Jan 27 15:43:08 volumio go-librespot[14208]: time="2026-01-27T15:43:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 15:43:08 volumio volumio[14183]: info: Scanning category music_service Jan 27 15:43:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 15:43:08 volumio volumio[14183]: info: Scanning category plugins.json Jan 27 15:43:08 volumio volumio[14183]: info: Scanning category system_controller Jan 27 15:43:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 15:43:08 volumio volumio[14183]: info: Scanning category user_interface Jan 27 15:43:08 volumio volumio[14183]: info: Scanning into folder /data/plugins/ Jan 27 15:43:08 volumio volumio[14183]: info: Scanning category music_service Jan 27 15:43:08 volumio volumio[14183]: info: Plugin folders cleanup completed Jan 27 15:43:08 volumio volumio[14183]: info: ------------------------------------------- Jan 27 15:43:08 volumio volumio[14183]: info: ----- Core plugins startup ---- Jan 27 15:43:08 volumio volumio[14183]: info: ------------------------------------------- Jan 27 15:43:08 volumio volumio[14183]: info: Loading plugins from folder /volumio/app/plugins/ Jan 27 15:43:08 volumio volumio[14183]: info: Adding plugin upnp to MyMusic Plugins Jan 27 15:43:08 volumio volumio[14183]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 27 15:43:08 volumio volumio[14183]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 27 15:43:08 volumio volumio[14183]: info: Loading plugins from folder /data/plugins/ Jan 27 15:43:08 volumio volumio[14183]: info: Loading plugin "system"... Jan 27 15:43:08 volumio volumio[14183]: info: Loading plugin "appearance"... Jan 27 15:43:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:43:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:43:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:43:10 volumio volumio[14183]: info: Loading plugin "network"... Jan 27 15:43:10 volumio volumio[14183]: info: Refreshing Cached IP Addresses Jan 27 15:43:10 volumio sudo[14222]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 15:43:10 volumio sudo[14222]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:43:10 volumio sudo[14224]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 15:43:10 volumio sudo[14224]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:43:10 volumio sudo[14222]: pam_unix(sudo:session): session closed for user root Jan 27 15:43:10 volumio volumio[14183]: info: Loading plugin "services"... Jan 27 15:43:10 volumio volumio[14183]: info: Loading plugin "alsa_controller"... Jan 27 15:43:10 volumio sudo[14224]: pam_unix(sudo:session): session closed for user root Jan 27 15:43:10 volumio sudo[14232]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 27 15:43:10 volumio sudo[14232]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:43:10 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 15:43:10 volumio volumio[14183]: info: Loading plugin "wizard"... Jan 27 15:43:11 volumio volumio[14183]: info: Loading plugin "networkfs"... Jan 27 15:43:11 volumio volumio[14183]: info: Starting Udev Watcher for removable devices Jan 27 15:43:11 volumio volumio[14183]: info: Ignoring mount for partition: boot Jan 27 15:43:11 volumio volumio[14183]: info: Ignoring mount for partition: volumio Jan 27 15:43:11 volumio volumio[14183]: info: Ignoring mount for partition: volumio_data Jan 27 15:43:11 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 15:43:11 volumio volumio[14183]: info: Loading plugin "volumio_command_line_client"... Jan 27 15:43:11 volumio volumio[14183]: info: Loading plugin "upnp"... Jan 27 15:43:11 volumio volumio[14183]: info: [1769503391153] Starting Upmpd Daemon Jan 27 15:43:11 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 15:43:11 volumio volumio[14183]: info: Loading plugin "my_music"... Jan 27 15:43:11 volumio volumio[14183]: info: Loading plugin "mpd"... Jan 27 15:43:11 volumio volumio[14183]: info: Loading plugin "upnp_browser"... Jan 27 15:43:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Jan 27 15:43:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:43:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:43:12 volumio go-librespot[14255]: go-librespot daemon starting... Jan 27 15:43:12 volumio go-librespot[14256]: time="2026-01-27T15:43:12+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 15:43:12 volumio go-librespot[14256]: time="2026-01-27T15:43:12+07:00" level=debug msg="app state loaded" Jan 27 15:43:12 volumio go-librespot[14256]: time="2026-01-27T15:43:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 15:43:12 volumio go-librespot[14256]: time="2026-01-27T15:43:12+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 15:43:12 volumio go-librespot[14256]: time="2026-01-27T15:43:12+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 15:43:12 volumio go-librespot[14256]: time="2026-01-27T15:43:12+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 15:43:12 volumio go-librespot[14256]: time="2026-01-27T15:43:12+07:00" level=info msg="zeroconf server listening on port 35719" Jan 27 15:43:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:43:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:43:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:43:12 volumio go-librespot[14256]: time="2026-01-27T15:43:12+07:00" level=debug msg="obtained new client token: AAAduqiuKLO1ljSE4SsJr+h4YErCnLcEIxFPlzgoD8l1ckXBejpIQqFmZHO4lXPkNdAJnpqvUkN112HYj+228zhCNjIglIMt0vM5a0VlfKgDiKHQzTcd79sh6Bvwt2G9ZSUpA3Etu6lxOY6AJIGMTE5RsqJ+k4/4vuIqzVM6qVZ7+6WCEpy4qY5DVEGBf+S1GfI+C5aL4l/HdfgmgPO7sd/hEZVEay4Bbc8J15PlYW127NFqvxK5p97DD5k=" Jan 27 15:43:12 volumio go-librespot[14256]: time="2026-01-27T15:43:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 15:43:13 volumio go-librespot[14256]: time="2026-01-27T15:43:13+07:00" level=debug msg="completed keyexchange" Jan 27 15:43:13 volumio go-librespot[14256]: time="2026-01-27T15:43:13+07:00" level=debug msg="completed challenge" Jan 27 15:43:13 volumio go-librespot[14256]: time="2026-01-27T15:43:13+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 15:43:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 15:43:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 15:43:13 volumio sudo[14232]: pam_unix(sudo:session): session closed for user root Jan 27 15:43:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:43:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:43:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:43:14 volumio volumio[14183]: info: Starting UPNP Browser Jan 27 15:43:14 volumio volumio[14183]: info: Loading plugin "alarm-clock"... Jan 27 15:43:15 volumio volumio[14183]: info: Loading plugin "airplay_emulation"... Jan 27 15:43:15 volumio volumio[14183]: info: Starting Shairport Sync Jan 27 15:43:15 volumio volumio[14183]: info: Loading plugin "last_100"... Jan 27 15:43:15 volumio volumio[14183]: info: Loading plugin "webradio"... Jan 27 15:43:15 volumio volumio[14183]: info: Loading plugin "i2s_dacs"... Jan 27 15:43:15 volumio volumio[14183]: info: Loading plugin "volumiodiscovery"... Jan 27 15:43:15 volumio volumio[14183]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 15:43:15 volumio volumio[14183]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 15:43:15 volumio volumio[14183]: *** WARNING *** For more information see Jan 27 15:43:15 volumio volumio[14183]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 15:43:15 volumio volumio[14183]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 15:43:15 volumio volumio[14183]: *** WARNING *** For more information see Jan 27 15:43:15 volumio node[14183]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 15:43:15 volumio node[14183]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 15:43:15 volumio node[14183]: *** WARNING *** For more information see Jan 27 15:43:15 volumio node[14183]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 15:43:15 volumio node[14183]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 15:43:15 volumio node[14183]: *** WARNING *** For more information see Jan 27 15:43:15 volumio volumio[14183]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 27 15:43:15 volumio volumio[14183]: info: Discovery: Started advertising with name: Volumio Jan 27 15:43:15 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 15:43:15 volumio volumio[14183]: info: Loading plugin "spop"... Jan 27 15:43:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Jan 27 15:43:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:43:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:43:16 volumio go-librespot[14265]: go-librespot daemon starting... Jan 27 15:43:16 volumio go-librespot[14266]: time="2026-01-27T15:43:16+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 15:43:16 volumio go-librespot[14266]: time="2026-01-27T15:43:16+07:00" level=debug msg="app state loaded" Jan 27 15:43:16 volumio go-librespot[14266]: time="2026-01-27T15:43:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 15:43:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:43:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:43:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:43:16 volumio go-librespot[14266]: time="2026-01-27T15:43:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 15:43:16 volumio go-librespot[14266]: time="2026-01-27T15:43:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 15:43:16 volumio go-librespot[14266]: time="2026-01-27T15:43:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 15:43:16 volumio go-librespot[14266]: time="2026-01-27T15:43:16+07:00" level=info msg="zeroconf server listening on port 39071" Jan 27 15:43:17 volumio go-librespot[14266]: time="2026-01-27T15:43:17+07:00" level=debug msg="obtained new client token: AACTDE1f9sf3us1tU/qeixdp2Im366rBqKyvCWkdWdmYKAdWBASegCdA+umait6yRGNdgIbfglzTmKqleRWvblTnys4jrRLQ0iD1bBfxSmhuTLNwP97ulAQ5XRd0MfHHRabKcvL98XD5MWmMNCRNIvqJUEGykma8sulBG3/InxWh2WJXXX+x5fc3nhUjCk2MIWqkXWvkeBOYB6BX5vdBq3aXdKrGKHCTah3Rv2YAfoh4+XqgpOV5+D1+" Jan 27 15:43:17 volumio go-librespot[14266]: time="2026-01-27T15:43:17+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 27 15:43:17 volumio volumio[14183]: info: Loading plugin "ytcr"... Jan 27 15:43:17 volumio go-librespot[14266]: time="2026-01-27T15:43:17+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Jan 27 15:43:17 volumio go-librespot[14266]: time="2026-01-27T15:43:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Jan 27 15:43:17 volumio go-librespot[14266]: time="2026-01-27T15:43:17+07:00" level=debug msg="completed keyexchange" Jan 27 15:43:17 volumio go-librespot[14266]: time="2026-01-27T15:43:17+07:00" level=debug msg="completed challenge" Jan 27 15:43:17 volumio go-librespot[14266]: time="2026-01-27T15:43:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 15:43:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 15:43:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 15:43:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:43:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:43:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:43:19 volumio volumio[14183]: info: Loading plugin "ytmusic"... Jan 27 15:43:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:43:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:43:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:43:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Jan 27 15:43:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:43:20 volumio volumio-remote-updater[628]: [2026-01-27 15:43:20] [connect] Successful connection Jan 27 15:43:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:43:20 volumio go-librespot[14273]: go-librespot daemon starting... Jan 27 15:43:20 volumio go-librespot[14274]: time="2026-01-27T15:43:20+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 15:43:20 volumio go-librespot[14274]: time="2026-01-27T15:43:20+07:00" level=debug msg="app state loaded" Jan 27 15:43:20 volumio go-librespot[14274]: time="2026-01-27T15:43:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 15:43:21 volumio volumio[14183]: info: Loading plugin "outputs"... Jan 27 15:43:21 volumio volumio[14183]: info: Loading plugin "albumart"... Jan 27 15:43:21 volumio volumio[14183]: info: Plugin example_plugin is not enabled Jan 27 15:43:21 volumio volumio[14183]: info: Loading plugin "inputs"... Jan 27 15:43:21 volumio volumio[14183]: info: Loading plugin "updater_comm"... Jan 27 15:43:21 volumio volumio[14183]: info: Plugin mpdemulation is not enabled Jan 27 15:43:21 volumio volumio[14183]: info: Loading plugin "rest_api"... Jan 27 15:43:21 volumio volumio[14183]: info: Loading plugin "websocket"... Jan 27 15:43:21 volumio go-librespot[14274]: time="2026-01-27T15:43:21+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 15:43:21 volumio go-librespot[14274]: time="2026-01-27T15:43:21+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 27 15:43:21 volumio go-librespot[14274]: time="2026-01-27T15:43:21+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 27 15:43:21 volumio volumio[14183]: info: Starting Socket.io Server version 1.7.4 Jan 27 15:43:21 volumio go-librespot[14274]: time="2026-01-27T15:43:21+07:00" level=info msg="zeroconf server listening on port 32803" Jan 27 15:43:21 volumio volumio[14183]: info: Loading plugin "RoonBridge"... Jan 27 15:43:21 volumio go-librespot[14274]: time="2026-01-27T15:43:21+07:00" level=debug msg="obtained new client token: AABGZklori/8I+wUa/YvxyZMVl0mpei6K7lC7FBpQx3wNBnkWlluw4RY91aFpXwxIcg7MGYsGmp3vm01ahvG6hOf+jbMswEyzPNB2EnqmEq10XNNbf+wQQaRsuDvWxeBglGHVfWzGFS8/bB33za45l83cTz5d8Afmi4jW2E1WhK3StdCJ597q+ngV5KVT9dIF5H3TQOosxhFLBmgTbDOxlpli7ycKSmAl0Vtf2qxhnd8G3kCFE5eILpWm3k=" Jan 27 15:43:21 volumio go-librespot[14274]: time="2026-01-27T15:43:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 15:43:21 volumio go-librespot[14274]: time="2026-01-27T15:43:21+07:00" level=debug msg="completed keyexchange" Jan 27 15:43:21 volumio go-librespot[14274]: time="2026-01-27T15:43:21+07:00" level=debug msg="completed challenge" Jan 27 15:43:21 volumio volumio[14183]: info: Applying required configuration parameters for plugin RoonBridge Jan 27 15:43:22 volumio go-librespot[14274]: time="2026-01-27T15:43:22+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 15:43:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 15:43:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 15:43:22 volumio volumio[14183]: info: Loading i18n strings for locale en Jan 27 15:43:22 volumio volumio[14183]: Updating browse sources language Jan 27 15:43:22 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 15:43:22 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 15:43:22 volumio volumio[14183]: info: CoreCommandRouter::initPlayerControls Jan 27 15:43:22 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:43:22 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:43:22 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:43:22 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:43:22 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:43:22 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:43:22 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:43:22 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:43:22 volumio volumio[14295]: Forking 3 albumart workers Jan 27 15:43:22 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 15:43:22 volumio volumio[14183]: Express server listening on port 3000 Jan 27 15:43:22 volumio volumio[14183]: [Metrics] WebUI: 16s 91.00ms Jan 27 15:43:22 volumio volumio[14183]: info: CoreStateMachine::resetVolumioState Jan 27 15:43:22 volumio volumio[14183]: info: CoreStateMachine::getcurrentVolume Jan 27 15:43:22 volumio volumio[14183]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 15:43:22 volumio sudo[14337]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 15:43:22 volumio sudo[14337]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:43:22 volumio sudo[14337]: pam_unix(sudo:session): session closed for user root Jan 27 15:43:22 volumio sudo[14339]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 15:43:22 volumio sudo[14339]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:43:22 volumio sudo[14339]: pam_unix(sudo:session): session closed for user root Jan 27 15:43:22 volumio volumio[14183]: info: Volumio Network Manager: Network status updated: 1 Jan 27 15:43:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:43:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:43:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:43:22 volumio volumio[14183]: info: VolumeController:: Volume=100 Mute =false Jan 27 15:43:22 volumio volumio[14183]: info: CoreStateMachine::pushState Jan 27 15:43:22 volumio volumio[14183]: info: CorePlayQueue::getTrack 0 Jan 27 15:43:22 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 15:43:22 volumio volumio[14183]: info: CoreCommandRouter::volumioPushState Jan 27 15:43:22 volumio volumio[14183]: info: CoreStateMachine::updateTrackBlock Jan 27 15:43:22 volumio volumio[14183]: info: CorePlayQueue::getTrackBlock Jan 27 15:43:22 volumio volumio[14183]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 15:43:23 volumio volumio-remote-updater[628]: [2026-01-27 15:43:23] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769503400 101 Jan 27 15:43:23 volumio volumio[14183]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 27 15:43:23 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:43:23 volumio volumio[14183]: info: Reloading queue from file Jan 27 15:43:23 volumio volumio[14183]: info: CoreStateMachine::setRepeat null single undefined Jan 27 15:43:23 volumio volumio[14183]: info: CoreStateMachine::pushState Jan 27 15:43:23 volumio volumio[14183]: info: CorePlayQueue::getTrack 0 Jan 27 15:43:23 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 15:43:23 volumio volumio[14183]: info: CoreCommandRouter::volumioPushState Jan 27 15:43:23 volumio volumio[14183]: info: CoreStateMachine::setRandom null Jan 27 15:43:23 volumio volumio[14183]: info: CoreStateMachine::pushState Jan 27 15:43:23 volumio volumio[14183]: info: CorePlayQueue::getTrack 0 Jan 27 15:43:23 volumio volumio[14183]: info: CoreCommandRouter::volumioPushState Jan 27 15:43:23 volumio volumio[14183]: info: Setting Device type: Raspberry PI Jan 27 15:43:23 volumio volumio[14183]: info: Completed loading Core Plugins Jan 27 15:43:23 volumio volumio[14183]: info: Preparing to generate the ALSA configuration file Jan 27 15:43:23 volumio volumio[14183]: info: VolumeController:: Volume=100 Mute =false Jan 27 15:43:23 volumio volumio[14183]: info: CoreStateMachine::pushState Jan 27 15:43:23 volumio volumio[14183]: info: CorePlayQueue::getTrack 0 Jan 27 15:43:23 volumio volumio[14183]: info: CoreCommandRouter::volumioPushState Jan 27 15:43:23 volumio volumio[14183]: info: Asound.conf file unchanged, so no further update is needed Jan 27 15:43:23 volumio volumio[14183]: info: Output device has changed, restarting MPD Jan 27 15:43:23 volumio volumio[14183]: info: Output device has changed, restarting Shairport Sync Jan 27 15:43:23 volumio sudo[14357]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 27 15:43:23 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:43:23 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:43:23 volumio sudo[14357]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:43:23 volumio sudo[14359]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 15:43:23 volumio sudo[14359]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:43:23 volumio volumio[14183]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 15:43:23 volumio sudo[14361]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 15:43:23 volumio volumio[14183]: info: ___________ START PLUGINS ___________ Jan 27 15:43:23 volumio sudo[14359]: pam_unix(sudo:session): session closed for user root Jan 27 15:43:23 volumio volumio[14183]: info: ControllerMpd::onStart: Initializing MPD Jan 27 15:43:23 volumio sudo[14361]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:43:23 volumio volumio[14183]: info: Creating MPD Configuration file Jan 27 15:43:23 volumio sudo[14357]: pam_unix(sudo:session): session closed for user root Jan 27 15:43:23 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 15:43:23 volumio volumio[14183]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 15:43:23 volumio volumio[14183]: info: [1769503403737] CoreMusicLibrary::Adding element Media Servers Jan 27 15:43:23 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 15:43:23 volumio volumio[14183]: info: UPNP Browser: Client initialized successfully Jan 27 15:43:23 volumio sudo[14370]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 15:43:23 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 27 15:43:23 volumio sudo[14370]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:43:23 volumio sudo[14370]: pam_unix(sudo:session): session closed for user root Jan 27 15:43:23 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:43:23 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:43:23 volumio sudo[14372]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 15:43:23 volumio sudo[14372]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:43:23 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 15:43:23 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 15:43:23 volumio systemd[1]: mpd.service: Consumed 7.521s CPU time. Jan 27 15:43:23 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 15:43:23 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 15:43:23 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 15:43:23 volumio volumio[14183]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 15:43:24 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:43:24 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:43:24 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 15:43:24 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 15:43:24 volumio volumio[14183]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 15:43:24 volumio volumio[14183]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 15:43:24 volumio volumio[14183]: info: [1769503404133] CoreMusicLibrary::Adding element Last_100 Jan 27 15:43:24 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 15:43:24 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 15:43:24 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 15:43:24 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 15:43:24 volumio volumio[14183]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 15:43:24 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 15:43:24 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 15:43:24 volumio volumio[14183]: info: [1769503404161] CoreMusicLibrary::Adding element Webradio Jan 27 15:43:24 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 15:43:24 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 15:43:24 volumio volumio[14183]: info: Initializing BBC Radios Jan 27 15:43:24 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 15:43:24 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 15:43:24 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 15:43:24 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:43:24 volumio volumio[14183]: info: Creating Spotify config file Jan 27 15:43:24 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:43:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:43:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:43:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:43:24 volumio sudo[14394]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 27 15:43:24 volumio sudo[14394]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 27 15:43:24 volumio sudo[14394]: pam_unix(sudo:session): session closed for user root Jan 27 15:43:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Jan 27 15:43:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:43:25 volumio volumio[14305]: Starting albumart workers Jan 27 15:43:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:43:25 volumio go-librespot[14402]: go-librespot daemon starting... Jan 27 15:43:25 volumio go-librespot[14403]: time="2026-01-27T15:43:25+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 15:43:25 volumio volumio[14183]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 15:43:25 volumio volumio[14183]: info: [1769503405516] CoreMusicLibrary::Adding element YouTube Music Jan 27 15:43:25 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 15:43:25 volumio volumio[14183]: Cannot find translation for source YouTube Music Jan 27 15:43:25 volumio volumio[14183]: info: Volumio Calling Home Jan 27 15:43:25 volumio sudo[14410]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 27 15:43:25 volumio sudo[14410]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:43:25 volumio sudo[14410]: pam_unix(sudo:session): session closed for user root Jan 27 15:43:25 volumio volumio[14309]: Starting albumart workers Jan 27 15:43:26 volumio go-librespot[14403]: time="2026-01-27T15:43:26+07:00" level=info msg="zeroconf server listening on port 36833" Jan 27 15:43:26 volumio volumio[14307]: Starting albumart workers Jan 27 15:43:26 volumio volumio[14183]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 15:43:26 volumio volumio[14183]: info: Discovery: Found device Volumio Jan 27 15:43:26 volumio volumio[14183]: info: CoreCommandRouter::volumioGetState Jan 27 15:43:26 volumio volumio[14183]: info: CorePlayQueue::getTrack 0 Jan 27 15:43:26 volumio volumio[14183]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 15:43:26 volumio volumio[14183]: info: Discovery: Found device Volumio Jan 27 15:43:26 volumio volumio[14183]: info: CoreCommandRouter::volumioGetState Jan 27 15:43:26 volumio volumio[14183]: info: CorePlayQueue::getTrack 0 Jan 27 15:43:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:43:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:43:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:43:26 volumio volumio[14183]: info: MPD Permissions set Jan 27 15:43:26 volumio volumio[14183]: info: MPD Permissions set Jan 27 15:43:26 volumio volumio[14183]: info: Upmpdcli Daemon Started Jan 27 15:43:26 volumio volumio[14183]: info: Volumio called home Jan 27 15:43:26 volumio volumio[14183]: info: Spotify config file written Jan 27 15:43:27 volumio sudo[14420]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 15:43:27 volumio sudo[14420]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:43:27 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 27 15:43:27 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 27 15:43:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:43:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:43:27 volumio sudo[14420]: pam_unix(sudo:session): session closed for user root Jan 27 15:43:27 volumio go-librespot[14426]: go-librespot daemon starting... Jan 27 15:43:27 volumio go-librespot[14427]: time="2026-01-27T15:43:27+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 15:43:27 volumio go-librespot[14427]: time="2026-01-27T15:43:27+07:00" level=debug msg="app state loaded" Jan 27 15:43:27 volumio go-librespot[14427]: time="2026-01-27T15:43:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 15:43:27 volumio volumio[14183]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 27 15:43:27 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:43:27 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:43:27 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:43:27 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:43:27 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:43:27 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:43:27 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:43:27 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:43:27 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:43:27 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:43:27 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:43:27 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:43:27 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:43:27 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:43:27 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:43:27 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:43:27 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:43:28 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:43:28 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:43:28 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 15:43:28 volumio volumio[14183]: info: No need to fix Spotify hosts Jan 27 15:43:28 volumio go-librespot[14427]: time="2026-01-27T15:43:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 15:43:28 volumio go-librespot[14427]: time="2026-01-27T15:43:28+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 15:43:28 volumio go-librespot[14427]: time="2026-01-27T15:43:28+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 15:43:28 volumio go-librespot[14427]: time="2026-01-27T15:43:28+07:00" level=info msg="zeroconf server listening on port 37981" Jan 27 15:43:28 volumio go-librespot[14427]: time="2026-01-27T15:43:28+07:00" level=debug msg="obtained new client token: AAD/uuExnCAlajAwUAydUSS/h+hJvs6FeU+iqf8KuqbnD5q1290CUjW3Y0YO1S98MpYiSFETGY5tJdK9c4A/xlxm2wuC/KJ6sti2LIpL82AFAHwPM0lQgYTt0E+Kaiit78ubgR2wWIxuyXRQ2Pq2LOyxtr9F2qTFyODCgrhZu5togMEc1926H0raFxAytaMNYDOLJEEDc2M6g7Vdx95EjGXIkoB3Zk3+pZrv/QLzDoNR3eSBOu2KPAdeRqI=" Jan 27 15:43:28 volumio go-librespot[14427]: time="2026-01-27T15:43:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 15:43:28 volumio volumio[14183]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 15:43:28 volumio volumio[14183]: SPOTIFY: BQC5Z9CvuIYSQjL9lHG3seQQYgGhZGcjxS6hxatYgJmyxGSVOj4Jdsqbab0zkLdVqSSL6aQKBufbVQml14EwFyFNQYVQ0PqAp4lnlX7qRQTF2O0hLNxs7MCrvyUM6pnauLu7xnOvHOqVR9YsZSPaXWh2Zwoy9OsSO5iRzt8BILRcHnWGuNDYKo1Df0QxzrfMhLiu9WujpXW7aI67RRqZek4mX7LdPn9vzs2FvCys55IO0CscmpLiit-yLnBkXaVu6MA1_fzUXs1xSK3hEHcz1SaOh7UIvjgWvBxKh5lTzis79OQmfyoUhVce Jan 27 15:43:28 volumio volumio[14183]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 15:43:28 volumio volumio[14183]: info: New Spotify access token = BQC5Z9CvuIYSQjL9lHG3seQQYgGhZGcjxS6hxatYgJmyxGSVOj4Jdsqbab0zkLdVqSSL6aQKBufbVQml14EwFyFNQYVQ0PqAp4lnlX7qRQTF2O0hLNxs7MCrvyUM6pnauLu7xnOvHOqVR9YsZSPaXWh2Zwoy9OsSO5iRzt8BILRcHnWGuNDYKo1Df0QxzrfMhLiu9WujpXW7aI67RRqZek4mX7LdPn9vzs2FvCys55IO0CscmpLiit-yLnBkXaVu6MA1_fzUXs1xSK3hEHcz1SaOh7UIvjgWvBxKh5lTzis79OQmfyoUhVce Jan 27 15:43:28 volumio volumio[14183]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 27 15:43:28 volumio go-librespot[14427]: time="2026-01-27T15:43:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 15:43:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 15:43:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 15:43:28 volumio volumio[14183]: info: Starting Shairport Sync Jan 27 15:43:28 volumio volumio[14183]: info: Starting Shairport Sync Jan 27 15:43:28 volumio volumio[14183]: info: Starting Shairport Sync Jan 27 15:43:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:43:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:43:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:43:28 volumio sudo[14460]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 15:43:28 volumio sudo[14460]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:43:28 volumio sudo[14465]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 15:43:28 volumio sudo[14465]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:43:28 volumio sudo[14462]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 15:43:28 volumio sudo[14462]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:43:28 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 15:43:28 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 15:43:29 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 15:43:29 volumio systemd[1]: shairport-sync.service: Consumed 2.397s CPU time. Jan 27 15:43:29 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 15:43:29 volumio sudo[14460]: pam_unix(sudo:session): session closed for user root Jan 27 15:43:29 volumio sudo[14462]: pam_unix(sudo:session): session closed for user root Jan 27 15:43:29 volumio sudo[14465]: pam_unix(sudo:session): session closed for user root Jan 27 15:43:29 volumio volumio[14183]: info: Shairport-Sync Started Jan 27 15:43:29 volumio volumio[14183]: Error adding Membership: Error: addMembership EINVAL Jan 27 15:43:29 volumio volumio[14183]: info: Shairport-Sync Started Jan 27 15:43:29 volumio volumio[14183]: info: Shairport-Sync Started Jan 27 15:43:29 volumio volumio[14183]: info: CoreCommandRouter::volumioGetState Jan 27 15:43:29 volumio volumio[14183]: info: CorePlayQueue::getTrack 0 Jan 27 15:43:29 volumio volumio[14183]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Jan 27 15:43:29 volumio volumio[14183]: info: Spotify Successfully logged in Jan 27 15:43:29 volumio volumio[14183]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 15:43:29 volumio volumio[14183]: info: [1769503409630] CoreMusicLibrary::Adding element Spotify Jan 27 15:43:29 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 15:43:29 volumio volumio[14183]: Cannot find translation for source YouTube Music Jan 27 15:43:29 volumio volumio[14183]: Cannot find translation for source Spotify Jan 27 15:43:30 volumio volumio[14183]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 27 15:43:30 volumio volumio[14183]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 15:43:30 volumio volumio[14183]: info: VolumeController:: Volume=100 Mute =false Jan 27 15:43:30 volumio volumio[14183]: info: CoreCommandRouter::volumioGetState Jan 27 15:43:30 volumio volumio[14183]: info: CorePlayQueue::getTrack 0 Jan 27 15:43:30 volumio volumio[14183]: info: CoreStateMachine::pushState Jan 27 15:43:30 volumio volumio[14183]: info: CorePlayQueue::getTrack 0 Jan 27 15:43:30 volumio volumio[14183]: info: CoreCommandRouter::volumioPushState Jan 27 15:43:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:43:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:43:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:43:31 volumio volumio[14183]: info: go-librespot daemon successfully initialized Jan 27 15:43:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 27 15:43:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:43:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:43:31 volumio go-librespot[14500]: go-librespot daemon starting... Jan 27 15:43:31 volumio mpd[14401]: 2026-01-27T15:43:31 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 27 15:43:31 volumio go-librespot[14501]: time="2026-01-27T15:43:31+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 15:43:31 volumio go-librespot[14501]: time="2026-01-27T15:43:31+07:00" level=debug msg="app state loaded" Jan 27 15:43:31 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 27 15:43:31 volumio go-librespot[14501]: time="2026-01-27T15:43:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 15:43:31 volumio sudo[14361]: pam_unix(sudo:session): session closed for user root Jan 27 15:43:31 volumio sudo[14372]: pam_unix(sudo:session): session closed for user root Jan 27 15:43:32 volumio volumio[14183]: error: MPD error: The expression evaluated to a falsy value: Jan 27 15:43:32 volumio volumio[14183]: assert.ok(self.idling) Jan 27 15:43:32 volumio volumio[14183]: error: The expression evaluated to a falsy value: Jan 27 15:43:32 volumio volumio[14183]: assert.ok(self.idling) Jan 27 15:43:32 volumio volumio[14183]: error: updateQueue error: null Jan 27 15:43:32 volumio volumio[14183]: info: MPD running with PID14401 Jan 27 15:43:32 volumio volumio[14183]: ,establishing connection Jan 27 15:43:32 volumio volumio[14183]: info: Completed starting Core Plugins Jan 27 15:43:32 volumio volumio[14183]: info: ------------------------------------------- Jan 27 15:43:32 volumio volumio[14183]: info: ----- MyVolumio plugins startup ---- Jan 27 15:43:32 volumio volumio[14183]: info: ------------------------------------------- Jan 27 15:43:32 volumio volumio[14183]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 27 15:43:32 volumio volumio[14183]: error: updateQueue error: null Jan 27 15:43:32 volumio go-librespot[14501]: time="2026-01-27T15:43:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 15:43:32 volumio go-librespot[14501]: time="2026-01-27T15:43:32+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 15:43:32 volumio go-librespot[14501]: time="2026-01-27T15:43:32+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 15:43:32 volumio go-librespot[14501]: time="2026-01-27T15:43:32+07:00" level=info msg="zeroconf server listening on port 46515" Jan 27 15:43:32 volumio go-librespot[14501]: time="2026-01-27T15:43:32+07:00" level=debug msg="obtained new client token: AAAtvncaKLizpBNzSu+iymYHqj0bsVlZg6k8mm/f0lIno5Qez36Q5zXRuUQP7CSoSSYPcN0O3jaeoPRNPGuJZJnbJYysUMzcNc7VnESIOMDoDU6uPBcT66BorByP4YbCvY+gxfRpUi3Vg+pm/19uFeLF7bWuPOGnIxvfIGmRA3d6QB6GVsSAR/yLKCkJvN74ejGJ99oVwlTHs9rifQL8zqlpwBZLmpkzpp+VsvvQqIVNjgs84QH0SRcrbPM=" Jan 27 15:43:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:43:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:43:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:43:32 volumio go-librespot[14501]: time="2026-01-27T15:43:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 15:43:32 volumio go-librespot[14501]: time="2026-01-27T15:43:32+07:00" level=debug msg="completed keyexchange" Jan 27 15:43:32 volumio go-librespot[14501]: time="2026-01-27T15:43:32+07:00" level=debug msg="completed challenge" Jan 27 15:43:32 volumio go-librespot[14501]: time="2026-01-27T15:43:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 15:43:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 15:43:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 15:43:34 volumio volumio[14183]: info: Initializing connection to go-librespot Websocket Jan 27 15:43:34 volumio volumio[14183]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 15:43:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:43:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:43:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:43:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 27 15:43:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:43:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:43:36 volumio go-librespot[14515]: go-librespot daemon starting... Jan 27 15:43:36 volumio go-librespot[14516]: time="2026-01-27T15:43:36+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 15:43:36 volumio go-librespot[14516]: time="2026-01-27T15:43:36+07:00" level=debug msg="app state loaded" Jan 27 15:43:36 volumio go-librespot[14516]: time="2026-01-27T15:43:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 15:43:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:43:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:43:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:43:36 volumio go-librespot[14516]: time="2026-01-27T15:43:36+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 15:43:36 volumio go-librespot[14516]: time="2026-01-27T15:43:36+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 15:43:36 volumio go-librespot[14516]: time="2026-01-27T15:43:36+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 15:43:36 volumio go-librespot[14516]: time="2026-01-27T15:43:36+07:00" level=info msg="zeroconf server listening on port 34701" Jan 27 15:43:37 volumio volumio[14183]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 27 15:43:37 volumio go-librespot[14516]: time="2026-01-27T15:43:37+07:00" level=debug msg="obtained new client token: AAANTqrKxzA/eDh8MPv6IEjckWSevm/bVOBmi+Xeyxn9/iSJ0KzQ2g6LrJLvVAzZh5mUM7EnWCgrXuaZ6/Rys6uh8yNQc31z99nZe1jPldNZnCD4fJ4ykXEJtEN1NJzQFqWjfzq8uQHZztcg2k1/jXq6R5F9XfMBMXUaNAtjYYtULzkGNF2SJn4z8QkJc/BP4zcltXfsk5amKRbvMEIVyr1n37AldtoYvYyjuyKqLRTRSOqG1S8zuBXL" Jan 27 15:43:37 volumio go-librespot[14516]: time="2026-01-27T15:43:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 15:43:37 volumio go-librespot[14516]: time="2026-01-27T15:43:37+07:00" level=debug msg="completed keyexchange" Jan 27 15:43:37 volumio go-librespot[14516]: time="2026-01-27T15:43:37+07:00" level=debug msg="completed challenge" Jan 27 15:43:37 volumio go-librespot[14516]: time="2026-01-27T15:43:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 15:43:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 15:43:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 15:43:37 volumio volumio[14183]: info: Initializing connection to go-librespot Websocket Jan 27 15:43:37 volumio volumio[14183]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 15:43:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:43:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:43:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:43:40 volumio volumio[14183]: info: Initializing connection to go-librespot Websocket Jan 27 15:43:40 volumio volumio[14183]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 15:43:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 27 15:43:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:43:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:43:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:43:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:43:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:43:40 volumio go-librespot[14524]: go-librespot daemon starting... Jan 27 15:43:40 volumio go-librespot[14525]: time="2026-01-27T15:43:40+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 15:43:40 volumio go-librespot[14525]: time="2026-01-27T15:43:40+07:00" level=debug msg="app state loaded" Jan 27 15:43:40 volumio go-librespot[14525]: time="2026-01-27T15:43:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 15:43:41 volumio volumio[14183]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 27 15:43:41 volumio volumio[14183]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 27 15:43:41 volumio volumio[14183]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 27 15:43:41 volumio volumio[14183]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 27 15:43:41 volumio volumio[14183]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 27 15:43:41 volumio volumio[14183]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 27 15:43:41 volumio volumio[14183]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 27 15:43:41 volumio volumio[14183]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 27 15:43:41 volumio volumio[14183]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 27 15:43:41 volumio volumio[14183]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 27 15:43:41 volumio volumio[14183]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 27 15:43:41 volumio volumio[14183]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 27 15:43:41 volumio volumio[14183]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 27 15:43:41 volumio volumio[14183]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 27 15:43:41 volumio volumio[14183]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 27 15:43:41 volumio volumio[14183]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 27 15:43:41 volumio volumio[14183]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 27 15:43:41 volumio volumio[14183]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 27 15:43:41 volumio volumio[14183]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 27 15:43:41 volumio volumio[14183]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 27 15:43:41 volumio volumio[14183]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 27 15:43:41 volumio volumio[14183]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 27 15:43:41 volumio volumio[14183]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 27 15:43:41 volumio volumio[14183]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 27 15:43:41 volumio volumio[14183]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 27 15:43:41 volumio volumio[14183]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 27 15:43:41 volumio volumio[14183]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 27 15:43:41 volumio volumio[14183]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 27 15:43:41 volumio volumio[14183]: info: Adding plugin bluetooth to MyMusic Plugins Jan 27 15:43:41 volumio volumio[14183]: info: Adding plugin multiroom to MyMusic Plugins Jan 27 15:43:41 volumio volumio[14183]: info: Adding plugin metavolumio to MyMusic Plugins Jan 27 15:43:41 volumio volumio[14183]: info: Adding plugin cd_controller to MyMusic Plugins Jan 27 15:43:41 volumio volumio[14183]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 27 15:43:41 volumio volumio[14183]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 27 15:43:41 volumio volumio[14183]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 27 15:43:41 volumio volumio[14183]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 27 15:43:41 volumio go-librespot[14525]: time="2026-01-27T15:43:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 15:43:41 volumio go-librespot[14525]: time="2026-01-27T15:43:41+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 15:43:41 volumio go-librespot[14525]: time="2026-01-27T15:43:41+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 15:43:41 volumio go-librespot[14525]: time="2026-01-27T15:43:41+07:00" level=info msg="zeroconf server listening on port 36179" Jan 27 15:43:41 volumio go-librespot[14525]: time="2026-01-27T15:43:41+07:00" level=debug msg="obtained new client token: AAAeiVB4GIZdTOuqENubV+UdzIGvgRpX9Hp6eXszgny6Oc8Zks0DgikV/kM+Msqc8dGQVsW7lluH8W3VcXg6wFdOCAjHCSSe/6K5YwRL2Cn5yVmzPPohOkLLzGpGFht7Ltm0kB9OLz6uzc6JEgdgTPbJ91TfBcrC9WyyCt4I7ayvckyzgHfuGSTNWyQ9Di00KGPDUlIwHMNoe+hOx7mWjftnv5ItekEgcxrdKBvCjOZo3oZdtlIiTi9qD64=" Jan 27 15:43:41 volumio go-librespot[14525]: time="2026-01-27T15:43:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 15:43:41 volumio go-librespot[14525]: time="2026-01-27T15:43:41+07:00" level=debug msg="completed keyexchange" Jan 27 15:43:41 volumio go-librespot[14525]: time="2026-01-27T15:43:41+07:00" level=debug msg="completed challenge" Jan 27 15:43:42 volumio go-librespot[14525]: time="2026-01-27T15:43:42+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 15:43:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 15:43:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 15:43:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:43:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:43:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:43:43 volumio volumio[14183]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 27 15:43:43 volumio volumio[14183]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 27 15:43:43 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:43:43 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:43:43 volumio volumio[14183]: info: Starting MyVolumio Remote Streaming Endpoints Jan 27 15:43:43 volumio volumio[14183]: info: MyVolumio login type: Token Jan 27 15:43:43 volumio volumio[14183]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 27 15:43:43 volumio volumio[14183]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 27 15:43:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:43:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:43:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:43:45 volumio volumio[14183]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 27 15:43:45 volumio volumio[14183]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 27 15:43:45 volumio volumio[14183]: info: Streaming services startup Jan 27 15:43:45 volumio volumio[14183]: info: Starting Streaming Daemon Jan 27 15:43:45 volumio sudo[14547]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 15:43:45 volumio volumio[14183]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 27 15:43:45 volumio sudo[14547]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:43:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 27 15:43:45 volumio sudo[14547]: pam_unix(sudo:session): session closed for user root Jan 27 15:43:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:43:45 volumio volumio[14183]: info: Initializing connection to go-librespot Websocket Jan 27 15:43:45 volumio volumio[14183]: error: Cannot start Volumio Streaming Daemon Jan 27 15:43:45 volumio volumio[14183]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 15:43:45 volumio volumio[14183]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 15:43:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:43:45 volumio go-librespot[14553]: go-librespot daemon starting... Jan 27 15:43:45 volumio volumio[14183]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 15:43:45 volumio go-librespot[14555]: time="2026-01-27T15:43:45+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 15:43:45 volumio go-librespot[14555]: time="2026-01-27T15:43:45+07:00" level=debug msg="app state loaded" Jan 27 15:43:45 volumio go-librespot[14555]: time="2026-01-27T15:43:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 15:43:45 volumio go-librespot[14555]: time="2026-01-27T15:43:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 15:43:45 volumio go-librespot[14555]: time="2026-01-27T15:43:45+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 15:43:45 volumio go-librespot[14555]: time="2026-01-27T15:43:45+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 15:43:45 volumio go-librespot[14555]: time="2026-01-27T15:43:45+07:00" level=info msg="zeroconf server listening on port 39999" Jan 27 15:43:46 volumio go-librespot[14555]: time="2026-01-27T15:43:46+07:00" level=debug msg="obtained new client token: AAAXIGFwDT7OK5O4g14nsytS0oygUfZkp9sZO1GMFVIAgk43T1jFOqAJg36NANHJ2foXW0cobGA9YJnzSzNr14Od1QQp77Jh7N0bD5q95ud+NVAJvHtI5cG8C+2cnIGqUStmQPukxZ8TEoX4ACjbNIx6gvJoTtfb2fK+vdh/xunpqBdfDSzCjZcySqCKsSUJ9Krw04ePBpUtV8Asr64IDsuTTIaM8aHEMt7orrc/M8qcJf+r1OQNJUNF" Jan 27 15:43:46 volumio go-librespot[14555]: time="2026-01-27T15:43:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 15:43:46 volumio volumio[14183]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 27 15:43:46 volumio go-librespot[14555]: time="2026-01-27T15:43:46+07:00" level=debug msg="completed keyexchange" Jan 27 15:43:46 volumio go-librespot[14555]: time="2026-01-27T15:43:46+07:00" level=debug msg="completed challenge" Jan 27 15:43:46 volumio go-librespot[14555]: time="2026-01-27T15:43:46+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 15:43:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 15:43:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 15:43:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:43:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:43:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:43:47 volumio volumio[14183]: info: MyVolumio token set successfully Jan 27 15:43:47 volumio volumio[14183]: info: MYVOLUMIO: Adding device Jan 27 15:43:47 volumio volumio[14183]: info: MYVOLUMIO: Evaluating Server Jan 27 15:43:47 volumio volumio[14183]: info: MyVolumio status changed Jan 27 15:43:47 volumio volumio[14183]: info: Streaming services startup Jan 27 15:43:47 volumio volumio[14183]: info: Starting Streaming Daemon Jan 27 15:43:47 volumio volumio[14183]: info: Removing browser output: myVolumio user plan is not superstar Jan 27 15:43:47 volumio volumio[14183]: info: Removing audio output: Jan 27 15:43:47 volumio volumio[14183]: info: Stoppping Tunnel 1 Jan 27 15:43:47 volumio sudo[14586]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 15:43:47 volumio sudo[14586]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:43:47 volumio sudo[14588]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 27 15:43:47 volumio sudo[14588]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:43:48 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 15:43:48 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 15:43:48 volumio sudo[14586]: pam_unix(sudo:session): session closed for user root Jan 27 15:43:48 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 15:43:48 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 15:43:48 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 15:43:48 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 15:43:48 volumio volumio[14183]: error: Cannot start Volumio Streaming Daemon Jan 27 15:43:48 volumio sudo[14588]: pam_unix(sudo:session): session closed for user root Jan 27 15:43:48 volumio volumio[14183]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 15:43:48 volumio volumio[14183]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 15:43:48 volumio volumio[14183]: info: Setting Geolocation for MyVolumio to as1 Jan 27 15:43:48 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:43:48 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:43:48 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:43:48 volumio volumio[14183]: info: Remote SSH Stopped Jan 27 15:43:48 volumio volumio[14183]: info: Initializing connection to go-librespot Websocket Jan 27 15:43:48 volumio volumio[14183]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 15:43:48 volumio volumio[14183]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 27 15:43:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:43:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:43:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:43:49 volumio volumio[14183]: info: Updating MyVolumio device info Jan 27 15:43:49 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:43:49 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:43:49 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:43:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 27 15:43:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:43:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:43:49 volumio go-librespot[14591]: go-librespot daemon starting... Jan 27 15:43:49 volumio volumio[14183]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jan 27 15:43:49 volumio go-librespot[14592]: time="2026-01-27T15:43:49+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 15:43:49 volumio go-librespot[14592]: time="2026-01-27T15:43:49+07:00" level=debug msg="app state loaded" Jan 27 15:43:49 volumio go-librespot[14592]: time="2026-01-27T15:43:49+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 15:43:50 volumio go-librespot[14592]: time="2026-01-27T15:43:50+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 15:43:50 volumio go-librespot[14592]: time="2026-01-27T15:43:50+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 15:43:50 volumio go-librespot[14592]: time="2026-01-27T15:43:50+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 15:43:50 volumio go-librespot[14592]: time="2026-01-27T15:43:50+07:00" level=info msg="zeroconf server listening on port 44431" Jan 27 15:43:50 volumio go-librespot[14592]: time="2026-01-27T15:43:50+07:00" level=debug msg="obtained new client token: AAAeqRdmTXJ5xgVR9Qg8TLIYYyhqJF6p9UndoVWlCRFxHkUow311ssHqKF50BizOMv2T9ifuKRFoJty0O3M2ws2xJVBlOAaQpJuXg1QBW5pQe5PFDGkcSLf9nPzZM/RILhoT/QWKs8v5ZaNls1sTm0QeuaFpfnlLDol4Wen1UUbdrf0jRc6uRLF7E4kfTfiov5GKBAbG+R0iiKenB/bTIDJ7lH5ONzrDSVIvzN6JUygyrR9hXUJCvzyi5Fw=" Jan 27 15:43:50 volumio go-librespot[14592]: time="2026-01-27T15:43:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 15:43:50 volumio go-librespot[14592]: time="2026-01-27T15:43:50+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 15:43:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 15:43:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 15:43:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:43:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:43:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:43:51 volumio volumio[14183]: info: Initializing connection to go-librespot Websocket Jan 27 15:43:51 volumio volumio[14183]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 15:43:52 volumio volumio[14183]: info: MYVOLUMIO: Adding device Jan 27 15:43:52 volumio volumio[14183]: info: MYVOLUMIO: Evaluating Server Jan 27 15:43:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:43:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:43:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:43:53 volumio volumio[14183]: info: Setting Geolocation for MyVolumio to as1 Jan 27 15:43:53 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:43:53 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:43:53 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:43:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 27 15:43:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:43:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:43:53 volumio go-librespot[14631]: go-librespot daemon starting... Jan 27 15:43:53 volumio go-librespot[14632]: time="2026-01-27T15:43:53+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 15:43:53 volumio go-librespot[14632]: time="2026-01-27T15:43:53+07:00" level=debug msg="app state loaded" Jan 27 15:43:53 volumio go-librespot[14632]: time="2026-01-27T15:43:53+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 15:43:53 volumio volumio[14183]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 27 15:43:54 volumio volumio[14183]: info: Initializing connection to go-librespot Websocket Jan 27 15:43:54 volumio go-librespot[14632]: time="2026-01-27T15:43:54+07:00" level=debug msg="new websocket client" Jan 27 15:43:54 volumio volumio[14183]: info: Connection to go-librespot Websocket established Jan 27 15:43:54 volumio go-librespot[14632]: time="2026-01-27T15:43:54+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 15:43:54 volumio go-librespot[14632]: time="2026-01-27T15:43:54+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 15:43:54 volumio go-librespot[14632]: time="2026-01-27T15:43:54+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 15:43:54 volumio go-librespot[14632]: time="2026-01-27T15:43:54+07:00" level=info msg="zeroconf server listening on port 46291" Jan 27 15:43:54 volumio volumio[14183]: info: Updating MyVolumio device info Jan 27 15:43:54 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:43:54 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:43:54 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:43:54 volumio go-librespot[14632]: time="2026-01-27T15:43:54+07:00" level=debug msg="obtained new client token: AAAHSoUn4SOOWB9dfVqsjS36KrfYo6cEba4qRqj6fAmandOrrlf4dwUUnkwn04gl1ZHguj49EHgQm1qexWFsdPMY1ej/n+TwaJLYsVOZT0gvufaiQYi60zJWJw8FDXXxKWgkr/bRL1tkG16C7IpHGTqgToCEPzZOKxUUKf7CLoR9TakiWx49KWOIBmj3rbcs+vpoR7QUFnE2td8NUXXmtJoWlYX64XslIfclDY3Hc82w13+6Vkfmihh95NY=" Jan 27 15:43:54 volumio go-librespot[14632]: time="2026-01-27T15:43:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 15:43:54 volumio go-librespot[14632]: time="2026-01-27T15:43:54+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 15:43:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 15:43:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 15:43:54 volumio volumio[14183]: info: Connection to go-librespot Websocket closed Jan 27 15:43:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:43:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:43:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:43:54 volumio volumio[14183]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jan 27 15:43:55 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 15:43:55 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 15:43:55 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 27 15:43:55 volumio volumio-remote-updater[628]: Test mode disabled Jan 27 15:43:55 volumio volumio-remote-updater[628]: Alpha mode disabled Jan 27 15:43:55 volumio volumio-remote-updater[628]: Alpha legacy test mode disabled Jan 27 15:43:55 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Jan 27 15:43:56 volumio volumio[14183]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Jan 27 15:43:56 volumio volumio[14183]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Jan 27 15:43:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:43:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:43:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:43:57 volumio volumio[14183]: info: Getting Spotify volume Jan 27 15:43:57 volumio volumio[14183]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 15:43:57 volumio volumio[14183]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 15:43:57 volumio volumio[14183]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 27 15:43:57 volumio volumio[14183]: errno: -111, Jan 27 15:43:57 volumio volumio[14183]: code: 'ECONNREFUSED', Jan 27 15:43:57 volumio volumio[14183]: syscall: 'connect', Jan 27 15:43:57 volumio volumio[14183]: address: '127.0.0.1', Jan 27 15:43:57 volumio volumio[14183]: port: 9879, Jan 27 15:43:57 volumio volumio[14183]: response: undefined Jan 27 15:43:57 volumio volumio[14183]: } Jan 27 15:43:57 volumio volumio[14183]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 15:43:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 27 15:43:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:43:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 15:43:57 volumio go-librespot[14655]: go-librespot daemon starting... Jan 27 15:43:57 volumio go-librespot[14656]: time="2026-01-27T15:43:57+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 15:43:57 volumio go-librespot[14656]: time="2026-01-27T15:43:57+07:00" level=debug msg="app state loaded" Jan 27 15:43:57 volumio go-librespot[14656]: time="2026-01-27T15:43:57+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 15:43:58 volumio go-librespot[14656]: time="2026-01-27T15:43:58+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 15:43:58 volumio go-librespot[14656]: time="2026-01-27T15:43:58+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 15:43:58 volumio go-librespot[14656]: time="2026-01-27T15:43:58+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 15:43:58 volumio go-librespot[14656]: time="2026-01-27T15:43:58+07:00" level=info msg="zeroconf server listening on port 37663" Jan 27 15:43:58 volumio go-librespot[14656]: time="2026-01-27T15:43:58+07:00" level=debug msg="obtained new client token: AAAGbcy1yzWHEszfrkQS2l+dYB7gbuw7Ugg4sI1tm9WAijQfAsXTrly+E4zsE88aCcwtXjZrQwVhv60lCQHI8EHSCBGu+NifEmcy+OMtrL55s9uRKwZIslKf/xZ/Dw7fved3lEZueunLS+TQp2IqMPzV91+EwElrofUwRuQOu+TKdfFH7RhxtTkKlmy0LA8616bF9o4r7Q4WjOEnRKPvqpoh++390DLOY4o0na1d2twF+04+jBRBAJxUqJE=" Jan 27 15:43:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 15:43:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 15:43:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 15:43:58 volumio go-librespot[14656]: time="2026-01-27T15:43:58+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 27 15:43:58 volumio go-librespot[14656]: time="2026-01-27T15:43:58+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 15:43:58 volumio sudo[14665]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 15:42' Jan 27 15:43:58 volumio sudo[14665]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 15:43:58 volumio go-librespot[14656]: time="2026-01-27T15:43:58+07:00" level=debug msg="completed keyexchange" Jan 27 15:43:58 volumio go-librespot[14656]: time="2026-01-27T15:43:58+07:00" level=debug msg="completed challenge" Jan 27 15:43:59 volumio go-librespot[14656]: time="2026-01-27T15:43:59+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 15:43:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 15:43:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"