Jan 27 21:27:00 volumio volumio[29488]: info: Initializing connection to go-librespot Websocket Jan 27 21:27:00 volumio volumio[29488]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:27:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:27:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:27:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:27:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 27 21:27:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:27:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:27:02 volumio go-librespot[29840]: go-librespot daemon starting... Jan 27 21:27:02 volumio go-librespot[29841]: time="2026-01-27T21:27:02+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:27:02 volumio go-librespot[29841]: time="2026-01-27T21:27:02+07:00" level=debug msg="app state loaded" Jan 27 21:27:02 volumio go-librespot[29841]: time="2026-01-27T21:27:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:27:03 volumio go-librespot[29841]: time="2026-01-27T21:27: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:27:03 volumio go-librespot[29841]: time="2026-01-27T21:27:03+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 21:27:03 volumio go-librespot[29841]: time="2026-01-27T21:27:03+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 21:27:03 volumio go-librespot[29841]: time="2026-01-27T21:27:03+07:00" level=info msg="zeroconf server listening on port 34731" Jan 27 21:27:03 volumio go-librespot[29841]: time="2026-01-27T21:27:03+07:00" level=debug msg="obtained new client token: AABNt1zoFg0Tq0qCQAAz50KIczBJWgXlx8XKw9ZeXI/oHTUaZPL9HYmO1Emya/Re4GzAFNd6McAnk8N49/o0hkjyVRQWIkJaCKfU31GBGfEv2TUtXZDw+pPbVrwuFcMpqGRlyRECiokmoGSH5J5zY7vz+EJ1ysvNbKSAfp1F8JRuTZmNaueq+5Bn/qo41IpiTMFp2jCy+tCfZbt3FZV1g7e2SmrcyZOAZ0sV8jvAILDxKioVO0/NsOC/KIs=" Jan 27 21:27:03 volumio go-librespot[29841]: time="2026-01-27T21:27:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:27:03 volumio go-librespot[29841]: time="2026-01-27T21:27:03+07:00" level=debug msg="completed keyexchange" Jan 27 21:27:03 volumio go-librespot[29841]: time="2026-01-27T21:27:03+07:00" level=debug msg="completed challenge" Jan 27 21:27:03 volumio volumio[29488]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 27 21:27:03 volumio go-librespot[29841]: time="2026-01-27T21:27:03+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 21:27:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:27:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:27:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:27:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:27:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:27:03 volumio volumio[29488]: info: Initializing connection to go-librespot Websocket Jan 27 21:27:03 volumio volumio[29488]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:27:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:27:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:27:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:27:06 volumio volumio[29488]: info: Initializing connection to go-librespot Websocket Jan 27 21:27:06 volumio volumio[29488]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:27:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 27 21:27:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:27:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:27:07 volumio go-librespot[29848]: go-librespot daemon starting... Jan 27 21:27:07 volumio go-librespot[29849]: time="2026-01-27T21:27:07+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:27:07 volumio go-librespot[29849]: time="2026-01-27T21:27:07+07:00" level=debug msg="app state loaded" Jan 27 21:27:07 volumio go-librespot[29849]: time="2026-01-27T21:27:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:27:07 volumio go-librespot[29849]: time="2026-01-27T21:27: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:27:07 volumio go-librespot[29849]: time="2026-01-27T21:27:07+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 21:27:07 volumio go-librespot[29849]: time="2026-01-27T21:27:07+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 21:27:07 volumio go-librespot[29849]: time="2026-01-27T21:27:07+07:00" level=info msg="zeroconf server listening on port 45441" Jan 27 21:27:07 volumio volumio[29488]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 27 21:27:07 volumio volumio[29488]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 27 21:27:07 volumio volumio[29488]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 27 21:27:07 volumio volumio[29488]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 27 21:27:07 volumio volumio[29488]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 27 21:27:07 volumio volumio[29488]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 27 21:27:07 volumio volumio[29488]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 27 21:27:07 volumio volumio[29488]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 27 21:27:07 volumio volumio[29488]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 27 21:27:07 volumio volumio[29488]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 27 21:27:07 volumio volumio[29488]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 27 21:27:07 volumio volumio[29488]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 27 21:27:07 volumio volumio[29488]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 27 21:27:07 volumio volumio[29488]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 27 21:27:07 volumio volumio[29488]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 27 21:27:07 volumio volumio[29488]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 27 21:27:07 volumio volumio[29488]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 27 21:27:07 volumio volumio[29488]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 27 21:27:07 volumio volumio[29488]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 27 21:27:07 volumio volumio[29488]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 27 21:27:07 volumio volumio[29488]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 27 21:27:07 volumio volumio[29488]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 27 21:27:07 volumio volumio[29488]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 27 21:27:07 volumio volumio[29488]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 27 21:27:07 volumio volumio[29488]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 27 21:27:07 volumio volumio[29488]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 27 21:27:07 volumio volumio[29488]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 27 21:27:07 volumio volumio[29488]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 27 21:27:07 volumio volumio[29488]: info: Adding plugin bluetooth to MyMusic Plugins Jan 27 21:27:07 volumio volumio[29488]: info: Adding plugin multiroom to MyMusic Plugins Jan 27 21:27:07 volumio volumio[29488]: info: Adding plugin metavolumio to MyMusic Plugins Jan 27 21:27:07 volumio volumio[29488]: info: Adding plugin cd_controller to MyMusic Plugins Jan 27 21:27:07 volumio volumio[29488]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 27 21:27:07 volumio volumio[29488]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 27 21:27:07 volumio volumio[29488]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 27 21:27:07 volumio volumio[29488]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 27 21:27:07 volumio go-librespot[29849]: time="2026-01-27T21:27:07+07:00" level=debug msg="obtained new client token: AAAW0AMpN7lxaztoV2etATASiYFF8l3ZkD90NFcM3cdBLnWNYMAP5/yli/8EhsVBjJgeOZwEE+jrS0HIQsCpePYe7n+qZcaa4nLp6Ni5H0i1MfHw0VMybejfgT+OSWt5+2vbfFn/jZuMfXVjI4VD5mWmBHi6i0Qrfm63QTTQk/CVni3r5nELK59Um7U5AP3Kw3b9Ddv5FSqypgilLGAjuydbsHKHqsAgAJnFilj+FeGmQgoJpOezfoIOoz8=" Jan 27 21:27:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:27:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:27:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:27:08 volumio go-librespot[29849]: time="2026-01-27T21:27:08+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 21:27:08 volumio go-librespot[29849]: time="2026-01-27T21:27:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 21:27:08 volumio go-librespot[29849]: time="2026-01-27T21:27:08+07:00" level=debug msg="completed keyexchange" Jan 27 21:27:08 volumio go-librespot[29849]: time="2026-01-27T21:27:08+07:00" level=debug msg="completed challenge" Jan 27 21:27:08 volumio go-librespot[29849]: time="2026-01-27T21:27:08+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 21:27:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:27:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:27:09 volumio volumio[29488]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 27 21:27:09 volumio volumio[29488]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 27 21:27:09 volumio volumio[29488]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:27:09 volumio volumio[29488]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:27:09 volumio volumio[29488]: info: Starting MyVolumio Remote Streaming Endpoints Jan 27 21:27:09 volumio volumio[29488]: info: MyVolumio login type: Token Jan 27 21:27:09 volumio volumio[29488]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 27 21:27:09 volumio volumio[29488]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 27 21:27:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:27:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:27:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:27:11 volumio volumio[29488]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 27 21:27:11 volumio volumio[29488]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 27 21:27:11 volumio volumio[29488]: info: Streaming services startup Jan 27 21:27:11 volumio volumio[29488]: info: Starting Streaming Daemon Jan 27 21:27:11 volumio sudo[29872]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 21:27:11 volumio volumio[29488]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 27 21:27:11 volumio sudo[29872]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:27:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 27 21:27:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:27:11 volumio volumio[29488]: info: Initializing connection to go-librespot Websocket Jan 27 21:27:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:27:11 volumio volumio[29488]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:27:11 volumio go-librespot[29878]: go-librespot daemon starting... Jan 27 21:27:11 volumio sudo[29872]: pam_unix(sudo:session): session closed for user root Jan 27 21:27:11 volumio volumio[29488]: error: Cannot start Volumio Streaming Daemon Jan 27 21:27:11 volumio volumio[29488]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 21:27:11 volumio volumio[29488]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 21:27:11 volumio go-librespot[29880]: time="2026-01-27T21:27:11+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:27:11 volumio go-librespot[29880]: time="2026-01-27T21:27:11+07:00" level=debug msg="app state loaded" Jan 27 21:27:11 volumio go-librespot[29880]: time="2026-01-27T21:27:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:27:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:27:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:27:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:27:12 volumio go-librespot[29880]: time="2026-01-27T21:27: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-gew4.spotify.com:80]" Jan 27 21:27:12 volumio go-librespot[29880]: time="2026-01-27T21:27:12+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 21:27:12 volumio go-librespot[29880]: time="2026-01-27T21:27:12+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 21:27:12 volumio go-librespot[29880]: time="2026-01-27T21:27:12+07:00" level=info msg="zeroconf server listening on port 34683" Jan 27 21:27:12 volumio go-librespot[29880]: time="2026-01-27T21:27:12+07:00" level=debug msg="obtained new client token: AADUvtYcdtgBE9k3H3SzgmxYaE5TxgAqWONic3An0KyY3yGR2l8mTqIzrsHIW3HN++Ux+2XWh6GNbFEo4XOzgOvcMZpN9wov0xY4wB9L7VIUiCyxeBWWcr5PI5/zfmWnO5Rt75GvXoPtRwgNAUGIX6YofjolBnCE9DOF2IbQz1UIdMPC0AcIona7XrSbWWJiL6oSaQkftiFrqZRxfMNWpBhhULJFD5scP3gx3Jp+JhhpeRL/wyaSFqPytxg=" Jan 27 21:27:12 volumio go-librespot[29880]: time="2026-01-27T21:27:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:27:12 volumio volumio[29488]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 27 21:27:12 volumio go-librespot[29880]: time="2026-01-27T21:27:12+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 21:27:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:27:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:27:13 volumio volumio[29488]: info: MyVolumio token set successfully Jan 27 21:27:13 volumio volumio[29488]: info: MYVOLUMIO: Adding device Jan 27 21:27:13 volumio volumio[29488]: info: MYVOLUMIO: Evaluating Server Jan 27 21:27:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:27:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:27:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:27:13 volumio volumio[29488]: info: MyVolumio status changed Jan 27 21:27:13 volumio volumio[29488]: info: Streaming services startup Jan 27 21:27:13 volumio volumio[29488]: info: Starting Streaming Daemon Jan 27 21:27:13 volumio volumio[29488]: info: Removing browser output: myVolumio user plan is not superstar Jan 27 21:27:13 volumio volumio[29488]: info: Removing audio output: Jan 27 21:27:13 volumio volumio[29488]: info: Stoppping Tunnel 1 Jan 27 21:27:14 volumio sudo[29909]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 21:27:14 volumio sudo[29909]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:27:14 volumio sudo[29909]: pam_unix(sudo:session): session closed for user root Jan 27 21:27:14 volumio volumio[29488]: error: Cannot start Volumio Streaming Daemon Jan 27 21:27:14 volumio volumio[29488]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 21:27:14 volumio volumio[29488]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 21:27:14 volumio sudo[29912]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 27 21:27:14 volumio sudo[29912]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:27:14 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 21:27:14 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 21:27:14 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 21:27:14 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 21:27:14 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 21:27:14 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 21:27:14 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 21:27:14 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 21:27:14 volumio sudo[29912]: pam_unix(sudo:session): session closed for user root Jan 27 21:27:14 volumio volumio[29488]: info: Remote SSH Stopped Jan 27 21:27:14 volumio volumio[29488]: info: Initializing connection to go-librespot Websocket Jan 27 21:27:14 volumio volumio[29488]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:27:15 volumio volumio[29488]: info: Setting Geolocation for MyVolumio to as1 Jan 27 21:27:15 volumio volumio[29488]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:27:15 volumio volumio[29488]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:27:15 volumio volumio[29488]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:27:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 27 21:27:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:27:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:27:15 volumio go-librespot[29914]: go-librespot daemon starting... Jan 27 21:27:15 volumio go-librespot[29915]: time="2026-01-27T21:27:15+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:27:15 volumio go-librespot[29915]: time="2026-01-27T21:27:15+07:00" level=debug msg="app state loaded" Jan 27 21:27:15 volumio go-librespot[29915]: time="2026-01-27T21:27:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:27:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:27:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:27:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:27:16 volumio go-librespot[29915]: time="2026-01-27T21:27: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 21:27:16 volumio go-librespot[29915]: time="2026-01-27T21:27: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 21:27:16 volumio go-librespot[29915]: time="2026-01-27T21:27: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 21:27:16 volumio go-librespot[29915]: time="2026-01-27T21:27:16+07:00" level=info msg="zeroconf server listening on port 35505" Jan 27 21:27:16 volumio go-librespot[29915]: time="2026-01-27T21:27:16+07:00" level=debug msg="obtained new client token: AAB0I5Ff8c4IrDfiVcfIMc66bzv91z4Ap1r4oYvRA6+F1+JnwkfgPNLAHW9s0/d6Y0I1xBeBXuRc+veHrFHRACEEH4c3nClcQwSmhZGluk5BJy9W6Cz77eq2jp+Z6iFRM22rc1jiRWXCmevD83JoGvMsWO++ocdHfqnPa4+4mxr6DY5K7Yjb2FrTvP1z834Kt8ruMSd6NY6RpYtrdIIwgcxIam9oW06DLhC7o2MPop5+H6tUIjHQDsO3wZ8=" Jan 27 21:27:16 volumio go-librespot[29915]: time="2026-01-27T21:27:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:27:16 volumio volumio[29488]: info: Updating MyVolumio device info Jan 27 21:27:16 volumio volumio[29488]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:27:16 volumio volumio[29488]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:27:16 volumio volumio[29488]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:27:16 volumio go-librespot[29915]: time="2026-01-27T21:27:16+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: read tcp 192.168.1.107:36100->104.199.241.202:4070: read: connection reset by peer" Jan 27 21:27:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:27:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:27:17 volumio volumio[29488]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 27 21:27:17 volumio volumio[29488]: info: Initializing connection to go-librespot Websocket Jan 27 21:27:17 volumio volumio[29488]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:27:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:27:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:27:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:27:17 volumio volumio[29488]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jan 27 21:27:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:27:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:27:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:27:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 27 21:27:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:27:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:27:20 volumio go-librespot[29938]: go-librespot daemon starting... Jan 27 21:27:20 volumio go-librespot[29939]: time="2026-01-27T21:27:20+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:27:20 volumio go-librespot[29939]: time="2026-01-27T21:27:20+07:00" level=debug msg="app state loaded" Jan 27 21:27:20 volumio go-librespot[29939]: time="2026-01-27T21:27:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:27:20 volumio go-librespot[29939]: time="2026-01-27T21:27: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:27:20 volumio go-librespot[29939]: time="2026-01-27T21:27:20+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 21:27:20 volumio go-librespot[29939]: time="2026-01-27T21:27:20+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 21:27:20 volumio volumio[29488]: info: Initializing connection to go-librespot Websocket Jan 27 21:27:20 volumio go-librespot[29939]: time="2026-01-27T21:27:20+07:00" level=debug msg="new websocket client" Jan 27 21:27:20 volumio go-librespot[29939]: time="2026-01-27T21:27:20+07:00" level=info msg="zeroconf server listening on port 45907" Jan 27 21:27:20 volumio volumio[29488]: info: Connection to go-librespot Websocket established Jan 27 21:27:20 volumio go-librespot[29939]: time="2026-01-27T21:27:20+07:00" level=debug msg="obtained new client token: AADvMXr+6QPiuhjlFxIo0TzPQy3DxjFgTYuwwxpAnVqrBtzz+hlkbGCQxsbeSqnNXAdQiOia2rIxqIHSRZPEcusI51tOaWbhbENgJO8SE2qj2HTfe2ODJ9SI5Bky4deQupSu5f0kqauLv9bkiqRFORtD7JHbzYyWYCncDKA/6hXeUiGADY+9iG+RwQyqIlepjiNHBwYn2rYRk3AN3CXRQXfjL1soo6/qF9V8TKGJH8jwbcyn4oEMQR/1fuE=" Jan 27 21:27:20 volumio go-librespot[29939]: time="2026-01-27T21:27:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:27:20 volumio go-librespot[29939]: time="2026-01-27T21:27:20+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 21:27:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:27:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:27:21 volumio volumio[29488]: info: Connection to go-librespot Websocket closed Jan 27 21:27:21 volumio volumio[29488]: info: MYVOLUMIO: Adding device Jan 27 21:27:21 volumio volumio[29488]: info: MYVOLUMIO: Evaluating Server Jan 27 21:27:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:27:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:27:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:27:22 volumio volumio[29488]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 21:27:22 volumio volumio[29488]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:27:22 volumio volumio[29488]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 27 21:27:22 volumio volumio-remote-updater[628]: Test mode disabled Jan 27 21:27:22 volumio volumio-remote-updater[628]: Alpha mode disabled Jan 27 21:27:22 volumio volumio-remote-updater[628]: Alpha legacy test mode disabled Jan 27 21:27:22 volumio volumio[29488]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Jan 27 21:27:22 volumio volumio[29488]: info: Setting Geolocation for MyVolumio to as1 Jan 27 21:27:22 volumio volumio[29488]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:27:22 volumio volumio[29488]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:27:22 volumio volumio[29488]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:27:22 volumio volumio[29488]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Jan 27 21:27:22 volumio volumio[29488]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Jan 27 21:27:23 volumio volumio[29488]: info: Getting Spotify volume Jan 27 21:27:23 volumio volumio[29488]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 21:27:23 volumio volumio[29488]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:27:23 volumio volumio[29488]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 27 21:27:23 volumio volumio[29488]: errno: -111, Jan 27 21:27:23 volumio volumio[29488]: code: 'ECONNREFUSED', Jan 27 21:27:23 volumio volumio[29488]: syscall: 'connect', Jan 27 21:27:23 volumio volumio[29488]: address: '127.0.0.1', Jan 27 21:27:23 volumio volumio[29488]: port: 9879, Jan 27 21:27:23 volumio volumio[29488]: response: undefined Jan 27 21:27:23 volumio volumio[29488]: } Jan 27 21:27:23 volumio volumio[29488]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 21:27:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:27:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:27:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:27:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 27 21:27:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:27:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:27:24 volumio go-librespot[29982]: go-librespot daemon starting... Jan 27 21:27:24 volumio go-librespot[29983]: time="2026-01-27T21:27:24+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:27:24 volumio go-librespot[29983]: time="2026-01-27T21:27:24+07:00" level=debug msg="app state loaded" Jan 27 21:27:24 volumio go-librespot[29983]: time="2026-01-27T21:27:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:27:24 volumio go-librespot[29983]: time="2026-01-27T21:27:24+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 21:27:24 volumio go-librespot[29983]: time="2026-01-27T21:27:24+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 21:27:24 volumio go-librespot[29983]: time="2026-01-27T21:27:24+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 21:27:24 volumio go-librespot[29983]: time="2026-01-27T21:27:24+07:00" level=info msg="zeroconf server listening on port 42805" Jan 27 21:27:25 volumio go-librespot[29983]: time="2026-01-27T21:27:25+07:00" level=debug msg="obtained new client token: AAAjRyM7iAQPJcA15M6dqc0y2pPLQrlj4WaasE9Y7x6x0Mpf8WUDj1zweIp/tn8qOpWcwHa29Q2Z+0OMv0ZdHQLfWd94AF60OnZYvE75mFczMXGG1SFBekHLsUgNP5P0Jbm5CxU8AzS3RJLjgL0ht+Y+rD72j3UBIFDnXFP4CCvrtk8AKVSrBZnOG1Ymyto9wKL7c6Tl5ob+IcktSe143WaiIK2OMd8Q+qkVn6F8yuwCR43vhHkkd7Zk" Jan 27 21:27:25 volumio sudo[29992]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 21:26' Jan 27 21:27:25 volumio sudo[29992]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:27:25 volumio go-librespot[29983]: time="2026-01-27T21:27:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:27:25 volumio go-librespot[29983]: time="2026-01-27T21:27:25+07:00" level=debug msg="completed keyexchange" Jan 27 21:27:25 volumio go-librespot[29983]: time="2026-01-27T21:27:25+07:00" level=debug msg="completed challenge" Jan 27 21:27:25 volumio go-librespot[29983]: time="2026-01-27T21:27:25+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 21:27:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:27:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:27:25 volumio sudo[29992]: pam_unix(sudo:session): session closed for user root Jan 27 21:27:25 volumio volumio-remote-updater[628]: [2026-01-27 21:27:25] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 27 21:27:25 volumio volumio-remote-updater[628]: [2026-01-27 21:27:25] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 27 21:27:25 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:27:25 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 27 21:27:25 volumio systemd[1]: volumio.service: Consumed 1min 79ms CPU time. Jan 27 21:27:25 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 21:27:25 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 21:27:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:27:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:27:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:27:25 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 9163. Jan 27 21:27:26 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 21:27:26 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 27 21:27:26 volumio systemd[1]: volumio.service: Consumed 1min 79ms CPU time. Jan 27 21:27:26 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 27 21:27:26 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 21:27:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:27:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:27:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:27:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 27 21:27:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:27:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:27:28 volumio go-librespot[30020]: go-librespot daemon starting... Jan 27 21:27:28 volumio go-librespot[30021]: time="2026-01-27T21:27:28+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:27:28 volumio go-librespot[30021]: time="2026-01-27T21:27:28+07:00" level=debug msg="app state loaded" Jan 27 21:27:28 volumio go-librespot[30021]: time="2026-01-27T21:27:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:27:29 volumio go-librespot[30021]: time="2026-01-27T21:27: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:27:29 volumio go-librespot[30021]: time="2026-01-27T21:27:29+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 21:27:29 volumio go-librespot[30021]: time="2026-01-27T21:27:29+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 21:27:29 volumio go-librespot[30021]: time="2026-01-27T21:27:29+07:00" level=info msg="zeroconf server listening on port 34963" Jan 27 21:27:29 volumio go-librespot[30021]: time="2026-01-27T21:27:29+07:00" level=debug msg="obtained new client token: AACRRcDNn73+w0S5eTFHiuuvXFvC3YnyEDDU9jZTOWP79aKKtDyqA+MpvrVyOtMnF4bfMOyMJSyc2leeLrLwGqVM+cpKwy2TDvsGtW8Kna+W4IwkIayuqgGFlP4My2YMxEIiLdMaW18hRF8WQ0iG/4NXLR77wzK74XUOAzjXIwTXlq3VTNNhbqgXFlRbnRZ3MX5Q/DV+EpkxdJ5m6OPj/ZpjhV0Bw1rHFmcKJtMaokr/8iYwl6pZ3OGGvpQ=" Jan 27 21:27:29 volumio go-librespot[30021]: time="2026-01-27T21:27:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:27:29 volumio go-librespot[30021]: time="2026-01-27T21:27:29+07:00" level=debug msg="completed keyexchange" Jan 27 21:27:29 volumio go-librespot[30021]: time="2026-01-27T21:27:29+07:00" level=debug msg="completed challenge" Jan 27 21:27:29 volumio go-librespot[30021]: time="2026-01-27T21:27: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 21:27:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:27:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:27:29 volumio volumio[30005]: info: ------------------------------------------- Jan 27 21:27:29 volumio volumio[30005]: info: ----- Volumio3 ---- Jan 27 21:27:29 volumio volumio[30005]: info: ------------------------------------------- Jan 27 21:27:29 volumio volumio[30005]: info: ----- System startup ---- Jan 27 21:27:29 volumio volumio[30005]: info: ------------------------------------------- Jan 27 21:27:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:27:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:27:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:27:30 volumio volumio-remote-updater[628]: [2026-01-27 21:27:30] [connect] Successful connection Jan 27 21:27:31 volumio volumio[30005]: info: MYVOLUMIO Environment detected Jan 27 21:27:31 volumio volumio[30005]: info: Plugin folders cleanup Jan 27 21:27:31 volumio volumio[30005]: info: Scanning into folder /volumio/app/plugins/ Jan 27 21:27:31 volumio volumio[30005]: info: Scanning category audio_interface Jan 27 21:27:31 volumio volumio[30005]: info: Scanning category miscellanea Jan 27 21:27:31 volumio volumio[30005]: info: Scanning category music_service Jan 27 21:27:31 volumio volumio[30005]: info: Scanning category plugins.json Jan 27 21:27:31 volumio volumio[30005]: info: Scanning category system_controller Jan 27 21:27:31 volumio volumio[30005]: info: Scanning category user_interface Jan 27 21:27:31 volumio volumio[30005]: info: Scanning into folder /data/plugins/ Jan 27 21:27:31 volumio volumio[30005]: info: Scanning category music_service Jan 27 21:27:31 volumio volumio[30005]: info: Plugin folders cleanup completed Jan 27 21:27:31 volumio volumio[30005]: info: ------------------------------------------- Jan 27 21:27:31 volumio volumio[30005]: info: ----- Core plugins startup ---- Jan 27 21:27:31 volumio volumio[30005]: info: ------------------------------------------- Jan 27 21:27:31 volumio volumio[30005]: info: Loading plugins from folder /volumio/app/plugins/ Jan 27 21:27:31 volumio volumio[30005]: info: Adding plugin upnp to MyMusic Plugins Jan 27 21:27:31 volumio volumio[30005]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 27 21:27:31 volumio volumio[30005]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 27 21:27:31 volumio volumio[30005]: info: Loading plugins from folder /data/plugins/ Jan 27 21:27:31 volumio volumio[30005]: info: Loading plugin "system"... Jan 27 21:27:31 volumio volumio[30005]: info: Loading plugin "appearance"... Jan 27 21:27:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:27:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:27:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:27:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 27 21:27:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:27:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:27:32 volumio go-librespot[30040]: go-librespot daemon starting... Jan 27 21:27:32 volumio go-librespot[30041]: time="2026-01-27T21:27:32+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:27:32 volumio go-librespot[30041]: time="2026-01-27T21:27:32+07:00" level=debug msg="app state loaded" Jan 27 21:27:32 volumio go-librespot[30041]: time="2026-01-27T21:27:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:27:33 volumio volumio[30005]: info: Loading plugin "network"... Jan 27 21:27:33 volumio volumio[30005]: info: Refreshing Cached IP Addresses Jan 27 21:27:33 volumio go-librespot[30041]: time="2026-01-27T21:27: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:27:33 volumio go-librespot[30041]: time="2026-01-27T21:27:33+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 21:27:33 volumio go-librespot[30041]: time="2026-01-27T21:27:33+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 21:27:33 volumio sudo[30049]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 21:27:33 volumio sudo[30049]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:27:33 volumio volumio[30005]: info: Loading plugin "services"... Jan 27 21:27:33 volumio sudo[30049]: pam_unix(sudo:session): session closed for user root Jan 27 21:27:33 volumio volumio[30005]: info: Loading plugin "alsa_controller"... Jan 27 21:27:33 volumio sudo[30051]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 21:27:33 volumio go-librespot[30041]: time="2026-01-27T21:27:33+07:00" level=info msg="zeroconf server listening on port 38231" Jan 27 21:27:33 volumio sudo[30051]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:27:33 volumio sudo[30051]: pam_unix(sudo:session): session closed for user root Jan 27 21:27:33 volumio sudo[30058]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 27 21:27:33 volumio sudo[30058]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:27:33 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 21:27:33 volumio volumio[30005]: info: Loading plugin "wizard"... Jan 27 21:27:33 volumio volumio[30005]: info: Loading plugin "networkfs"... Jan 27 21:27:33 volumio volumio[30005]: info: Starting Udev Watcher for removable devices Jan 27 21:27:33 volumio go-librespot[30041]: time="2026-01-27T21:27:33+07:00" level=debug msg="obtained new client token: AAAFHEzF2rubQPpJztTRXFSFAKr+11dHMW3+aKHkBRuse8CoJ1gnqS0Pc4YJ5RrHBavfWAuvSkYGDMWUCotwVwGxWiCvY+/lLifIG5vVNfT4z7jvdP8EBikjbqbhsziTf3oaqbsV3YqTBA2owBgGVxiFbJJaMCPyAWpIUeKBV91fcIc+131VfXNO5SQL71J7+v7Cr292juQZebnb+uMg+qEsx7AQ2WBaxeXfZvxap5Fg7PXhng2WdT2SVPg=" Jan 27 21:27:33 volumio volumio[30005]: info: Ignoring mount for partition: boot Jan 27 21:27:33 volumio volumio[30005]: info: Ignoring mount for partition: volumio Jan 27 21:27:33 volumio volumio[30005]: info: Ignoring mount for partition: volumio_data Jan 27 21:27:33 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 21:27:33 volumio volumio[30005]: info: Loading plugin "volumio_command_line_client"... Jan 27 21:27:33 volumio volumio[30005]: info: Loading plugin "upnp"... Jan 27 21:27:33 volumio volumio[30005]: info: [1769524053732] Starting Upmpd Daemon Jan 27 21:27:33 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 21:27:33 volumio volumio[30005]: info: Loading plugin "my_music"... Jan 27 21:27:33 volumio volumio[30005]: info: Loading plugin "mpd"... Jan 27 21:27:33 volumio go-librespot[30041]: time="2026-01-27T21:27:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:27:33 volumio go-librespot[30041]: time="2026-01-27T21:27:33+07:00" level=debug msg="completed keyexchange" Jan 27 21:27:33 volumio go-librespot[30041]: time="2026-01-27T21:27:33+07:00" level=debug msg="completed challenge" Jan 27 21:27:33 volumio go-librespot[30041]: time="2026-01-27T21:27:33+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 21:27:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:27:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:27:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:27:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:27:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:27:34 volumio volumio[30005]: info: Loading plugin "upnp_browser"... Jan 27 21:27:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:27:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:27:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:27:36 volumio sudo[30058]: pam_unix(sudo:session): session closed for user root Jan 27 21:27:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 27 21:27:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:27:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:27:37 volumio go-librespot[30082]: go-librespot daemon starting... Jan 27 21:27:37 volumio go-librespot[30083]: time="2026-01-27T21:27:37+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:27:37 volumio go-librespot[30083]: time="2026-01-27T21:27:37+07:00" level=debug msg="app state loaded" Jan 27 21:27:37 volumio go-librespot[30083]: time="2026-01-27T21:27:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:27:37 volumio volumio[30005]: info: Starting UPNP Browser Jan 27 21:27:37 volumio volumio[30005]: info: Loading plugin "alarm-clock"... Jan 27 21:27:37 volumio go-librespot[30083]: time="2026-01-27T21:27:37+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 21:27:37 volumio go-librespot[30083]: time="2026-01-27T21:27:37+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 21:27:37 volumio go-librespot[30083]: time="2026-01-27T21:27:37+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 21:27:37 volumio volumio[30005]: info: Loading plugin "airplay_emulation"... Jan 27 21:27:37 volumio go-librespot[30083]: time="2026-01-27T21:27:37+07:00" level=info msg="zeroconf server listening on port 38119" Jan 27 21:27:37 volumio volumio[30005]: info: Starting Shairport Sync Jan 27 21:27:37 volumio volumio[30005]: info: Loading plugin "last_100"... Jan 27 21:27:37 volumio volumio[30005]: info: Loading plugin "webradio"... Jan 27 21:27:37 volumio volumio[30005]: info: Loading plugin "i2s_dacs"... Jan 27 21:27:37 volumio volumio[30005]: info: Loading plugin "volumiodiscovery"... Jan 27 21:27:37 volumio go-librespot[30083]: time="2026-01-27T21:27:37+07:00" level=debug msg="obtained new client token: AABvOR0UA0HsyTBHFLStX4VZnfsvgZBiEt2NfftVGiicbVzey3gTzevLn/Y9jjt08wEjQFmHmfxcQd4dVv7G23P+aptecIz/om9BqlEmdHQ/wJjfAjHLJZcUx5FDQtC7d1PbTn4Q+UUOYAWRDVIe6+Hu6dcNTH5rv7nZ/Lb26A+T2VL1zQbQMs5mkWTkW44MtxBr4w64dwgVaCsVSmn9kq2gB9rbI/ji7at+hBGTt+F9q9SlMz7Wk0rqVuw=" Jan 27 21:27:37 volumio volumio[30005]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 21:27:37 volumio volumio[30005]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 21:27:37 volumio volumio[30005]: *** WARNING *** For more information see Jan 27 21:27:37 volumio volumio[30005]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 21:27:37 volumio volumio[30005]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 21:27:37 volumio volumio[30005]: *** WARNING *** For more information see Jan 27 21:27:37 volumio node[30005]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 21:27:37 volumio node[30005]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 21:27:37 volumio node[30005]: *** WARNING *** For more information see Jan 27 21:27:37 volumio node[30005]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 21:27:37 volumio node[30005]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 21:27:37 volumio node[30005]: *** WARNING *** For more information see Jan 27 21:27:37 volumio volumio[30005]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 27 21:27:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:27:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:27:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:27:37 volumio volumio[30005]: info: Discovery: Started advertising with name: Volumio Jan 27 21:27:38 volumio go-librespot[30083]: time="2026-01-27T21:27: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 21:27:38 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 21:27:38 volumio volumio[30005]: info: Loading plugin "spop"... Jan 27 21:27:38 volumio go-librespot[30083]: time="2026-01-27T21:27:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 21:27:38 volumio go-librespot[30083]: time="2026-01-27T21:27: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 21:27:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:27:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:27:39 volumio volumio[30005]: info: Loading plugin "ytcr"... Jan 27 21:27:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:27:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:27:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:27:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Jan 27 21:27:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:27:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:27:41 volumio go-librespot[30093]: go-librespot daemon starting... Jan 27 21:27:41 volumio go-librespot[30094]: time="2026-01-27T21:27:41+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:27:41 volumio go-librespot[30094]: time="2026-01-27T21:27:41+07:00" level=debug msg="app state loaded" Jan 27 21:27:41 volumio go-librespot[30094]: time="2026-01-27T21:27:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:27:41 volumio go-librespot[30094]: time="2026-01-27T21:27: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 21:27:41 volumio go-librespot[30094]: time="2026-01-27T21:27: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 21:27:41 volumio go-librespot[30094]: time="2026-01-27T21:27: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 21:27:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:27:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:27:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:27:41 volumio go-librespot[30094]: time="2026-01-27T21:27:41+07:00" level=info msg="zeroconf server listening on port 40775" Jan 27 21:27:42 volumio go-librespot[30094]: time="2026-01-27T21:27:42+07:00" level=debug msg="obtained new client token: AAAztU+YAH1zDMQVRTieeuCaHaRnFUi0oWZftb+jrC8iZyO+kp0nk58B7PQuGwSvqXd+xHLvtpE7xxlVWyS4xfjnPEG2qtPnW0cjsaxpaeU7Ijc33UZ5sfEZDU1ONuz7Da/WdyF6V/Dkwcqo5MT/n04+I5fWn4BQlLK0DTs46Ec03PscMpwC+6TClJ9vPmx/9zI8aYkS5HCSBwOHrn6EVpVRV01nEIMAJvZTOLnBiZJ4osA1KbN40D1C" Jan 27 21:27:42 volumio go-librespot[30094]: time="2026-01-27T21:27:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:27:42 volumio go-librespot[30094]: time="2026-01-27T21:27:42+07:00" level=debug msg="completed keyexchange" Jan 27 21:27:42 volumio go-librespot[30094]: time="2026-01-27T21:27:42+07:00" level=debug msg="completed challenge" Jan 27 21:27:42 volumio go-librespot[30094]: time="2026-01-27T21:27: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 21:27:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:27:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:27:42 volumio volumio[30005]: info: Loading plugin "ytmusic"... Jan 27 21:27:43 volumio volumio-remote-updater[628]: [2026-01-27 21:27:43] [connect] Successful connection Jan 27 21:27:43 volumio volumio[30005]: info: Loading plugin "outputs"... Jan 27 21:27:43 volumio volumio[30005]: info: Loading plugin "albumart"... Jan 27 21:27:43 volumio volumio[30005]: info: Plugin example_plugin is not enabled Jan 27 21:27:43 volumio volumio[30005]: info: Loading plugin "inputs"... Jan 27 21:27:43 volumio volumio[30005]: info: Loading plugin "updater_comm"... Jan 27 21:27:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:27:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:27:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:27:44 volumio volumio[30005]: info: Plugin mpdemulation is not enabled Jan 27 21:27:44 volumio volumio[30005]: info: Loading plugin "rest_api"... Jan 27 21:27:44 volumio volumio[30005]: info: Loading plugin "websocket"... Jan 27 21:27:44 volumio volumio[30005]: info: Starting Socket.io Server version 1.7.4 Jan 27 21:27:44 volumio volumio[30005]: info: Loading plugin "RoonBridge"... Jan 27 21:27:44 volumio volumio[30005]: info: Applying required configuration parameters for plugin RoonBridge Jan 27 21:27:44 volumio volumio[30005]: info: Loading i18n strings for locale en Jan 27 21:27:44 volumio volumio[30005]: Updating browse sources language Jan 27 21:27:44 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:27:44 volumio volumio[30115]: Forking 3 albumart workers Jan 27 21:27:44 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 21:27:44 volumio volumio[30005]: info: CoreCommandRouter::initPlayerControls Jan 27 21:27:44 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:27:44 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:27:44 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:27:44 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:27:44 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:27:44 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:27:44 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:27:44 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:27:44 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 21:27:44 volumio volumio[30005]: Express server listening on port 3000 Jan 27 21:27:44 volumio volumio[30005]: [Metrics] WebUI: 16s 143.69ms Jan 27 21:27:44 volumio volumio[30005]: info: CoreStateMachine::resetVolumioState Jan 27 21:27:44 volumio volumio[30005]: info: CoreStateMachine::getcurrentVolume Jan 27 21:27:44 volumio volumio[30005]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 21:27:45 volumio sudo[30160]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 21:27:45 volumio sudo[30160]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:27:45 volumio volumio[30005]: info: Volumio Network Manager: Network status updated: 1 Jan 27 21:27:45 volumio sudo[30160]: pam_unix(sudo:session): session closed for user root Jan 27 21:27:45 volumio sudo[30162]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 21:27:45 volumio sudo[30162]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:27:45 volumio sudo[30162]: pam_unix(sudo:session): session closed for user root Jan 27 21:27:45 volumio volumio-remote-updater[628]: [2026-01-27 21:27:45] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769524063 101 Jan 27 21:27:45 volumio volumio[30005]: 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 21:27:45 volumio volumio[30005]: info: VolumeController:: Volume=100 Mute =false Jan 27 21:27:45 volumio volumio[30005]: info: CoreStateMachine::pushState Jan 27 21:27:45 volumio volumio[30005]: info: CorePlayQueue::getTrack 0 Jan 27 21:27:45 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 21:27:45 volumio volumio[30005]: info: CoreCommandRouter::volumioPushState Jan 27 21:27:45 volumio volumio[30005]: info: CoreStateMachine::updateTrackBlock Jan 27 21:27:45 volumio volumio[30005]: info: CorePlayQueue::getTrackBlock Jan 27 21:27:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jan 27 21:27:45 volumio volumio[30005]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 21:27:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:27:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:27:45 volumio go-librespot[30167]: go-librespot daemon starting... Jan 27 21:27:45 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:27:45 volumio volumio[30005]: info: Reloading queue from file Jan 27 21:27:45 volumio volumio[30005]: info: CoreStateMachine::setRepeat null single undefined Jan 27 21:27:45 volumio volumio[30005]: info: CoreStateMachine::pushState Jan 27 21:27:45 volumio volumio[30005]: info: CorePlayQueue::getTrack 0 Jan 27 21:27:45 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 21:27:45 volumio volumio[30005]: info: CoreCommandRouter::volumioPushState Jan 27 21:27:45 volumio volumio[30005]: info: CoreStateMachine::setRandom null Jan 27 21:27:45 volumio volumio[30005]: info: CoreStateMachine::pushState Jan 27 21:27:45 volumio volumio[30005]: info: CorePlayQueue::getTrack 0 Jan 27 21:27:45 volumio volumio[30005]: info: CoreCommandRouter::volumioPushState Jan 27 21:27:45 volumio go-librespot[30171]: time="2026-01-27T21:27:45+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:27:45 volumio go-librespot[30171]: time="2026-01-27T21:27:45+07:00" level=debug msg="app state loaded" Jan 27 21:27:45 volumio volumio[30005]: info: Setting Device type: Raspberry PI Jan 27 21:27:45 volumio go-librespot[30171]: time="2026-01-27T21:27:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:27:45 volumio volumio[30005]: info: Completed loading Core Plugins Jan 27 21:27:45 volumio volumio[30005]: info: Preparing to generate the ALSA configuration file Jan 27 21:27:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:27:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:27:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:27:46 volumio volumio[30005]: info: VolumeController:: Volume=100 Mute =false Jan 27 21:27:46 volumio volumio[30005]: info: CoreStateMachine::pushState Jan 27 21:27:46 volumio volumio[30005]: info: CorePlayQueue::getTrack 0 Jan 27 21:27:46 volumio volumio[30005]: info: CoreCommandRouter::volumioPushState Jan 27 21:27:46 volumio sudo[30181]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 27 21:27:46 volumio sudo[30181]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:27:46 volumio volumio[30005]: info: Asound.conf file unchanged, so no further update is needed Jan 27 21:27:46 volumio volumio[30005]: info: Output device has changed, restarting MPD Jan 27 21:27:46 volumio sudo[30181]: pam_unix(sudo:session): session closed for user root Jan 27 21:27:46 volumio sudo[30186]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 21:27:46 volumio sudo[30186]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:27:46 volumio volumio[30005]: info: Output device has changed, restarting Shairport Sync Jan 27 21:27:46 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:27:46 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:27:46 volumio sudo[30186]: pam_unix(sudo:session): session closed for user root Jan 27 21:27:46 volumio sudo[30188]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 21:27:46 volumio sudo[30188]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:27:46 volumio volumio[30005]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 21:27:46 volumio volumio[30005]: info: ___________ START PLUGINS ___________ Jan 27 21:27:46 volumio volumio[30005]: info: ControllerMpd::onStart: Initializing MPD Jan 27 21:27:46 volumio volumio[30005]: info: Creating MPD Configuration file Jan 27 21:27:46 volumio go-librespot[30171]: time="2026-01-27T21:27: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:27:46 volumio go-librespot[30171]: time="2026-01-27T21:27:46+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 21:27:46 volumio go-librespot[30171]: time="2026-01-27T21:27:46+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 21:27:46 volumio go-librespot[30171]: time="2026-01-27T21:27:46+07:00" level=info msg="zeroconf server listening on port 42527" Jan 27 21:27:46 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 21:27:46 volumio volumio[30005]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 21:27:46 volumio volumio[30005]: info: [1769524066493] CoreMusicLibrary::Adding element Media Servers Jan 27 21:27:46 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:27:46 volumio volumio[30005]: info: UPNP Browser: Client initialized successfully Jan 27 21:27:46 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 27 21:27:46 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:27:46 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:27:46 volumio sudo[30196]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 21:27:46 volumio sudo[30196]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:27:46 volumio sudo[30198]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 21:27:46 volumio sudo[30198]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:27:46 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 21:27:46 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 21:27:46 volumio systemd[1]: mpd.service: Consumed 7.317s CPU time. Jan 27 21:27:46 volumio volumio[30005]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 21:27:46 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:27:46 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 21:27:46 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:27:46 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 21:27:46 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 21:27:46 volumio sudo[30196]: pam_unix(sudo:session): session closed for user root Jan 27 21:27:46 volumio volumio[30005]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 21:27:46 volumio volumio[30005]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 21:27:46 volumio volumio[30005]: info: [1769524066753] CoreMusicLibrary::Adding element Last_100 Jan 27 21:27:46 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:27:46 volumio go-librespot[30171]: time="2026-01-27T21:27:46+07:00" level=debug msg="obtained new client token: AAC4Xs1NhoUEViOkNZRys2SOkhtLugEzV+mvw4Z4Ha8q99B+QuNv8d1kMxdNVZb1gLl2kFaQY7LWN19cgZyQMvsSj47kVQn9egXfbCnJOsg/SbbdoxkMtSaiiLycZhQwWy+UMyhSafWAS1XBqKEiAX5UT/9qJvVZsYLj1cJIRD3annDWxPSivoFxUTNUwhOdxrIcKCKVgRqS6YkpTSi7fqzeyckDTHQ6Kv2so71SIe588E6FxhPlypUj7Sw=" Jan 27 21:27:46 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 21:27:46 volumio volumio[30005]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 21:27:46 volumio volumio[30005]: info: [1769524066771] CoreMusicLibrary::Adding element Webradio Jan 27 21:27:46 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:27:46 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 21:27:46 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 21:27:46 volumio volumio[30005]: info: Initializing BBC Radios Jan 27 21:27:46 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 21:27:46 volumio go-librespot[30171]: time="2026-01-27T21:27:46+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 21:27:46 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 21:27:46 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 21:27:46 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 21:27:46 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 21:27:46 volumio go-librespot[30171]: time="2026-01-27T21:27:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 21:27:46 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 21:27:46 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 21:27:47 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 21:27:47 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:27:47 volumio go-librespot[30171]: time="2026-01-27T21:27:47+07:00" level=debug msg="completed keyexchange" Jan 27 21:27:47 volumio go-librespot[30171]: time="2026-01-27T21:27:47+07:00" level=debug msg="completed challenge" Jan 27 21:27:47 volumio volumio[30005]: info: Creating Spotify config file Jan 27 21:27:47 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:27:47 volumio go-librespot[30171]: time="2026-01-27T21:27:47+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 21:27:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:27:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:27:47 volumio sudo[30221]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 27 21:27:47 volumio sudo[30221]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 27 21:27:47 volumio sudo[30221]: pam_unix(sudo:session): session closed for user root Jan 27 21:27:47 volumio volumio[30125]: Starting albumart workers Jan 27 21:27:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:27:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:27:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:27:48 volumio volumio[30127]: Starting albumart workers Jan 27 21:27:48 volumio volumio[30126]: Starting albumart workers Jan 27 21:27:48 volumio volumio[30005]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 21:27:48 volumio volumio[30005]: info: [1769524068377] CoreMusicLibrary::Adding element YouTube Music Jan 27 21:27:48 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:27:48 volumio volumio[30005]: Cannot find translation for source YouTube Music Jan 27 21:27:48 volumio volumio[30005]: info: Volumio Calling Home Jan 27 21:27:48 volumio sudo[30230]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 27 21:27:48 volumio sudo[30230]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:27:48 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Jan 27 21:27:48 volumio sudo[30230]: pam_unix(sudo:session): session closed for user root Jan 27 21:27:49 volumio volumio[30005]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 21:27:49 volumio volumio[30005]: info: Discovery: Found device Volumio Jan 27 21:27:49 volumio volumio[30005]: info: CoreCommandRouter::volumioGetState Jan 27 21:27:49 volumio volumio[30005]: info: CorePlayQueue::getTrack 0 Jan 27 21:27:49 volumio volumio[30005]: info: MPD Permissions set Jan 27 21:27:49 volumio volumio[30005]: info: MPD Permissions set Jan 27 21:27:49 volumio volumio[30005]: info: Upmpdcli Daemon Started Jan 27 21:27:49 volumio volumio[30005]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 21:27:49 volumio volumio[30005]: info: Discovery: Found device Volumio Jan 27 21:27:49 volumio volumio[30005]: info: CoreCommandRouter::volumioGetState Jan 27 21:27:49 volumio volumio[30005]: info: CorePlayQueue::getTrack 0 Jan 27 21:27:49 volumio volumio[30005]: info: Spotify config file written Jan 27 21:27:49 volumio volumio[30005]: 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 21:27:49 volumio volumio[30005]: info: Volumio called home Jan 27 21:27:49 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:27:49 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:27:49 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:27:49 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:27:49 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:27:49 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:27:49 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:27:49 volumio sudo[30250]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 21:27:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:27:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:27:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:27:49 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:27:49 volumio sudo[30250]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:27:50 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:27:50 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:27:50 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:27:50 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:27:50 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:27:50 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:27:50 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:27:50 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:27:50 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:27:50 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:27:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Jan 27 21:27:50 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:27:50 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:27:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:27:50 volumio volumio[30005]: info: No need to fix Spotify hosts Jan 27 21:27:50 volumio go-librespot[30270]: go-librespot daemon starting... Jan 27 21:27:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:27:50 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 27 21:27:50 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 27 21:27:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:27:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:27:50 volumio go-librespot[30278]: go-librespot daemon starting... Jan 27 21:27:50 volumio sudo[30250]: pam_unix(sudo:session): session closed for user root Jan 27 21:27:50 volumio go-librespot[30279]: time="2026-01-27T21:27:50+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:27:50 volumio go-librespot[30279]: time="2026-01-27T21:27:50+07:00" level=debug msg="app state loaded" Jan 27 21:27:50 volumio go-librespot[30279]: time="2026-01-27T21:27:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:27:51 volumio go-librespot[30279]: time="2026-01-27T21:27:51+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 21:27:51 volumio go-librespot[30279]: time="2026-01-27T21:27:51+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 21:27:51 volumio go-librespot[30279]: time="2026-01-27T21:27:51+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 21:27:51 volumio go-librespot[30279]: time="2026-01-27T21:27:51+07:00" level=info msg="zeroconf server listening on port 33169" Jan 27 21:27:51 volumio go-librespot[30279]: time="2026-01-27T21:27:51+07:00" level=debug msg="obtained new client token: AABdKPaiVeu/RASzFYYrtFOe7DQ50sapOBUsXOBWtNgZBcI4BtMgteHQGXjGeW7C4wn10JneE2FANpqDmW3wI4lt72hEOJGAq0VnFx7Y361BqJ+4fTu1KDQiQXDyvmeEELHfQu9FChkKowBLPd2hkMdBbuEQUBNd91FMOu+N0RqzRDsNyeqHVj1uDiH1iwZXhaWH0xgWS1M8U+pi03MWi1ZzAzpp5hRioPhDKr/umpNdhozWDGox9p1Obnc=" Jan 27 21:27:51 volumio go-librespot[30279]: time="2026-01-27T21:27:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:27:51 volumio go-librespot[30279]: time="2026-01-27T21:27:51+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 21:27:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:27:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:27:51 volumio volumio[30005]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 21:27:51 volumio volumio[30005]: SPOTIFY: BQDnCSQd8Lbu3A3palXcAXyueulxWTkSR63HbCYNgHsr7Apdoxa3b9DYHuKpYJ3Cboam4EjcdDP--TCVWAkF5WVKsZcIxI0xRQWkTBmw91UQEYIKr0Q1kwSqiJq6cSyBWEu-svSRRzf8F3TusXP8h_mHudRJUFb_U5gloUU7E6vG1djjkXzZRRIpJ7Dr4LrJ8icyWn96kT2NxHERuMmIgpO8aSXAsX90VZkK03mhhIQ_M5hgoo69k6bYi1zpDyZ28TYoYseVOQSQn0PNmKqPyk6_bpzA8A-pc2e4NydenmEC-rs2RlQQE3io Jan 27 21:27:51 volumio volumio[30005]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 21:27:51 volumio volumio[30005]: info: New Spotify access token = BQDnCSQd8Lbu3A3palXcAXyueulxWTkSR63HbCYNgHsr7Apdoxa3b9DYHuKpYJ3Cboam4EjcdDP--TCVWAkF5WVKsZcIxI0xRQWkTBmw91UQEYIKr0Q1kwSqiJq6cSyBWEu-svSRRzf8F3TusXP8h_mHudRJUFb_U5gloUU7E6vG1djjkXzZRRIpJ7Dr4LrJ8icyWn96kT2NxHERuMmIgpO8aSXAsX90VZkK03mhhIQ_M5hgoo69k6bYi1zpDyZ28TYoYseVOQSQn0PNmKqPyk6_bpzA8A-pc2e4NydenmEC-rs2RlQQE3io Jan 27 21:27:51 volumio volumio[30005]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 27 21:27:51 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Jan 27 21:27:51 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Jan 27 21:27:51 volumio systemd[1]: setdatetime-helper.service: Consumed 2.178s CPU time. Jan 27 21:27:51 volumio volumio[30005]: info: Starting Shairport Sync Jan 27 21:27:51 volumio volumio[30005]: info: Starting Shairport Sync Jan 27 21:27:51 volumio volumio[30005]: info: Starting Shairport Sync Jan 27 21:27:51 volumio sudo[30309]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 21:27:51 volumio sudo[30309]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:27:51 volumio sudo[30313]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 21:27:51 volumio sudo[30313]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:27:51 volumio sudo[30311]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 21:27:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:27:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:27:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:27:51 volumio sudo[30311]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:27:52 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 21:27:52 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 21:27:52 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 21:27:52 volumio systemd[1]: shairport-sync.service: Consumed 2.452s CPU time. Jan 27 21:27:52 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 21:27:52 volumio sudo[30309]: pam_unix(sudo:session): session closed for user root Jan 27 21:27:52 volumio sudo[30313]: pam_unix(sudo:session): session closed for user root Jan 27 21:27:52 volumio sudo[30311]: pam_unix(sudo:session): session closed for user root Jan 27 21:27:52 volumio volumio[30005]: info: Shairport-Sync Started Jan 27 21:27:52 volumio volumio[30005]: Error adding Membership: Error: addMembership EINVAL Jan 27 21:27:52 volumio volumio[30005]: info: Shairport-Sync Started Jan 27 21:27:52 volumio volumio[30005]: info: Shairport-Sync Started Jan 27 21:27:52 volumio volumio[30005]: info: CoreCommandRouter::volumioGetState Jan 27 21:27:52 volumio volumio[30005]: info: CorePlayQueue::getTrack 0 Jan 27 21:27:52 volumio volumio[30005]: 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 21:27:52 volumio volumio[30005]: info: Spotify Successfully logged in Jan 27 21:27:52 volumio volumio[30005]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 21:27:52 volumio volumio[30005]: info: [1769524072569] CoreMusicLibrary::Adding element Spotify Jan 27 21:27:52 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:27:52 volumio volumio[30005]: Cannot find translation for source YouTube Music Jan 27 21:27:52 volumio volumio[30005]: Cannot find translation for source Spotify Jan 27 21:27:53 volumio volumio[30005]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 27 21:27:53 volumio volumio[30005]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 21:27:53 volumio volumio[30005]: info: VolumeController:: Volume=100 Mute =false Jan 27 21:27:53 volumio volumio[30005]: info: CoreCommandRouter::volumioGetState Jan 27 21:27:53 volumio volumio[30005]: info: CorePlayQueue::getTrack 0 Jan 27 21:27:53 volumio volumio[30005]: info: CoreStateMachine::pushState Jan 27 21:27:53 volumio volumio[30005]: info: CorePlayQueue::getTrack 0 Jan 27 21:27:53 volumio volumio[30005]: info: CoreCommandRouter::volumioPushState Jan 27 21:27:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:27:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:27:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:27:54 volumio volumio[30005]: info: go-librespot daemon successfully initialized Jan 27 21:27:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 27 21:27:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:27:54 volumio mpd[30228]: 2026-01-27T21:27:54 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 27 21:27:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:27:54 volumio go-librespot[30352]: go-librespot daemon starting... Jan 27 21:27:54 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 27 21:27:54 volumio sudo[30198]: pam_unix(sudo:session): session closed for user root Jan 27 21:27:54 volumio sudo[30188]: pam_unix(sudo:session): session closed for user root Jan 27 21:27:54 volumio go-librespot[30355]: time="2026-01-27T21:27:54+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:27:54 volumio go-librespot[30355]: time="2026-01-27T21:27:54+07:00" level=debug msg="app state loaded" Jan 27 21:27:54 volumio go-librespot[30355]: time="2026-01-27T21:27:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:27:55 volumio volumio[30005]: error: MPD error: The expression evaluated to a falsy value: Jan 27 21:27:55 volumio volumio[30005]: assert.ok(self.idling) Jan 27 21:27:55 volumio volumio[30005]: error: The expression evaluated to a falsy value: Jan 27 21:27:55 volumio volumio[30005]: assert.ok(self.idling) Jan 27 21:27:55 volumio volumio[30005]: error: updateQueue error: null Jan 27 21:27:55 volumio volumio[30005]: info: Completed starting Core Plugins Jan 27 21:27:55 volumio volumio[30005]: info: ------------------------------------------- Jan 27 21:27:55 volumio volumio[30005]: info: ----- MyVolumio plugins startup ---- Jan 27 21:27:55 volumio volumio[30005]: info: ------------------------------------------- Jan 27 21:27:55 volumio volumio[30005]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 27 21:27:55 volumio volumio[30005]: info: MPD running with PID30228 Jan 27 21:27:55 volumio volumio[30005]: ,establishing connection Jan 27 21:27:55 volumio volumio[30005]: error: updateQueue error: null Jan 27 21:27:55 volumio go-librespot[30355]: time="2026-01-27T21:27:55+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 21:27:55 volumio go-librespot[30355]: time="2026-01-27T21:27:55+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 21:27:55 volumio go-librespot[30355]: time="2026-01-27T21:27:55+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 21:27:55 volumio go-librespot[30355]: time="2026-01-27T21:27:55+07:00" level=info msg="zeroconf server listening on port 39131" Jan 27 21:27:55 volumio go-librespot[30355]: time="2026-01-27T21:27:55+07:00" level=debug msg="obtained new client token: AACH1H6O6+ih11CANXkR/6HS0cbbv3jryNrjMiq+3TLARdxwUi5/n5YS0uK3E1lEqyPql8CVZV82A9TGLedMJgrDmM2lB3N21otpC1S/WzXfEjzt3HAbZ0dV9GwSapMZeKLuzC9K3gUDP1VEH1CjtaTa+KUifWoIlHkIEcATyUAaEaVvHcHwVNSK3ABnbj3JWV1AQXSL8aoqtj4KiEKQ7g5v7kEtdGqr50vQbBaqoGZbkFnqjSDU7mB0eHw=" Jan 27 21:27:55 volumio go-librespot[30355]: time="2026-01-27T21:27:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:27:55 volumio go-librespot[30355]: time="2026-01-27T21:27:55+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 21:27:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:27:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:27:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:27:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:27:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:27:57 volumio volumio[30005]: info: Initializing connection to go-librespot Websocket Jan 27 21:27:57 volumio volumio[30005]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:27:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:27:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:27:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:27:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 27 21:27:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:27:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:27:59 volumio go-librespot[30365]: go-librespot daemon starting... Jan 27 21:27:59 volumio go-librespot[30366]: time="2026-01-27T21:27:59+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:27:59 volumio go-librespot[30366]: time="2026-01-27T21:27:59+07:00" level=debug msg="app state loaded" Jan 27 21:27:59 volumio go-librespot[30366]: time="2026-01-27T21:27:59+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:27:59 volumio go-librespot[30366]: time="2026-01-27T21:27: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:27:59 volumio go-librespot[30366]: time="2026-01-27T21:27:59+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 21:27:59 volumio go-librespot[30366]: time="2026-01-27T21:27:59+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 21:27:59 volumio go-librespot[30366]: time="2026-01-27T21:27:59+07:00" level=info msg="zeroconf server listening on port 33543" Jan 27 21:27:59 volumio volumio[30005]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 27 21:27:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:27:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:27:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:00 volumio go-librespot[30366]: time="2026-01-27T21:28:00+07:00" level=debug msg="obtained new client token: AABSeipyQ52vtn8Mf/6/r5pndQeX3XoB6M7uCUX8A1qVTsIzNWTzSFdTY85f9k98JVVn7NbbRdOsVPke/xnNyr2hNEdmpTQF6ogS6q1SFW8IBDR5kKOkmgvUWjjyO06kFN/2f0ki7gfhRabm9rG71Wwfs9GE3xQRj6UVUlu/icfudgpCTulrUBaE7Rhv5x8CkNsnPkNb+IE4r/uxS4xg4v8LhNMehB+pryfNQLZBDTQcVT6rP4S1tfY+" Jan 27 21:28:00 volumio go-librespot[30366]: time="2026-01-27T21:28:00+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 21:28:00 volumio go-librespot[30366]: time="2026-01-27T21:28:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 21:28:00 volumio go-librespot[30366]: time="2026-01-27T21:28:00+07:00" level=debug msg="completed keyexchange" Jan 27 21:28:00 volumio go-librespot[30366]: time="2026-01-27T21:28:00+07:00" level=debug msg="completed challenge" Jan 27 21:28:00 volumio go-librespot[30366]: time="2026-01-27T21:28:00+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 21:28:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:28:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:28:00 volumio volumio[30005]: info: Initializing connection to go-librespot Websocket Jan 27 21:28:00 volumio volumio[30005]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:28:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 27 21:28:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:03 volumio go-librespot[30373]: go-librespot daemon starting... Jan 27 21:28:03 volumio go-librespot[30374]: time="2026-01-27T21:28:03+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:28:03 volumio go-librespot[30374]: time="2026-01-27T21:28:03+07:00" level=debug msg="app state loaded" Jan 27 21:28:03 volumio go-librespot[30374]: time="2026-01-27T21:28:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:28:03 volumio volumio[30005]: info: Initializing connection to go-librespot Websocket Jan 27 21:28:03 volumio go-librespot[30374]: time="2026-01-27T21:28:03+07:00" level=debug msg="new websocket client" Jan 27 21:28:03 volumio volumio[30005]: info: Connection to go-librespot Websocket established Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 27 21:28:03 volumio volumio[30005]: info: Adding plugin bluetooth to MyMusic Plugins Jan 27 21:28:03 volumio volumio[30005]: info: Adding plugin multiroom to MyMusic Plugins Jan 27 21:28:03 volumio volumio[30005]: info: Adding plugin metavolumio to MyMusic Plugins Jan 27 21:28:03 volumio volumio[30005]: info: Adding plugin cd_controller to MyMusic Plugins Jan 27 21:28:03 volumio volumio[30005]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 27 21:28:03 volumio volumio[30005]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 27 21:28:03 volumio volumio[30005]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 27 21:28:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:04 volumio go-librespot[30374]: time="2026-01-27T21:28:04+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 21:28:04 volumio go-librespot[30374]: time="2026-01-27T21:28:04+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 21:28:04 volumio go-librespot[30374]: time="2026-01-27T21:28:04+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 21:28:04 volumio go-librespot[30374]: time="2026-01-27T21:28:04+07:00" level=info msg="zeroconf server listening on port 46511" Jan 27 21:28:04 volumio go-librespot[30374]: time="2026-01-27T21:28:04+07:00" level=debug msg="obtained new client token: AAAui3x5PkrzTcp49/HhArF5FTCMYlw6tis5/wOYWeVCAjQti6O+48YjNVfwT1TfBNuA8ooOk6vgU53kdy+IOt6TLAehIRclkjDKH+IwafmmfOSA9GODoXK30mkW9VsMRERuhQZq/Vzsy7BYd68iAF7nHGXGh55wOlzHNxGbv4esON6LF0TLq/xER6v1WN+VktZIkACrpA0oBNn6lIhnhNXHnDr8l2hvapLIj37+CqZsYoDbNi8BYoB+IR0=" Jan 27 21:28:04 volumio go-librespot[30374]: time="2026-01-27T21:28:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:28:04 volumio go-librespot[30374]: time="2026-01-27T21:28:04+07:00" level=debug msg="completed keyexchange" Jan 27 21:28:04 volumio go-librespot[30374]: time="2026-01-27T21:28:04+07:00" level=debug msg="completed challenge" Jan 27 21:28:04 volumio go-librespot[30374]: time="2026-01-27T21:28: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 21:28:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:28:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:28:05 volumio volumio[30005]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 27 21:28:05 volumio volumio[30005]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 27 21:28:05 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:28:05 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:28:05 volumio volumio[30005]: info: Starting MyVolumio Remote Streaming Endpoints Jan 27 21:28:05 volumio volumio[30005]: info: MyVolumio login type: Token Jan 27 21:28:05 volumio volumio[30005]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 27 21:28:05 volumio volumio[30005]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 27 21:28:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:07 volumio volumio[30005]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 27 21:28:07 volumio volumio[30005]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 27 21:28:07 volumio volumio[30005]: info: Streaming services startup Jan 27 21:28:07 volumio volumio[30005]: info: Starting Streaming Daemon Jan 27 21:28:07 volumio sudo[30397]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 21:28:07 volumio volumio[30005]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 27 21:28:07 volumio sudo[30397]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:07 volumio sudo[30397]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:07 volumio volumio[30005]: info: Getting Spotify volume Jan 27 21:28:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 27 21:28:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:07 volumio volumio[30005]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 21:28:07 volumio volumio[30005]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:28:07 volumio volumio[30005]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 27 21:28:07 volumio volumio[30005]: errno: -111, Jan 27 21:28:07 volumio volumio[30005]: code: 'ECONNREFUSED', Jan 27 21:28:07 volumio volumio[30005]: syscall: 'connect', Jan 27 21:28:07 volumio volumio[30005]: address: '127.0.0.1', Jan 27 21:28:07 volumio volumio[30005]: port: 9879, Jan 27 21:28:07 volumio volumio[30005]: response: undefined Jan 27 21:28:07 volumio volumio[30005]: } Jan 27 21:28:07 volumio volumio[30005]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 21:28:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:07 volumio go-librespot[30403]: go-librespot daemon starting... Jan 27 21:28:07 volumio go-librespot[30407]: time="2026-01-27T21:28:07+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:28:07 volumio go-librespot[30407]: time="2026-01-27T21:28:07+07:00" level=debug msg="app state loaded" Jan 27 21:28:07 volumio go-librespot[30407]: time="2026-01-27T21:28:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:28:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:08 volumio go-librespot[30407]: time="2026-01-27T21:28: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-gew1.spotify.com:80]" Jan 27 21:28:08 volumio go-librespot[30407]: time="2026-01-27T21:28:08+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 21:28:08 volumio go-librespot[30407]: time="2026-01-27T21:28:08+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 21:28:08 volumio go-librespot[30407]: time="2026-01-27T21:28:08+07:00" level=info msg="zeroconf server listening on port 34511" Jan 27 21:28:08 volumio go-librespot[30407]: time="2026-01-27T21:28:08+07:00" level=debug msg="obtained new client token: AABewF2VgACV86J5ob1y/oxyB+tYAYg7815Bsi6Uzs9PgHOL+3Mvs7r3cNoTrcdgbCXg55p87464caxN5ozBBrDshv9ltQTIExp2v2eV2ymuhGl8PgE5qo2oKFWu0oWnYirDhDajphiWkdqPocYNFrRpkfdTfdKgBQN7ww/Hocvou3Hmjb1gYk2boKmN7MgM15NkgEeDS0vc2aD1FZCfOShzq9luJ/CBSHWY4YyTnbvZotcJImabyO/J0Bs=" Jan 27 21:28:08 volumio go-librespot[30407]: time="2026-01-27T21:28:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:28:08 volumio go-librespot[30407]: time="2026-01-27T21:28: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 21:28:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:28:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:28:09 volumio sudo[30425]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 21:27' Jan 27 21:28:09 volumio sudo[30425]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:09 volumio sudo[30425]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:09 volumio volumio-remote-updater[628]: [2026-01-27 21:28:09] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 27 21:28:09 volumio volumio-remote-updater[628]: [2026-01-27 21:28:09] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 27 21:28:09 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:28:09 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 27 21:28:09 volumio systemd[1]: volumio.service: Consumed 57.401s CPU time. Jan 27 21:28:09 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 21:28:09 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 21:28:09 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 9164. Jan 27 21:28:09 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 21:28:09 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 27 21:28:09 volumio systemd[1]: volumio.service: Consumed 57.401s CPU time. Jan 27 21:28:09 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 27 21:28:09 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 21:28:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 27 21:28:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:12 volumio go-librespot[30454]: go-librespot daemon starting... Jan 27 21:28:12 volumio go-librespot[30455]: time="2026-01-27T21:28:12+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:28:12 volumio go-librespot[30455]: time="2026-01-27T21:28:12+07:00" level=debug msg="app state loaded" Jan 27 21:28:12 volumio go-librespot[30455]: time="2026-01-27T21:28:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:28:12 volumio go-librespot[30455]: time="2026-01-27T21:28: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 21:28:12 volumio go-librespot[30455]: time="2026-01-27T21:28: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 21:28:12 volumio go-librespot[30455]: time="2026-01-27T21:28: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 21:28:12 volumio go-librespot[30455]: time="2026-01-27T21:28:12+07:00" level=info msg="zeroconf server listening on port 43967" Jan 27 21:28:12 volumio go-librespot[30455]: time="2026-01-27T21:28:12+07:00" level=debug msg="obtained new client token: AADXZLHDARwkABtEG/iOA0HKCiT5cVvea0hLenGNmAyYSJUVZ4DqeZoxC+YPhYbwa6mBUd7r1GSsuWtIS/pcd4XO0VF//9U4aO/pu+34+F+gGajCs9TZN8w+RyFx/mILsVXTcupvgZrwiSXxstD/wGZ3x9wP7g5IyA2O4en6/96yKFQpNUBSMfmxKRMR3e9qxwZ0+zIvRqXqoyssXzgRWEoQxWY+FAirHiuQstcOTrn/KLlvlmd4VB9O0S0=" Jan 27 21:28:13 volumio go-librespot[30455]: time="2026-01-27T21:28:13+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 21:28:13 volumio go-librespot[30455]: time="2026-01-27T21:28:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 21:28:13 volumio go-librespot[30455]: time="2026-01-27T21:28:13+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 21:28:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:28:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:28:13 volumio volumio[30438]: info: ------------------------------------------- Jan 27 21:28:13 volumio volumio[30438]: info: ----- Volumio3 ---- Jan 27 21:28:13 volumio volumio[30438]: info: ------------------------------------------- Jan 27 21:28:13 volumio volumio[30438]: info: ----- System startup ---- Jan 27 21:28:13 volumio volumio[30438]: info: ------------------------------------------- Jan 27 21:28:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:14 volumio volumio-remote-updater[628]: [2026-01-27 21:28:14] [connect] Successful connection Jan 27 21:28:14 volumio volumio[30438]: info: MYVOLUMIO Environment detected Jan 27 21:28:14 volumio volumio[30438]: info: Plugin folders cleanup Jan 27 21:28:14 volumio volumio[30438]: info: Scanning into folder /volumio/app/plugins/ Jan 27 21:28:14 volumio volumio[30438]: info: Scanning category audio_interface Jan 27 21:28:14 volumio volumio[30438]: info: Scanning category miscellanea Jan 27 21:28:14 volumio volumio[30438]: info: Scanning category music_service Jan 27 21:28:14 volumio volumio[30438]: info: Scanning category plugins.json Jan 27 21:28:14 volumio volumio[30438]: info: Scanning category system_controller Jan 27 21:28:14 volumio volumio[30438]: info: Scanning category user_interface Jan 27 21:28:14 volumio volumio[30438]: info: Scanning into folder /data/plugins/ Jan 27 21:28:14 volumio volumio[30438]: info: Scanning category music_service Jan 27 21:28:14 volumio volumio[30438]: info: Plugin folders cleanup completed Jan 27 21:28:14 volumio volumio[30438]: info: ------------------------------------------- Jan 27 21:28:14 volumio volumio[30438]: info: ----- Core plugins startup ---- Jan 27 21:28:14 volumio volumio[30438]: info: ------------------------------------------- Jan 27 21:28:14 volumio volumio[30438]: info: Loading plugins from folder /volumio/app/plugins/ Jan 27 21:28:14 volumio volumio[30438]: info: Adding plugin upnp to MyMusic Plugins Jan 27 21:28:14 volumio volumio[30438]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 27 21:28:15 volumio volumio[30438]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 27 21:28:15 volumio volumio[30438]: info: Loading plugins from folder /data/plugins/ Jan 27 21:28:15 volumio volumio[30438]: info: Loading plugin "system"... Jan 27 21:28:15 volumio volumio[30438]: info: Loading plugin "appearance"... Jan 27 21:28:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 27 21:28:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:16 volumio go-librespot[30475]: go-librespot daemon starting... Jan 27 21:28:16 volumio go-librespot[30476]: time="2026-01-27T21:28:16+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:28:16 volumio go-librespot[30476]: time="2026-01-27T21:28:16+07:00" level=debug msg="app state loaded" Jan 27 21:28:16 volumio go-librespot[30476]: time="2026-01-27T21:28:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:28:16 volumio go-librespot[30476]: time="2026-01-27T21:28: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 21:28:16 volumio go-librespot[30476]: time="2026-01-27T21:28:16+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 21:28:16 volumio go-librespot[30476]: time="2026-01-27T21:28:16+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 21:28:16 volumio go-librespot[30476]: time="2026-01-27T21:28:16+07:00" level=info msg="zeroconf server listening on port 34141" Jan 27 21:28:17 volumio volumio[30438]: info: Loading plugin "network"... Jan 27 21:28:17 volumio volumio[30438]: info: Refreshing Cached IP Addresses Jan 27 21:28:17 volumio sudo[30484]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 21:28:17 volumio sudo[30484]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:17 volumio sudo[30486]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 21:28:17 volumio sudo[30484]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:17 volumio sudo[30486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:17 volumio sudo[30486]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:17 volumio volumio[30438]: info: Loading plugin "services"... Jan 27 21:28:17 volumio volumio[30438]: info: Loading plugin "alsa_controller"... Jan 27 21:28:17 volumio sudo[30495]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 27 21:28:17 volumio sudo[30495]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:17 volumio go-librespot[30476]: time="2026-01-27T21:28:17+07:00" level=debug msg="obtained new client token: AABCU4rAdy4WagoZnMUseBKjkxX9O4EfykQi2/eJ2S01PYlt0k22wkLQMftiHQXn/Er7+HEbnBrty9gAX2hGWYmAm6vXieGfdkQI0vg3/Kvr/7OkycI26ORty+e0F8M7t38mm1Pf6zfQ7iM59/YmpIDGX8qbPy/jD0w88I7xBmP6qLXUuBsHyw8mq5S3qcZFf+bTfqDB41OI2VA8HYBgwpgWH8VzVSnfSG4VG/ogRdaUD2fADBp2pmdI" Jan 27 21:28:17 volumio go-librespot[30476]: time="2026-01-27T21:28:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:28:17 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 21:28:17 volumio volumio[30438]: info: Loading plugin "wizard"... Jan 27 21:28:17 volumio volumio[30438]: info: Loading plugin "networkfs"... Jan 27 21:28:17 volumio volumio[30438]: info: Starting Udev Watcher for removable devices Jan 27 21:28:17 volumio volumio[30438]: info: Ignoring mount for partition: boot Jan 27 21:28:17 volumio volumio[30438]: info: Ignoring mount for partition: volumio Jan 27 21:28:17 volumio volumio[30438]: info: Ignoring mount for partition: volumio_data Jan 27 21:28:17 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 21:28:17 volumio volumio[30438]: info: Loading plugin "volumio_command_line_client"... Jan 27 21:28:17 volumio volumio[30438]: info: Loading plugin "upnp"... Jan 27 21:28:17 volumio volumio[30438]: info: [1769524097459] Starting Upmpd Daemon Jan 27 21:28:17 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 21:28:17 volumio volumio[30438]: info: Loading plugin "my_music"... Jan 27 21:28:17 volumio volumio[30438]: info: Loading plugin "mpd"... Jan 27 21:28:17 volumio go-librespot[30476]: time="2026-01-27T21:28: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: read tcp 192.168.1.107:35162->104.199.241.202:4070: read: connection reset by peer" Jan 27 21:28:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:28:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:28:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:18 volumio volumio[30438]: info: Loading plugin "upnp_browser"... Jan 27 21:28:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:20 volumio sudo[30495]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 27 21:28:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:21 volumio volumio[30438]: info: Starting UPNP Browser Jan 27 21:28:21 volumio volumio[30438]: info: Loading plugin "alarm-clock"... Jan 27 21:28:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:21 volumio go-librespot[30520]: go-librespot daemon starting... Jan 27 21:28:21 volumio go-librespot[30521]: time="2026-01-27T21:28:21+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:28:21 volumio go-librespot[30521]: time="2026-01-27T21:28:21+07:00" level=debug msg="app state loaded" Jan 27 21:28:21 volumio go-librespot[30521]: time="2026-01-27T21:28:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:28:21 volumio volumio[30438]: info: Loading plugin "airplay_emulation"... Jan 27 21:28:21 volumio volumio[30438]: info: Starting Shairport Sync Jan 27 21:28:21 volumio volumio[30438]: info: Loading plugin "last_100"... Jan 27 21:28:21 volumio volumio[30438]: info: Loading plugin "webradio"... Jan 27 21:28:21 volumio volumio[30438]: info: Loading plugin "i2s_dacs"... Jan 27 21:28:21 volumio volumio[30438]: info: Loading plugin "volumiodiscovery"... Jan 27 21:28:21 volumio go-librespot[30521]: time="2026-01-27T21:28: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 21:28:21 volumio go-librespot[30521]: time="2026-01-27T21:28: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 21:28:21 volumio go-librespot[30521]: time="2026-01-27T21:28: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 21:28:21 volumio go-librespot[30521]: time="2026-01-27T21:28:21+07:00" level=info msg="zeroconf server listening on port 35035" Jan 27 21:28:21 volumio volumio[30438]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 21:28:21 volumio volumio[30438]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 21:28:21 volumio volumio[30438]: *** WARNING *** For more information see Jan 27 21:28:21 volumio volumio[30438]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 21:28:21 volumio volumio[30438]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 21:28:21 volumio volumio[30438]: *** WARNING *** For more information see Jan 27 21:28:21 volumio node[30438]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 21:28:21 volumio node[30438]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 21:28:21 volumio node[30438]: *** WARNING *** For more information see Jan 27 21:28:21 volumio node[30438]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 21:28:21 volumio node[30438]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 21:28:21 volumio node[30438]: *** WARNING *** For more information see Jan 27 21:28:21 volumio volumio[30438]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 27 21:28:21 volumio volumio[30438]: info: Discovery: Started advertising with name: Volumio Jan 27 21:28:21 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 21:28:21 volumio volumio[30438]: info: Loading plugin "spop"... Jan 27 21:28:21 volumio go-librespot[30521]: time="2026-01-27T21:28:21+07:00" level=debug msg="obtained new client token: AABVqLUeDbySrwd4+2cys8lvGbnXdNdgWXTeo9JVDQd+fq2YhBiZ88C6szG3Aa7Dyych7HdOhSgvI/hZJfzcn2C88ii1998Csuxhz53jXake+3TgRl1wAF+Zk3++Li5wnil2VkpOkeuISJyp/u6okir/jUpkvnHwPdXVGJ9gb4sM8t+8D2Ond+WHX1nMpOpiuRoF1ets3rqfOzkE4HA8AE5okITUBqkPnkjLFjDqpmYG6cMwT19fS+IAQ9s=" Jan 27 21:28:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:22 volumio go-librespot[30521]: time="2026-01-27T21:28:22+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 21:28:22 volumio go-librespot[30521]: time="2026-01-27T21:28:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 21:28:22 volumio go-librespot[30521]: time="2026-01-27T21:28:22+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 21:28:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:28:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:28:23 volumio volumio[30438]: info: Loading plugin "ytcr"... Jan 27 21:28:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 27 21:28:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:25 volumio go-librespot[30530]: go-librespot daemon starting... Jan 27 21:28:25 volumio go-librespot[30531]: time="2026-01-27T21:28:25+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:28:25 volumio go-librespot[30531]: time="2026-01-27T21:28:25+07:00" level=debug msg="app state loaded" Jan 27 21:28:25 volumio go-librespot[30531]: time="2026-01-27T21:28:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:28:25 volumio go-librespot[30531]: time="2026-01-27T21:28: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:28:25 volumio go-librespot[30531]: time="2026-01-27T21:28:25+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 21:28:25 volumio go-librespot[30531]: time="2026-01-27T21:28:25+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 21:28:25 volumio go-librespot[30531]: time="2026-01-27T21:28:25+07:00" level=info msg="zeroconf server listening on port 34987" Jan 27 21:28:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:26 volumio go-librespot[30531]: time="2026-01-27T21:28:26+07:00" level=debug msg="obtained new client token: AABLWLA6imrvSRlm8pdosO5ghEP8AuBU+j4duqa8iPJVMVkX8vdpubQwKtL9szqo8OSmjmDZ9Fj2yrTlWo5falXHY7nRiUcmzh5+4E7KhiTZCpTwXzujEHtb191N6EH/opWqzVeu8VqpGgmtXmko0wLOIs2wASrAMwVjWRGeOJE1hu1IHj4HJKFa1pLGgs/sKAuI9PAK5VHsMmxsQe1G9DYKGeoauGHAa0VO2BTfOPulV4k/u7HDZq8T" Jan 27 21:28:26 volumio go-librespot[30531]: time="2026-01-27T21:28:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:28:26 volumio go-librespot[30531]: time="2026-01-27T21:28:26+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 21:28:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:28:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:28:26 volumio volumio[30438]: info: Loading plugin "ytmusic"... Jan 27 21:28:27 volumio volumio-remote-updater[628]: [2026-01-27 21:28:27] [connect] Successful connection Jan 27 21:28:27 volumio volumio[30438]: info: Loading plugin "outputs"... Jan 27 21:28:27 volumio volumio[30438]: info: Loading plugin "albumart"... Jan 27 21:28:27 volumio volumio[30438]: info: Plugin example_plugin is not enabled Jan 27 21:28:27 volumio volumio[30438]: info: Loading plugin "inputs"... Jan 27 21:28:27 volumio volumio[30438]: info: Loading plugin "updater_comm"... Jan 27 21:28:27 volumio volumio[30438]: info: Plugin mpdemulation is not enabled Jan 27 21:28:27 volumio volumio[30438]: info: Loading plugin "rest_api"... Jan 27 21:28:27 volumio volumio[30438]: info: Loading plugin "websocket"... Jan 27 21:28:27 volumio volumio[30438]: info: Starting Socket.io Server version 1.7.4 Jan 27 21:28:27 volumio volumio[30438]: info: Loading plugin "RoonBridge"... Jan 27 21:28:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:28 volumio volumio[30438]: info: Applying required configuration parameters for plugin RoonBridge Jan 27 21:28:28 volumio volumio[30438]: info: Loading i18n strings for locale en Jan 27 21:28:28 volumio volumio[30438]: Updating browse sources language Jan 27 21:28:28 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:28:28 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 21:28:28 volumio volumio[30438]: info: CoreCommandRouter::initPlayerControls Jan 27 21:28:28 volumio volumio[30553]: Forking 3 albumart workers Jan 27 21:28:28 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:28 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:28 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:28 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:28 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:28 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:28 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:28 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:28 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 21:28:28 volumio volumio[30438]: Express server listening on port 3000 Jan 27 21:28:28 volumio volumio[30438]: [Metrics] WebUI: 16s 150.04ms Jan 27 21:28:28 volumio volumio[30438]: info: CoreStateMachine::resetVolumioState Jan 27 21:28:28 volumio volumio[30438]: info: CoreStateMachine::getcurrentVolume Jan 27 21:28:28 volumio volumio[30438]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 21:28:28 volumio sudo[30596]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 21:28:28 volumio sudo[30596]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:28 volumio sudo[30598]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 21:28:28 volumio sudo[30598]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:28 volumio sudo[30598]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:28 volumio sudo[30596]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:28 volumio volumio[30438]: info: Volumio Network Manager: Network status updated: 1 Jan 27 21:28:29 volumio volumio[30438]: info: VolumeController:: Volume=100 Mute =false Jan 27 21:28:29 volumio volumio[30438]: info: CoreStateMachine::pushState Jan 27 21:28:29 volumio volumio[30438]: info: CorePlayQueue::getTrack 0 Jan 27 21:28:29 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 21:28:29 volumio volumio[30438]: info: CoreCommandRouter::volumioPushState Jan 27 21:28:29 volumio volumio[30438]: info: CoreStateMachine::updateTrackBlock Jan 27 21:28:29 volumio volumio[30438]: info: CorePlayQueue::getTrackBlock Jan 27 21:28:29 volumio volumio[30438]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 21:28:29 volumio volumio-remote-updater[628]: [2026-01-27 21:28:29] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769524107 101 Jan 27 21:28:29 volumio volumio[30438]: 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 21:28:29 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:28:29 volumio volumio[30438]: info: Reloading queue from file Jan 27 21:28:29 volumio volumio[30438]: info: CoreStateMachine::setRepeat null single undefined Jan 27 21:28:29 volumio volumio[30438]: info: CoreStateMachine::pushState Jan 27 21:28:29 volumio volumio[30438]: info: CorePlayQueue::getTrack 0 Jan 27 21:28:29 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 21:28:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 27 21:28:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:29 volumio volumio[30438]: info: CoreCommandRouter::volumioPushState Jan 27 21:28:29 volumio volumio[30438]: info: CoreStateMachine::setRandom null Jan 27 21:28:29 volumio volumio[30438]: info: CoreStateMachine::pushState Jan 27 21:28:29 volumio volumio[30438]: info: CorePlayQueue::getTrack 0 Jan 27 21:28:29 volumio volumio[30438]: info: CoreCommandRouter::volumioPushState Jan 27 21:28:29 volumio volumio[30438]: info: Setting Device type: Raspberry PI Jan 27 21:28:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:29 volumio go-librespot[30612]: go-librespot daemon starting... Jan 27 21:28:29 volumio volumio[30438]: info: Completed loading Core Plugins Jan 27 21:28:29 volumio volumio[30438]: info: Preparing to generate the ALSA configuration file Jan 27 21:28:29 volumio go-librespot[30614]: time="2026-01-27T21:28:29+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:28:29 volumio go-librespot[30614]: time="2026-01-27T21:28:29+07:00" level=debug msg="app state loaded" Jan 27 21:28:29 volumio go-librespot[30614]: time="2026-01-27T21:28:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:28:29 volumio volumio[30438]: info: VolumeController:: Volume=100 Mute =false Jan 27 21:28:29 volumio volumio[30438]: info: CoreStateMachine::pushState Jan 27 21:28:29 volumio volumio[30438]: info: CorePlayQueue::getTrack 0 Jan 27 21:28:29 volumio volumio[30438]: info: CoreCommandRouter::volumioPushState Jan 27 21:28:29 volumio volumio[30438]: info: Asound.conf file unchanged, so no further update is needed Jan 27 21:28:29 volumio volumio[30438]: info: Output device has changed, restarting MPD Jan 27 21:28:29 volumio volumio[30438]: info: Output device has changed, restarting Shairport Sync Jan 27 21:28:29 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:29 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:28:29 volumio sudo[30622]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 27 21:28:29 volumio sudo[30622]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:29 volumio sudo[30627]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 21:28:29 volumio sudo[30627]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:30 volumio volumio[30438]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 21:28:30 volumio volumio[30438]: info: ___________ START PLUGINS ___________ Jan 27 21:28:30 volumio sudo[30625]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 21:28:30 volumio sudo[30625]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:30 volumio volumio[30438]: info: ControllerMpd::onStart: Initializing MPD Jan 27 21:28:30 volumio volumio[30438]: info: Creating MPD Configuration file Jan 27 21:28:30 volumio sudo[30625]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:30 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 27 21:28:30 volumio sudo[30636]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 21:28:30 volumio sudo[30636]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:30 volumio sudo[30622]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:30 volumio sudo[30636]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:30 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 21:28:30 volumio volumio[30438]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 21:28:30 volumio volumio[30438]: info: [1769524110147] CoreMusicLibrary::Adding element Media Servers Jan 27 21:28:30 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:28:30 volumio volumio[30438]: info: UPNP Browser: Client initialized successfully Jan 27 21:28:30 volumio sudo[30639]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 21:28:30 volumio sudo[30639]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:30 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 21:28:30 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 21:28:30 volumio systemd[1]: mpd.service: Consumed 7.443s CPU time. Jan 27 21:28:30 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 21:28:30 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 21:28:30 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 21:28:30 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:30 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:28:30 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 21:28:30 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 21:28:30 volumio volumio[30438]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 21:28:30 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:30 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:28:30 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 21:28:30 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 21:28:30 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 21:28:30 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 21:28:30 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 21:28:30 volumio go-librespot[30614]: time="2026-01-27T21:28:30+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 21:28:30 volumio go-librespot[30614]: time="2026-01-27T21:28:30+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 21:28:30 volumio go-librespot[30614]: time="2026-01-27T21:28:30+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 21:28:30 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 21:28:30 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 21:28:30 volumio go-librespot[30614]: time="2026-01-27T21:28:30+07:00" level=info msg="zeroconf server listening on port 40907" Jan 27 21:28:30 volumio volumio[30438]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 21:28:30 volumio volumio[30438]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 21:28:30 volumio volumio[30438]: info: [1769524110465] CoreMusicLibrary::Adding element Last_100 Jan 27 21:28:30 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:28:30 volumio volumio[30438]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 21:28:30 volumio volumio[30438]: info: [1769524110502] CoreMusicLibrary::Adding element Webradio Jan 27 21:28:30 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:28:30 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 21:28:30 volumio volumio[30438]: info: Initializing BBC Radios Jan 27 21:28:30 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 21:28:30 volumio go-librespot[30614]: time="2026-01-27T21:28:30+07:00" level=debug msg="obtained new client token: AABvdwlpXRX0CdCZGHaucFVNKbnnPRTE4/fCCbYVF2wos0/tqF9XECrvSuxqz7ItMYFCvQsM381o5hMNU/FlQuhqghVX/9T4NGukuTa3A+bNFTuLrEu/f9YUwUBbMvezKTfjlp88kbvzs8f6vpSOOWnyvl8pUxoJ7wSNSnJxyoYsfc8wRPoLqp3w8raMdDQBaTgClVw7EyKcByiCHQK9i7xWNjY7v+WBkt4CYbjCTU39DrcAEDUg29B9x4g=" Jan 27 21:28:30 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:28:30 volumio volumio[30438]: info: Creating Spotify config file Jan 27 21:28:30 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:30 volumio go-librespot[30614]: time="2026-01-27T21:28:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:28:30 volumio go-librespot[30614]: time="2026-01-27T21:28:30+07:00" level=debug msg="completed keyexchange" Jan 27 21:28:30 volumio go-librespot[30614]: time="2026-01-27T21:28:30+07:00" level=debug msg="completed challenge" Jan 27 21:28:30 volumio sudo[30652]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 27 21:28:30 volumio sudo[30652]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 27 21:28:30 volumio sudo[30652]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:30 volumio go-librespot[30614]: time="2026-01-27T21:28:30+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 21:28:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:28:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:28:31 volumio volumio[30438]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 21:28:31 volumio volumio[30438]: info: [1769524111807] CoreMusicLibrary::Adding element YouTube Music Jan 27 21:28:31 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:28:31 volumio volumio[30438]: Cannot find translation for source YouTube Music Jan 27 21:28:31 volumio volumio[30438]: info: Volumio Calling Home Jan 27 21:28:31 volumio sudo[30669]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 27 21:28:31 volumio sudo[30669]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:32 volumio sudo[30669]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:32 volumio volumio[30565]: Starting albumart workers Jan 27 21:28:32 volumio volumio[30438]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 21:28:32 volumio volumio[30438]: info: Discovery: Found device Volumio Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::volumioGetState Jan 27 21:28:32 volumio volumio[30438]: info: CorePlayQueue::getTrack 0 Jan 27 21:28:32 volumio volumio[30564]: Starting albumart workers Jan 27 21:28:32 volumio volumio[30438]: info: MPD Permissions set Jan 27 21:28:32 volumio volumio[30438]: info: MPD Permissions set Jan 27 21:28:32 volumio volumio[30438]: info: Upmpdcli Daemon Started Jan 27 21:28:32 volumio volumio[30438]: info: Spotify config file written Jan 27 21:28:32 volumio volumio[30438]: 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 21:28:32 volumio sudo[30675]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 21:28:32 volumio sudo[30675]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:32 volumio volumio[30567]: Starting albumart workers Jan 27 21:28:32 volumio volumio[30438]: info: Volumio called home Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:32 volumio go-librespot[30679]: go-librespot daemon starting... Jan 27 21:28:32 volumio sudo[30675]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: No need to fix Spotify hosts Jan 27 21:28:33 volumio go-librespot[30683]: time="2026-01-27T21:28:33+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:28:33 volumio go-librespot[30683]: time="2026-01-27T21:28:33+07:00" level=debug msg="app state loaded" Jan 27 21:28:33 volumio go-librespot[30683]: time="2026-01-27T21:28:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:28:33 volumio volumio[30438]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 21:28:33 volumio volumio[30438]: info: Discovery: Found device Volumio Jan 27 21:28:33 volumio volumio[30438]: info: CoreCommandRouter::volumioGetState Jan 27 21:28:33 volumio volumio[30438]: info: CorePlayQueue::getTrack 0 Jan 27 21:28:33 volumio go-librespot[30683]: time="2026-01-27T21:28: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:28:33 volumio go-librespot[30683]: time="2026-01-27T21:28:33+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 21:28:33 volumio go-librespot[30683]: time="2026-01-27T21:28:33+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 21:28:33 volumio go-librespot[30683]: time="2026-01-27T21:28:33+07:00" level=info msg="zeroconf server listening on port 36569" Jan 27 21:28:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:34 volumio go-librespot[30683]: time="2026-01-27T21:28:34+07:00" level=debug msg="obtained new client token: AAASM2iS4F7jxYpKlSmqG0djtOLeiV0T0QU2t+aQnKDynQ6x5oKBWyJwNQpnba6njgP0ZJAG8m4jv1uVW5gg9KMeBYV0sHaiaomjiI/ljFdnGlz5yBp/WYJJjBMnBE7wH4DpGxiOb8nU9YisdvG92Xj4M0XoBpdQBB6unDzAZ64LjvOs7KObg8zlqaqnVA7dHcuGbjLV1gKtF8qnXmbPYdlQ34fGOGnzen476cLMrqFdOkH7DPbkpdtv" Jan 27 21:28:34 volumio go-librespot[30683]: time="2026-01-27T21:28:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:28:34 volumio go-librespot[30683]: time="2026-01-27T21:28: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 21:28:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:28:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:28:34 volumio volumio[30438]: info: Starting Shairport Sync Jan 27 21:28:34 volumio volumio[30438]: info: Starting Shairport Sync Jan 27 21:28:34 volumio volumio[30438]: info: Starting Shairport Sync Jan 27 21:28:34 volumio sudo[30710]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 21:28:34 volumio sudo[30717]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 21:28:34 volumio sudo[30717]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:34 volumio sudo[30710]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:34 volumio volumio[30438]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 21:28:34 volumio volumio[30438]: SPOTIFY: BQAJbIptB0JlYTd_SOtfatkBVxhQ4bLn1A4QO1VIw_Z4iRiUflCIlH1NXLD6xBbP367rQWYD7qbJ2gyiuE2UlRa7cpnfN6m7iVFiRkSSNxWtfeVZecg5AGdGW0iPrAp7UnrUpGxOA82XXZOzu067hwjRkFG9EuhG8BXaWqJV303pzk--YnWWqIEc9YcJf0OEEqz3ZLqTc5Ey97RPf6bwSr6ONsaPGrxON97SD0kDzkvyr-V9X_ffShUU6BAQ2SLeMEwimYc8gB5SsiO_8seTPWSRwYuIz-hjpjlcuC5Lv6zoPwA6c1XqKgRr Jan 27 21:28:34 volumio volumio[30438]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 21:28:34 volumio volumio[30438]: info: New Spotify access token = BQAJbIptB0JlYTd_SOtfatkBVxhQ4bLn1A4QO1VIw_Z4iRiUflCIlH1NXLD6xBbP367rQWYD7qbJ2gyiuE2UlRa7cpnfN6m7iVFiRkSSNxWtfeVZecg5AGdGW0iPrAp7UnrUpGxOA82XXZOzu067hwjRkFG9EuhG8BXaWqJV303pzk--YnWWqIEc9YcJf0OEEqz3ZLqTc5Ey97RPf6bwSr6ONsaPGrxON97SD0kDzkvyr-V9X_ffShUU6BAQ2SLeMEwimYc8gB5SsiO_8seTPWSRwYuIz-hjpjlcuC5Lv6zoPwA6c1XqKgRr Jan 27 21:28:34 volumio volumio[30438]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 27 21:28:34 volumio sudo[30719]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 21:28:35 volumio sudo[30719]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:35 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 21:28:35 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 21:28:35 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 21:28:35 volumio systemd[1]: shairport-sync.service: Consumed 2.239s CPU time. Jan 27 21:28:35 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 21:28:35 volumio sudo[30717]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:35 volumio sudo[30710]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:35 volumio sudo[30719]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:35 volumio volumio[30438]: info: Shairport-Sync Started Jan 27 21:28:35 volumio volumio[30438]: Error adding Membership: Error: addMembership EINVAL Jan 27 21:28:35 volumio volumio[30438]: info: Shairport-Sync Started Jan 27 21:28:35 volumio volumio[30438]: info: Shairport-Sync Started Jan 27 21:28:35 volumio volumio[30438]: info: CoreCommandRouter::volumioGetState Jan 27 21:28:35 volumio volumio[30438]: info: CorePlayQueue::getTrack 0 Jan 27 21:28:35 volumio volumio[30438]: 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 21:28:35 volumio volumio[30438]: info: Spotify Successfully logged in Jan 27 21:28:35 volumio volumio[30438]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 21:28:35 volumio volumio[30438]: info: [1769524115781] CoreMusicLibrary::Adding element Spotify Jan 27 21:28:35 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:28:35 volumio volumio[30438]: Cannot find translation for source YouTube Music Jan 27 21:28:35 volumio volumio[30438]: Cannot find translation for source Spotify Jan 27 21:28:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:36 volumio volumio[30438]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 27 21:28:36 volumio volumio[30438]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 21:28:36 volumio volumio[30438]: info: VolumeController:: Volume=100 Mute =false Jan 27 21:28:36 volumio volumio[30438]: info: CoreCommandRouter::volumioGetState Jan 27 21:28:36 volumio volumio[30438]: info: CorePlayQueue::getTrack 0 Jan 27 21:28:36 volumio volumio[30438]: info: CoreStateMachine::pushState Jan 27 21:28:36 volumio volumio[30438]: info: CorePlayQueue::getTrack 0 Jan 27 21:28:36 volumio volumio[30438]: info: CoreCommandRouter::volumioPushState Jan 27 21:28:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 27 21:28:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:37 volumio volumio[30438]: info: go-librespot daemon successfully initialized Jan 27 21:28:37 volumio go-librespot[30755]: go-librespot daemon starting... Jan 27 21:28:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:37 volumio go-librespot[30756]: time="2026-01-27T21:28:37+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:28:37 volumio go-librespot[30756]: time="2026-01-27T21:28:37+07:00" level=debug msg="app state loaded" Jan 27 21:28:37 volumio go-librespot[30756]: time="2026-01-27T21:28:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:28:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:38 volumio go-librespot[30756]: time="2026-01-27T21:28: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:28:38 volumio go-librespot[30756]: time="2026-01-27T21:28:38+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 21:28:38 volumio go-librespot[30756]: time="2026-01-27T21:28:38+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 21:28:38 volumio go-librespot[30756]: time="2026-01-27T21:28:38+07:00" level=info msg="zeroconf server listening on port 38555" Jan 27 21:28:38 volumio mpd[30667]: 2026-01-27T21:28:38 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 27 21:28:38 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 27 21:28:38 volumio sudo[30639]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:38 volumio sudo[30627]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:38 volumio go-librespot[30756]: time="2026-01-27T21:28:38+07:00" level=debug msg="obtained new client token: AABKx5/gRWFW1f0xEgXtHVjJtn1sfnAUhWDSFOnjFeLU1/098b8oE8AP+gO/uTNsEjlVTGL7M6edfwwgRpWYICYKT5Lim6aai8vY3Gl/BEe4uA/Cr8YuMGhSUxFzF2D2WlMiEFGMej4U2rdW6KUqVoNmkw/8m95G7C54DDbDUm+kZCk8cVR4PznNmZl8Ws01mMauurAb7OQb+HP16jpzTzqyLJ8KcV5aGuWjY47PzjnDkovl9JeCXMrKXrc=" Jan 27 21:28:38 volumio go-librespot[30756]: time="2026-01-27T21:28:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:28:38 volumio go-librespot[30756]: time="2026-01-27T21:28: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 21:28:38 volumio volumio[30438]: error: MPD error: The expression evaluated to a falsy value: Jan 27 21:28:38 volumio volumio[30438]: assert.ok(self.idling) Jan 27 21:28:38 volumio volumio[30438]: error: The expression evaluated to a falsy value: Jan 27 21:28:38 volumio volumio[30438]: assert.ok(self.idling) Jan 27 21:28:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:28:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:28:38 volumio volumio[30438]: info: MPD running with PID30667 Jan 27 21:28:38 volumio volumio[30438]: ,establishing connection Jan 27 21:28:38 volumio volumio[30438]: error: updateQueue error: null Jan 27 21:28:38 volumio volumio[30438]: info: Completed starting Core Plugins Jan 27 21:28:38 volumio volumio[30438]: info: ------------------------------------------- Jan 27 21:28:38 volumio volumio[30438]: info: ----- MyVolumio plugins startup ---- Jan 27 21:28:38 volumio volumio[30438]: info: ------------------------------------------- Jan 27 21:28:38 volumio volumio[30438]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 27 21:28:38 volumio volumio[30438]: error: updateQueue error: null Jan 27 21:28:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:40 volumio volumio[30438]: info: Initializing connection to go-librespot Websocket Jan 27 21:28:40 volumio volumio[30438]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:28:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Jan 27 21:28:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:41 volumio go-librespot[30767]: go-librespot daemon starting... Jan 27 21:28:41 volumio go-librespot[30768]: time="2026-01-27T21:28:41+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:28:41 volumio go-librespot[30768]: time="2026-01-27T21:28:41+07:00" level=debug msg="app state loaded" Jan 27 21:28:41 volumio go-librespot[30768]: time="2026-01-27T21:28:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:28:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:42 volumio go-librespot[30768]: time="2026-01-27T21:28:42+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 21:28:42 volumio go-librespot[30768]: time="2026-01-27T21:28:42+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 21:28:42 volumio go-librespot[30768]: time="2026-01-27T21:28:42+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 21:28:42 volumio go-librespot[30768]: time="2026-01-27T21:28:42+07:00" level=info msg="zeroconf server listening on port 35937" Jan 27 21:28:42 volumio go-librespot[30768]: time="2026-01-27T21:28:42+07:00" level=debug msg="obtained new client token: AABOlKHRAqbpjOtVRTXOLwVUho6tFbpOdb9X6ZpmfYYMOd6/9u2yDlfUANqWncxAQg0Vy2/MaOO0Y0by9iF39u3brJ1VTI/ON3iPjni0RMCKtkQjEPWr6YwfJD3cMWvJju9AgpZmpStaX6+/YXPKgMtyjUo93y+N90R6CDOv1/DGXJtxXaA8pxzJECdpoZIB4VXgm8x49k+1G8Xy2LOGF0f/J99HbhptMFRXMH/v+uQiGThdVBpzvRj25iI=" Jan 27 21:28:42 volumio go-librespot[30768]: time="2026-01-27T21:28:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:28:42 volumio go-librespot[30768]: time="2026-01-27T21:28: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 21:28:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:28:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:28:43 volumio volumio[30438]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 27 21:28:43 volumio volumio[30438]: info: Initializing connection to go-librespot Websocket Jan 27 21:28:43 volumio volumio[30438]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:28:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jan 27 21:28:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:46 volumio go-librespot[30775]: go-librespot daemon starting... Jan 27 21:28:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:46 volumio go-librespot[30776]: time="2026-01-27T21:28:46+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:28:46 volumio go-librespot[30776]: time="2026-01-27T21:28:46+07:00" level=debug msg="app state loaded" Jan 27 21:28:46 volumio go-librespot[30776]: time="2026-01-27T21:28:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:28:46 volumio go-librespot[30776]: time="2026-01-27T21:28: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:28:46 volumio go-librespot[30776]: time="2026-01-27T21:28:46+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 21:28:46 volumio go-librespot[30776]: time="2026-01-27T21:28:46+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 21:28:46 volumio go-librespot[30776]: time="2026-01-27T21:28:46+07:00" level=info msg="zeroconf server listening on port 34445" Jan 27 21:28:46 volumio volumio[30438]: info: Initializing connection to go-librespot Websocket Jan 27 21:28:46 volumio go-librespot[30776]: time="2026-01-27T21:28:46+07:00" level=debug msg="new websocket client" Jan 27 21:28:46 volumio volumio[30438]: info: Connection to go-librespot Websocket established Jan 27 21:28:46 volumio go-librespot[30776]: time="2026-01-27T21:28:46+07:00" level=debug msg="obtained new client token: AAADFYpxIO+Vye1nItQcNwFIs+qkbhFEYNJzCgJ5iXktJK9AcrgIzOJsFo5uqdFEMyGOcy2+BJEzdnw4De0/tuUHZQfgfoXQVP8CsMm7WO0Nipv6VY64Zap6GJ0NuK5lUwQ6z5ZSLnRWNApN+JEiKTgCijb3e8U5SAdvvPAc8p79cb6jqKDXkotltrJl4svUHonOY6TfVJq4dV1MGBiO9dyfsGZTCGqywiPondRKuAPgHJWSFhTnL5J7hJs=" Jan 27 21:28:46 volumio go-librespot[30776]: time="2026-01-27T21:28:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:28:46 volumio go-librespot[30776]: time="2026-01-27T21:28:46+07:00" level=debug msg="completed keyexchange" Jan 27 21:28:46 volumio go-librespot[30776]: time="2026-01-27T21:28:46+07:00" level=debug msg="completed challenge" Jan 27 21:28:47 volumio go-librespot[30776]: time="2026-01-27T21:28:47+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 21:28:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:28:47 volumio volumio[30438]: info: Connection to go-librespot Websocket closed Jan 27 21:28:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 27 21:28:47 volumio volumio[30438]: info: Adding plugin bluetooth to MyMusic Plugins Jan 27 21:28:47 volumio volumio[30438]: info: Adding plugin multiroom to MyMusic Plugins Jan 27 21:28:47 volumio volumio[30438]: info: Adding plugin metavolumio to MyMusic Plugins Jan 27 21:28:47 volumio volumio[30438]: info: Adding plugin cd_controller to MyMusic Plugins Jan 27 21:28:47 volumio volumio[30438]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 27 21:28:47 volumio volumio[30438]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 27 21:28:47 volumio volumio[30438]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 27 21:28:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:49 volumio volumio[30438]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 27 21:28:49 volumio volumio[30438]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 27 21:28:49 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:28:49 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:28:49 volumio volumio[30438]: info: Starting MyVolumio Remote Streaming Endpoints Jan 27 21:28:49 volumio volumio[30438]: info: MyVolumio login type: Token Jan 27 21:28:49 volumio volumio[30438]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 27 21:28:49 volumio volumio[30438]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 27 21:28:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Jan 27 21:28:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:50 volumio go-librespot[30798]: go-librespot daemon starting... Jan 27 21:28:50 volumio go-librespot[30801]: time="2026-01-27T21:28:50+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:28:50 volumio go-librespot[30801]: time="2026-01-27T21:28:50+07:00" level=debug msg="app state loaded" Jan 27 21:28:50 volumio go-librespot[30801]: time="2026-01-27T21:28:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:28:50 volumio go-librespot[30801]: time="2026-01-27T21:28: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 21:28:50 volumio go-librespot[30801]: time="2026-01-27T21:28: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 21:28:50 volumio go-librespot[30801]: time="2026-01-27T21:28: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 21:28:50 volumio go-librespot[30801]: time="2026-01-27T21:28:50+07:00" level=info msg="zeroconf server listening on port 33515" Jan 27 21:28:51 volumio go-librespot[30801]: time="2026-01-27T21:28:51+07:00" level=debug msg="obtained new client token: AAAksMwUohlPKLZTyqB0iHoTZtgLrWJctRnf1mf7v47gkCcDNPmCXRD6Wc5wtxjJWDqi4Xrqf2PSUBiPeCZk9xbXrAWE/Ps72PtdALZ76P3NI9NoXYdqKtXyluAOCZw5a+tFRdMl7dFxnM1k+QoPxsKeaIVZOojXTwEh7QiNeZhVCe9V7GW39zmF4/YDczGOJPI1GFGs6/r45H1qeMlYOhQ/PqIG7DrzxZUOk65HQnpRSe4Jmp/YXYk+" Jan 27 21:28:51 volumio volumio[30438]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 27 21:28:51 volumio volumio[30438]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 27 21:28:51 volumio volumio[30438]: info: Streaming services startup Jan 27 21:28:51 volumio volumio[30438]: info: Starting Streaming Daemon Jan 27 21:28:51 volumio go-librespot[30801]: time="2026-01-27T21:28:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:28:51 volumio sudo[30810]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 21:28:51 volumio sudo[30810]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:51 volumio volumio[30438]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 27 21:28:51 volumio go-librespot[30801]: time="2026-01-27T21:28:51+07:00" level=debug msg="completed keyexchange" Jan 27 21:28:51 volumio sudo[30810]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:51 volumio go-librespot[30801]: time="2026-01-27T21:28:51+07:00" level=debug msg="completed challenge" Jan 27 21:28:51 volumio volumio[30438]: info: Getting Spotify volume Jan 27 21:28:51 volumio volumio[30438]: info: Initializing connection to go-librespot Websocket Jan 27 21:28:51 volumio go-librespot[30801]: time="2026-01-27T21:28: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 21:28:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:28:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:28:51 volumio volumio[30438]: error: Cannot start Volumio Streaming Daemon Jan 27 21:28:51 volumio volumio[30438]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 21:28:51 volumio volumio[30438]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 21:28:51 volumio volumio[30438]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 21:28:51 volumio volumio[30438]: Error: socket hang up Jan 27 21:28:51 volumio volumio[30438]: at connResetException (node:internal/errors:720:14) Jan 27 21:28:51 volumio volumio[30438]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 27 21:28:51 volumio volumio[30438]: at Socket.emit (node:events:526:35) Jan 27 21:28:51 volumio volumio[30438]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 27 21:28:51 volumio volumio[30438]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 27 21:28:51 volumio volumio[30438]: code: 'ECONNRESET', Jan 27 21:28:51 volumio volumio[30438]: response: undefined Jan 27 21:28:51 volumio volumio[30438]: } Jan 27 21:28:51 volumio volumio[30438]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 21:28:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:52 volumio sudo[30830]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 21:27' Jan 27 21:28:52 volumio sudo[30830]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"