Jan 28 22:15:00 volumio volumio[31236]: info: Initializing connection to go-librespot Websocket Jan 28 22:15:00 volumio volumio[31236]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 22:15:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:15:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:15:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:15:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 22:15:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:15:03 volumio volumio[31236]: info: Initializing connection to go-librespot Websocket Jan 28 22:15:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:15:03 volumio volumio[31236]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 22:15:03 volumio go-librespot[31577]: go-librespot daemon starting... Jan 28 22:15:03 volumio go-librespot[31578]: time="2026-01-28T22:15:03+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:15:03 volumio go-librespot[31578]: time="2026-01-28T22:15:03+07:00" level=debug msg="app state loaded" Jan 28 22:15:03 volumio go-librespot[31578]: time="2026-01-28T22:15:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:15:03 volumio go-librespot[31578]: time="2026-01-28T22:15:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 22:15:03 volumio go-librespot[31578]: time="2026-01-28T22:15:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 22:15:03 volumio go-librespot[31578]: time="2026-01-28T22:15:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 22:15:03 volumio go-librespot[31578]: time="2026-01-28T22:15:03+07:00" level=info msg="zeroconf server listening on port 37995" Jan 28 22:15:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:15:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:15:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:15:03 volumio volumio[31236]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 22:15:03 volumio volumio[31236]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 22:15:03 volumio volumio[31236]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 22:15:03 volumio volumio[31236]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 22:15:03 volumio volumio[31236]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 22:15:03 volumio volumio[31236]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 22:15:03 volumio volumio[31236]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 22:15:03 volumio volumio[31236]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 22:15:03 volumio volumio[31236]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 22:15:03 volumio volumio[31236]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 22:15:03 volumio volumio[31236]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 22:15:03 volumio volumio[31236]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 22:15:03 volumio volumio[31236]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 22:15:03 volumio volumio[31236]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 22:15:03 volumio volumio[31236]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 22:15:03 volumio volumio[31236]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 22:15:03 volumio volumio[31236]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 22:15:03 volumio volumio[31236]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 22:15:03 volumio volumio[31236]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 22:15:03 volumio volumio[31236]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 22:15:03 volumio volumio[31236]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 22:15:03 volumio volumio[31236]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 22:15:03 volumio volumio[31236]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 22:15:03 volumio volumio[31236]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 22:15:03 volumio volumio[31236]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 22:15:03 volumio volumio[31236]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 22:15:03 volumio volumio[31236]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 22:15:03 volumio volumio[31236]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 22:15:03 volumio volumio[31236]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 22:15:03 volumio volumio[31236]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 22:15:03 volumio volumio[31236]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 22:15:03 volumio volumio[31236]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 22:15:03 volumio volumio[31236]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 22:15:03 volumio volumio[31236]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 22:15:03 volumio volumio[31236]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 22:15:03 volumio volumio[31236]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 22:15:03 volumio go-librespot[31578]: time="2026-01-28T22:15:03+07:00" level=debug msg="obtained new client token: AAAgcgPgpMF7L1qFlpK3TwoIaEEuh/wx3iJ2o+8j3d01XWUI+n4xVD941fbIC/yQyXqv5Bl5cmz2LcSGI1uw0iikknJ2AvyK3jxOXPsi39b7XpsDhrIfzUbqBe9Whn1C5Zd1Xk4Cf+5FlAs6fxdYEo1cEtYB/CW2jC/ZrQr52nnxhJ3X2VgfvghwA6LZsobludrJ0Sn90dqa63THbNYL+x/5pezK8M0MfsgVaLL2U5ex/95gBqP7eZWl+lQ=" Jan 28 22:15:03 volumio go-librespot[31578]: time="2026-01-28T22:15:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:15:04 volumio go-librespot[31578]: time="2026-01-28T22:15:04+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 22:15:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:15:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:15:05 volumio volumio[31236]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 22:15:05 volumio volumio[31236]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 22:15:05 volumio volumio[31236]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:15:05 volumio volumio[31236]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:15:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:15:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:15:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:15:05 volumio volumio[31236]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 22:15:05 volumio volumio[31236]: info: MyVolumio login type: Token Jan 28 22:15:05 volumio volumio[31236]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 22:15:05 volumio volumio[31236]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 22:15:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 28 22:15:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:15:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:15:07 volumio go-librespot[31599]: go-librespot daemon starting... Jan 28 22:15:07 volumio volumio[31236]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 22:15:07 volumio volumio[31236]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 22:15:07 volumio volumio[31236]: info: Streaming services startup Jan 28 22:15:07 volumio volumio[31236]: info: Starting Streaming Daemon Jan 28 22:15:07 volumio go-librespot[31600]: time="2026-01-28T22:15:07+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:15:07 volumio go-librespot[31600]: time="2026-01-28T22:15:07+07:00" level=debug msg="app state loaded" Jan 28 22:15:07 volumio go-librespot[31600]: time="2026-01-28T22:15:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:15:07 volumio sudo[31607]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 22:15:07 volumio sudo[31607]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:15:07 volumio volumio[31236]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 22:15:07 volumio sudo[31607]: pam_unix(sudo:session): session closed for user root Jan 28 22:15:07 volumio volumio[31236]: info: Initializing connection to go-librespot Websocket Jan 28 22:15:07 volumio volumio[31236]: error: Cannot start Volumio Streaming Daemon Jan 28 22:15:07 volumio volumio[31236]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 22:15:07 volumio volumio[31236]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 22:15:07 volumio go-librespot[31600]: time="2026-01-28T22:15:07+07:00" level=debug msg="new websocket client" Jan 28 22:15:07 volumio volumio[31236]: info: Connection to go-librespot Websocket established Jan 28 22:15:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:15:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:15:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:15:07 volumio go-librespot[31600]: time="2026-01-28T22:15: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 22:15:07 volumio go-librespot[31600]: time="2026-01-28T22:15:07+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 28 22:15:07 volumio go-librespot[31600]: time="2026-01-28T22:15:07+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 28 22:15:07 volumio go-librespot[31600]: time="2026-01-28T22:15:07+07:00" level=info msg="zeroconf server listening on port 38733" Jan 28 22:15:08 volumio go-librespot[31600]: time="2026-01-28T22:15:08+07:00" level=debug msg="obtained new client token: AACLyOzBFJimi0hwZc0v98oAn4Ji/7jJVpRbFQiFF+tTotcD8ol5EPPQ4robD35wxU0Jn2qokVQ0e3lEpo2II5JZdEqT9Ki9RVbKUlzUA1BXvP/3Mzn07cHpYoJH/ZdKEX5b5XmkHHwkeqXOzcRmRxATev4VJibEiYsMFwNRvdj49DGjlnoNRnYdwXbpSIAl3IEiwNaKiUot9ROM10w4+NyXMNvfXFtqDcYGD6hNs/+WHsK8hzhVDcn3" Jan 28 22:15:08 volumio go-librespot[31600]: time="2026-01-28T22:15:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:15:08 volumio go-librespot[31600]: time="2026-01-28T22:15: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 28 22:15:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:15:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:15:08 volumio volumio[31236]: info: Connection to go-librespot Websocket closed Jan 28 22:15:08 volumio volumio[31236]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 28 22:15:09 volumio volumio[31236]: info: MyVolumio token set successfully Jan 28 22:15:09 volumio volumio[31236]: info: MYVOLUMIO: Adding device Jan 28 22:15:09 volumio volumio[31236]: info: MYVOLUMIO: Evaluating Server Jan 28 22:15:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:15:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:15:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:15:09 volumio volumio[31236]: info: MyVolumio status changed Jan 28 22:15:09 volumio volumio[31236]: info: Streaming services startup Jan 28 22:15:09 volumio volumio[31236]: info: Starting Streaming Daemon Jan 28 22:15:09 volumio volumio[31236]: info: Removing browser output: myVolumio user plan is not superstar Jan 28 22:15:09 volumio volumio[31236]: info: Removing audio output: Jan 28 22:15:09 volumio volumio[31236]: info: Stoppping Tunnel 1 Jan 28 22:15:09 volumio sudo[31635]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 22:15:09 volumio sudo[31635]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:15:10 volumio sudo[31635]: pam_unix(sudo:session): session closed for user root Jan 28 22:15:10 volumio sudo[31638]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 28 22:15:10 volumio sudo[31638]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:15:10 volumio volumio[31236]: error: Cannot start Volumio Streaming Daemon Jan 28 22:15:10 volumio volumio[31236]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 22:15:10 volumio volumio[31236]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 22:15:10 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 28 22:15:10 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 28 22:15:10 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 28 22:15:10 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 28 22:15:10 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 28 22:15:10 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 28 22:15:10 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 28 22:15:10 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 28 22:15:10 volumio sudo[31638]: pam_unix(sudo:session): session closed for user root Jan 28 22:15:10 volumio volumio[31236]: info: Remote SSH Stopped Jan 28 22:15:10 volumio volumio[31236]: info: Getting Spotify volume Jan 28 22:15:10 volumio volumio[31236]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 22:15:10 volumio volumio[31236]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 22:15:10 volumio volumio[31236]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 28 22:15:10 volumio volumio[31236]: errno: -111, Jan 28 22:15:10 volumio volumio[31236]: code: 'ECONNREFUSED', Jan 28 22:15:10 volumio volumio[31236]: syscall: 'connect', Jan 28 22:15:10 volumio volumio[31236]: address: '127.0.0.1', Jan 28 22:15:10 volumio volumio[31236]: port: 9879, Jan 28 22:15:10 volumio volumio[31236]: response: undefined Jan 28 22:15:10 volumio volumio[31236]: } Jan 28 22:15:10 volumio volumio[31236]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 22:15:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 28 22:15:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:15:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:15:11 volumio go-librespot[31653]: go-librespot daemon starting... Jan 28 22:15:11 volumio go-librespot[31654]: time="2026-01-28T22:15:11+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:15:11 volumio go-librespot[31654]: time="2026-01-28T22:15:11+07:00" level=debug msg="app state loaded" Jan 28 22:15:11 volumio go-librespot[31654]: time="2026-01-28T22:15:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:15:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:15:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:15:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:15:12 volumio go-librespot[31654]: time="2026-01-28T22:15: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 22:15:12 volumio sudo[31663]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 22:14' Jan 28 22:15:12 volumio go-librespot[31654]: time="2026-01-28T22:15:12+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 28 22:15:12 volumio go-librespot[31654]: time="2026-01-28T22:15:12+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 28 22:15:12 volumio sudo[31663]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:15:12 volumio go-librespot[31654]: time="2026-01-28T22:15:12+07:00" level=info msg="zeroconf server listening on port 43209" Jan 28 22:15:12 volumio go-librespot[31654]: time="2026-01-28T22:15:12+07:00" level=debug msg="obtained new client token: AABXvvtruc2XWA88HEdmDtF5F0r9xec1q7ZUmo7ArqaF7uzlw2WTj8wX0QH/lNUXaXkzSAxX6PdNIF6QCSkjmbtpmoO3r6vd6wDxdWGVjetWJ5QmHL9xTQlpbXFjUpbo/gFd1ZzHhcxBx78YndmA5yIk2vgFNvl6yPgwXlN5cBwWqgIUavRwFtdT4El5lysE9xjIxspIivcx3w/siLAe96mTOQsqp9KfVTT/TPE7etH58NVz3GtZnOFMC/4=" Jan 28 22:15:12 volumio sudo[31663]: pam_unix(sudo:session): session closed for user root Jan 28 22:15:12 volumio go-librespot[31654]: time="2026-01-28T22:15:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:15:12 volumio go-librespot[31654]: time="2026-01-28T22:15:12+07:00" level=debug msg="completed keyexchange" Jan 28 22:15:12 volumio go-librespot[31654]: time="2026-01-28T22:15:12+07:00" level=debug msg="completed challenge" Jan 28 22:15:12 volumio volumio-remote-updater[628]: [2026-01-28 22:15:12] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Jan 28 22:15:12 volumio volumio-remote-updater[628]: [2026-01-28 22:15:12] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Jan 28 22:15:12 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:15:12 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 22:15:12 volumio systemd[1]: volumio.service: Consumed 1min 2.645s CPU time. Jan 28 22:15:12 volumio go-librespot[31654]: time="2026-01-28T22:15:12+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 22:15:12 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 22:15:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:15:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:15:12 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 22:15:12 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10759. Jan 28 22:15:12 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 22:15:12 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 22:15:12 volumio systemd[1]: volumio.service: Consumed 1min 2.645s CPU time. Jan 28 22:15:12 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 22:15:12 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 22:15:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:15:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:15:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:15:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:15:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:15:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:15:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 28 22:15:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:15:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:15:15 volumio go-librespot[31693]: go-librespot daemon starting... Jan 28 22:15:15 volumio go-librespot[31694]: time="2026-01-28T22:15:15+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:15:15 volumio go-librespot[31694]: time="2026-01-28T22:15:15+07:00" level=debug msg="app state loaded" Jan 28 22:15:15 volumio go-librespot[31694]: time="2026-01-28T22:15:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:15:16 volumio volumio[31678]: info: ------------------------------------------- Jan 28 22:15:16 volumio volumio[31678]: info: ----- Volumio3 ---- Jan 28 22:15:16 volumio volumio[31678]: info: ------------------------------------------- Jan 28 22:15:16 volumio volumio[31678]: info: ----- System startup ---- Jan 28 22:15:16 volumio volumio[31678]: info: ------------------------------------------- Jan 28 22:15:16 volumio go-librespot[31694]: time="2026-01-28T22:15:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 22:15:16 volumio go-librespot[31694]: time="2026-01-28T22:15:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 22:15:16 volumio go-librespot[31694]: time="2026-01-28T22:15:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 22:15:16 volumio go-librespot[31694]: time="2026-01-28T22:15:16+07:00" level=info msg="zeroconf server listening on port 43055" Jan 28 22:15:16 volumio go-librespot[31694]: time="2026-01-28T22:15:16+07:00" level=debug msg="obtained new client token: AADY26qm3uoMk7ykqnJvPFzjbOKB0UlKZjhqZhoazQKAFlgWxQ0rvgPsknGjANGxRjSxzfGYBBYE4JMXiRlwzmF83f3ozCtmk2SzNzifpp1nxt+edgz5fBi0+oCwUwG6IxCHXGbR3mBkB9pOMVZC49ScUEIwvOBKu4xyJdqtRx0ziW1P5UBXj55/3tzpxEQFiJ+G3J2Y+BtlRd/YIfvMReYH9ta6a9ATa6MxmtHDfq5nyR03Q3oR7gW3ANs=" Jan 28 22:15:16 volumio go-librespot[31694]: time="2026-01-28T22:15:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:15:16 volumio go-librespot[31694]: time="2026-01-28T22:15:16+07:00" level=debug msg="completed keyexchange" Jan 28 22:15:16 volumio go-librespot[31694]: time="2026-01-28T22:15:16+07:00" level=debug msg="completed challenge" Jan 28 22:15:16 volumio go-librespot[31694]: time="2026-01-28T22:15:16+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 28 22:15:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:15:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:15:17 volumio volumio-remote-updater[628]: [2026-01-28 22:15:17] [connect] Successful connection Jan 28 22:15:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:15:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:15:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:15:17 volumio volumio[31678]: info: MYVOLUMIO Environment detected Jan 28 22:15:17 volumio volumio[31678]: info: Plugin folders cleanup Jan 28 22:15:17 volumio volumio[31678]: info: Scanning into folder /volumio/app/plugins/ Jan 28 22:15:17 volumio volumio[31678]: info: Scanning category audio_interface Jan 28 22:15:17 volumio volumio[31678]: info: Scanning category miscellanea Jan 28 22:15:17 volumio volumio[31678]: info: Scanning category music_service Jan 28 22:15:17 volumio volumio[31678]: info: Scanning category plugins.json Jan 28 22:15:17 volumio volumio[31678]: info: Scanning category system_controller Jan 28 22:15:17 volumio volumio[31678]: info: Scanning category user_interface Jan 28 22:15:17 volumio volumio[31678]: info: Scanning into folder /data/plugins/ Jan 28 22:15:17 volumio volumio[31678]: info: Scanning category music_service Jan 28 22:15:17 volumio volumio[31678]: info: Plugin folders cleanup completed Jan 28 22:15:17 volumio volumio[31678]: info: ------------------------------------------- Jan 28 22:15:17 volumio volumio[31678]: info: ----- Core plugins startup ---- Jan 28 22:15:17 volumio volumio[31678]: info: ------------------------------------------- Jan 28 22:15:17 volumio volumio[31678]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 22:15:17 volumio volumio[31678]: info: Adding plugin upnp to MyMusic Plugins Jan 28 22:15:17 volumio volumio[31678]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 22:15:17 volumio volumio[31678]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 22:15:17 volumio volumio[31678]: info: Loading plugins from folder /data/plugins/ Jan 28 22:15:17 volumio volumio[31678]: info: Loading plugin "system"... Jan 28 22:15:17 volumio volumio[31678]: info: Loading plugin "appearance"... Jan 28 22:15:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:15:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:15:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:15:19 volumio volumio[31678]: info: Loading plugin "network"... Jan 28 22:15:19 volumio volumio[31678]: info: Refreshing Cached IP Addresses Jan 28 22:15:19 volumio sudo[31716]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 22:15:19 volumio sudo[31716]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:15:19 volumio sudo[31716]: pam_unix(sudo:session): session closed for user root Jan 28 22:15:19 volumio sudo[31718]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 22:15:19 volumio sudo[31718]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:15:19 volumio sudo[31718]: pam_unix(sudo:session): session closed for user root Jan 28 22:15:19 volumio volumio[31678]: info: Loading plugin "services"... Jan 28 22:15:19 volumio volumio[31678]: info: Loading plugin "alsa_controller"... Jan 28 22:15:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 28 22:15:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:15:19 volumio sudo[31726]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 22:15:19 volumio sudo[31726]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:15:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:15:20 volumio go-librespot[31743]: go-librespot daemon starting... Jan 28 22:15:20 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 22:15:20 volumio volumio[31678]: info: Loading plugin "wizard"... Jan 28 22:15:20 volumio volumio[31678]: info: Loading plugin "networkfs"... Jan 28 22:15:20 volumio go-librespot[31750]: time="2026-01-28T22:15:20+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:15:20 volumio go-librespot[31750]: time="2026-01-28T22:15:20+07:00" level=debug msg="app state loaded" Jan 28 22:15:20 volumio go-librespot[31750]: time="2026-01-28T22:15:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:15:20 volumio volumio[31678]: info: Starting Udev Watcher for removable devices Jan 28 22:15:20 volumio volumio[31678]: info: Ignoring mount for partition: boot Jan 28 22:15:20 volumio volumio[31678]: info: Ignoring mount for partition: volumio Jan 28 22:15:20 volumio volumio[31678]: info: Ignoring mount for partition: volumio_data Jan 28 22:15:20 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 22:15:20 volumio volumio[31678]: info: Loading plugin "volumio_command_line_client"... Jan 28 22:15:20 volumio volumio[31678]: info: Loading plugin "upnp"... Jan 28 22:15:20 volumio volumio[31678]: info: [1769613320275] Starting Upmpd Daemon Jan 28 22:15:20 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 22:15:20 volumio volumio[31678]: info: Loading plugin "my_music"... Jan 28 22:15:20 volumio volumio[31678]: info: Loading plugin "mpd"... Jan 28 22:15:20 volumio go-librespot[31750]: time="2026-01-28T22:15:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 22:15:20 volumio go-librespot[31750]: time="2026-01-28T22:15:20+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 28 22:15:20 volumio go-librespot[31750]: time="2026-01-28T22:15:20+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 28 22:15:20 volumio go-librespot[31750]: time="2026-01-28T22:15:20+07:00" level=info msg="zeroconf server listening on port 33345" Jan 28 22:15:20 volumio go-librespot[31750]: time="2026-01-28T22:15:20+07:00" level=debug msg="obtained new client token: AACPlNDue87W69KNozo2pIQpMeJTSY6f3aQbXBlPC2NedB/v8UJiVarqEg6hEfU5n423EVeR9FpnfQDGkI/Cc49uzN+J7kgh9PIxOqcGF6VnS4w2ArLypVvjXaW7VRTIe2IncFAopSu0EP3QjR62cmYBNmCyQO2tKyzSFqoGsEt69ftJ/dBj756sz2b7y+IBRSpkVRWeCnIGZbixtqV5em65g4FBxCS92qTy74GYmGRWOJ4NeYEvtVUfti8=" Jan 28 22:15:20 volumio volumio[31678]: info: Loading plugin "upnp_browser"... Jan 28 22:15:21 volumio go-librespot[31750]: time="2026-01-28T22:15:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:15:21 volumio go-librespot[31750]: time="2026-01-28T22:15:21+07:00" level=debug msg="completed keyexchange" Jan 28 22:15:21 volumio go-librespot[31750]: time="2026-01-28T22:15:21+07:00" level=debug msg="completed challenge" Jan 28 22:15:21 volumio go-librespot[31750]: time="2026-01-28T22:15:21+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 28 22:15:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:15:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:15:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:15:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:15:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:15:22 volumio sudo[31726]: pam_unix(sudo:session): session closed for user root Jan 28 22:15:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:15:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:15:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:15:23 volumio volumio[31678]: info: Starting UPNP Browser Jan 28 22:15:23 volumio volumio[31678]: info: Loading plugin "alarm-clock"... Jan 28 22:15:24 volumio volumio[31678]: info: Loading plugin "airplay_emulation"... Jan 28 22:15:24 volumio volumio[31678]: info: Starting Shairport Sync Jan 28 22:15:24 volumio volumio[31678]: info: Loading plugin "last_100"... Jan 28 22:15:24 volumio volumio[31678]: info: Loading plugin "webradio"... Jan 28 22:15:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 28 22:15:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:15:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:15:24 volumio go-librespot[31759]: go-librespot daemon starting... Jan 28 22:15:24 volumio go-librespot[31760]: time="2026-01-28T22:15:24+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:15:24 volumio go-librespot[31760]: time="2026-01-28T22:15:24+07:00" level=debug msg="app state loaded" Jan 28 22:15:24 volumio go-librespot[31760]: time="2026-01-28T22:15:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:15:24 volumio volumio[31678]: info: Loading plugin "i2s_dacs"... Jan 28 22:15:24 volumio volumio[31678]: info: Loading plugin "volumiodiscovery"... Jan 28 22:15:24 volumio volumio[31678]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 22:15:24 volumio volumio[31678]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 22:15:24 volumio volumio[31678]: *** WARNING *** For more information see Jan 28 22:15:24 volumio volumio[31678]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 22:15:24 volumio volumio[31678]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 22:15:24 volumio volumio[31678]: *** WARNING *** For more information see Jan 28 22:15:24 volumio node[31678]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 22:15:24 volumio node[31678]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 22:15:24 volumio node[31678]: *** WARNING *** For more information see Jan 28 22:15:24 volumio node[31678]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 22:15:24 volumio node[31678]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 22:15:24 volumio node[31678]: *** WARNING *** For more information see Jan 28 22:15:24 volumio volumio[31678]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 22:15:24 volumio volumio[31678]: info: Discovery: Started advertising with name: Volumio Jan 28 22:15:24 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 22:15:24 volumio volumio[31678]: info: Loading plugin "spop"... Jan 28 22:15:24 volumio go-librespot[31760]: time="2026-01-28T22:15: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 28 22:15:24 volumio go-librespot[31760]: time="2026-01-28T22:15: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 28 22:15:24 volumio go-librespot[31760]: time="2026-01-28T22:15: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 28 22:15:24 volumio go-librespot[31760]: time="2026-01-28T22:15:24+07:00" level=info msg="zeroconf server listening on port 35621" Jan 28 22:15:25 volumio go-librespot[31760]: time="2026-01-28T22:15:25+07:00" level=debug msg="obtained new client token: AAAqauFP1o1QSfBk742U8VPd50z5UZ1nT+jiMS1wIekxuGWRP2BL33US7x6EysqKCC94NVR76YvDFmDhCcftH3/C1CyFAeycJoFVzhSf4NMSzMMfwDVPv7c1wBET7Vy5eLavugHhtYr2vQ1Vijbx1pJu0dIWj1poaEKVQE8O3qzbeSxQ92VN8lMdfHKdELn+ir5H9SRvCYVX6z0ma3RVoUxXyCcuQOfK8Jwj6PrP+Dbu6Sbh65SQigOp" Jan 28 22:15:25 volumio go-librespot[31760]: time="2026-01-28T22:15:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:15:25 volumio go-librespot[31760]: time="2026-01-28T22:15:25+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 22:15:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:15:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:15:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:15:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:15:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:15:26 volumio volumio[31678]: info: Loading plugin "ytcr"... Jan 28 22:15:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:15:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:15:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:15:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 28 22:15:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:15:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:15:28 volumio go-librespot[31769]: go-librespot daemon starting... Jan 28 22:15:28 volumio go-librespot[31770]: time="2026-01-28T22:15:28+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:15:28 volumio go-librespot[31770]: time="2026-01-28T22:15:28+07:00" level=debug msg="app state loaded" Jan 28 22:15:28 volumio go-librespot[31770]: time="2026-01-28T22:15:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:15:29 volumio go-librespot[31770]: time="2026-01-28T22:15: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 22:15:29 volumio go-librespot[31770]: time="2026-01-28T22:15:29+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 28 22:15:29 volumio go-librespot[31770]: time="2026-01-28T22:15:29+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 28 22:15:29 volumio go-librespot[31770]: time="2026-01-28T22:15:29+07:00" level=info msg="zeroconf server listening on port 44643" Jan 28 22:15:29 volumio volumio[31678]: info: Loading plugin "ytmusic"... Jan 28 22:15:29 volumio go-librespot[31770]: time="2026-01-28T22:15:29+07:00" level=debug msg="obtained new client token: AADQlYAY3vzwPOpyvkgtE7o3x+hXqBc9CCC9KDd5ZWhG55qviI2tla/8mBQsSk2i2k1joyptIS9FUNUu3i7Vap4fXRoSqT0UwwEYsOT1jqO1QbZm/avi9FeK6LyMiNu0mRe1U2H/FcPpSzF6YY8Bc2+zPnUf0+WbDPvGaAxp0fenwSkbdlJtm9YnvMFByhdlC8rEKKfLz55SPDCVLGCxTBZM0DV2Makshh1MMAaSWy8LratBTt1mYJV3mkI=" Jan 28 22:15:29 volumio go-librespot[31770]: time="2026-01-28T22:15:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:15:29 volumio go-librespot[31770]: time="2026-01-28T22:15:29+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 28 22:15:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:15:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:15:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:15:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:15:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:15:30 volumio volumio-remote-updater[628]: [2026-01-28 22:15:30] [connect] Successful connection Jan 28 22:15:30 volumio volumio[31678]: info: Loading plugin "outputs"... Jan 28 22:15:30 volumio volumio[31678]: info: Loading plugin "albumart"... Jan 28 22:15:30 volumio volumio[31678]: info: Plugin example_plugin is not enabled Jan 28 22:15:30 volumio volumio[31678]: info: Loading plugin "inputs"... Jan 28 22:15:30 volumio volumio[31678]: info: Loading plugin "updater_comm"... Jan 28 22:15:30 volumio volumio[31678]: info: Plugin mpdemulation is not enabled Jan 28 22:15:30 volumio volumio[31678]: info: Loading plugin "rest_api"... Jan 28 22:15:30 volumio volumio[31678]: info: Loading plugin "websocket"... Jan 28 22:15:30 volumio volumio[31678]: info: Starting Socket.io Server version 1.7.4 Jan 28 22:15:30 volumio volumio[31678]: info: Loading plugin "RoonBridge"... Jan 28 22:15:31 volumio volumio[31678]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 22:15:31 volumio volumio[31678]: info: Loading i18n strings for locale en Jan 28 22:15:31 volumio volumio[31678]: Updating browse sources language Jan 28 22:15:31 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 22:15:31 volumio volumio[31791]: Forking 3 albumart workers Jan 28 22:15:31 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 22:15:31 volumio volumio[31678]: info: CoreCommandRouter::initPlayerControls Jan 28 22:15:31 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:15:31 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:15:31 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:15:31 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:15:31 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:15:31 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:15:31 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:15:31 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:15:31 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 22:15:31 volumio volumio[31678]: Express server listening on port 3000 Jan 28 22:15:31 volumio volumio[31678]: [Metrics] WebUI: 16s 214.93ms Jan 28 22:15:31 volumio volumio[31678]: info: CoreStateMachine::resetVolumioState Jan 28 22:15:31 volumio volumio[31678]: info: CoreStateMachine::getcurrentVolume Jan 28 22:15:31 volumio volumio[31678]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 22:15:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:15:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:15:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:15:31 volumio sudo[31836]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 22:15:31 volumio sudo[31836]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:15:31 volumio sudo[31836]: pam_unix(sudo:session): session closed for user root Jan 28 22:15:31 volumio sudo[31838]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 22:15:31 volumio sudo[31838]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:15:31 volumio sudo[31838]: pam_unix(sudo:session): session closed for user root Jan 28 22:15:31 volumio volumio[31678]: info: Volumio Network Manager: Network status updated: 1 Jan 28 22:15:32 volumio volumio[31678]: info: VolumeController:: Volume=100 Mute =false Jan 28 22:15:32 volumio volumio[31678]: info: CoreStateMachine::pushState Jan 28 22:15:32 volumio volumio[31678]: info: CorePlayQueue::getTrack 0 Jan 28 22:15:32 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 22:15:32 volumio volumio[31678]: info: CoreCommandRouter::volumioPushState Jan 28 22:15:32 volumio volumio[31678]: info: CoreStateMachine::updateTrackBlock Jan 28 22:15:32 volumio volumio[31678]: info: CorePlayQueue::getTrackBlock Jan 28 22:15:32 volumio volumio[31678]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 22:15:32 volumio volumio-remote-updater[628]: [2026-01-28 22:15:32] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769613330 101 Jan 28 22:15:32 volumio volumio[31678]: 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 28 22:15:32 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:15:32 volumio volumio[31678]: info: Reloading queue from file Jan 28 22:15:32 volumio volumio[31678]: info: CoreStateMachine::setRepeat null single undefined Jan 28 22:15:32 volumio volumio[31678]: info: CoreStateMachine::pushState Jan 28 22:15:32 volumio volumio[31678]: info: CorePlayQueue::getTrack 0 Jan 28 22:15:32 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 22:15:32 volumio volumio[31678]: info: CoreCommandRouter::volumioPushState Jan 28 22:15:32 volumio volumio[31678]: info: CoreStateMachine::setRandom null Jan 28 22:15:32 volumio volumio[31678]: info: CoreStateMachine::pushState Jan 28 22:15:32 volumio volumio[31678]: info: CorePlayQueue::getTrack 0 Jan 28 22:15:32 volumio volumio[31678]: info: CoreCommandRouter::volumioPushState Jan 28 22:15:32 volumio volumio[31678]: info: Setting Device type: Raspberry PI Jan 28 22:15:32 volumio volumio[31678]: info: Completed loading Core Plugins Jan 28 22:15:32 volumio volumio[31678]: info: Preparing to generate the ALSA configuration file Jan 28 22:15:32 volumio volumio[31678]: info: VolumeController:: Volume=100 Mute =false Jan 28 22:15:32 volumio volumio[31678]: info: CoreStateMachine::pushState Jan 28 22:15:32 volumio volumio[31678]: info: CorePlayQueue::getTrack 0 Jan 28 22:15:32 volumio volumio[31678]: info: CoreCommandRouter::volumioPushState Jan 28 22:15:32 volumio volumio[31678]: info: Asound.conf file unchanged, so no further update is needed Jan 28 22:15:32 volumio volumio[31678]: info: Output device has changed, restarting MPD Jan 28 22:15:32 volumio volumio[31678]: info: Output device has changed, restarting Shairport Sync Jan 28 22:15:32 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:15:32 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:15:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 28 22:15:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:15:32 volumio sudo[31853]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 22:15:32 volumio sudo[31853]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:15:32 volumio sudo[31853]: pam_unix(sudo:session): session closed for user root Jan 28 22:15:32 volumio sudo[31851]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 22:15:32 volumio sudo[31851]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:15:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:15:32 volumio go-librespot[31856]: go-librespot daemon starting... Jan 28 22:15:32 volumio sudo[31855]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 22:15:32 volumio volumio[31678]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 22:15:32 volumio sudo[31855]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:15:32 volumio volumio[31678]: info: ___________ START PLUGINS ___________ Jan 28 22:15:32 volumio go-librespot[31863]: time="2026-01-28T22:15:32+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:15:32 volumio go-librespot[31863]: time="2026-01-28T22:15:32+07:00" level=debug msg="app state loaded" Jan 28 22:15:32 volumio volumio[31678]: info: ControllerMpd::onStart: Initializing MPD Jan 28 22:15:32 volumio volumio[31678]: info: Creating MPD Configuration file Jan 28 22:15:32 volumio go-librespot[31863]: time="2026-01-28T22:15:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:15:32 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 22:15:32 volumio volumio[31678]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 22:15:32 volumio volumio[31678]: info: [1769613332981] CoreMusicLibrary::Adding element Media Servers Jan 28 22:15:32 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 22:15:33 volumio sudo[31871]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 22:15:33 volumio volumio[31678]: info: UPNP Browser: Client initialized successfully Jan 28 22:15:33 volumio sudo[31871]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:15:33 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 22:15:33 volumio sudo[31851]: pam_unix(sudo:session): session closed for user root Jan 28 22:15:33 volumio sudo[31871]: pam_unix(sudo:session): session closed for user root Jan 28 22:15:33 volumio sudo[31873]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 22:15:33 volumio sudo[31873]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:15:33 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 22:15:33 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 22:15:33 volumio systemd[1]: mpd.service: Consumed 7.427s CPU time. Jan 28 22:15:33 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 22:15:33 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 22:15:33 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 22:15:33 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:15:33 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:15:33 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 22:15:33 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 22:15:33 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 22:15:33 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 22:15:33 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 22:15:33 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 22:15:33 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 22:15:33 volumio volumio[31678]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 22:15:33 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:15:33 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:15:33 volumio volumio[31678]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 22:15:33 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 22:15:33 volumio volumio[31678]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 22:15:33 volumio volumio[31678]: info: [1769613333508] CoreMusicLibrary::Adding element Last_100 Jan 28 22:15:33 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 22:15:33 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 22:15:33 volumio volumio[31678]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 22:15:33 volumio volumio[31678]: info: [1769613333533] CoreMusicLibrary::Adding element Webradio Jan 28 22:15:33 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 22:15:33 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 22:15:33 volumio volumio[31678]: info: Initializing BBC Radios Jan 28 22:15:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:15:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:15:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:15:33 volumio go-librespot[31863]: time="2026-01-28T22:15:33+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 22:15:33 volumio go-librespot[31863]: time="2026-01-28T22:15:33+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 22:15:33 volumio go-librespot[31863]: time="2026-01-28T22:15:33+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 22:15:33 volumio go-librespot[31863]: time="2026-01-28T22:15:33+07:00" level=info msg="zeroconf server listening on port 41333" Jan 28 22:15:33 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 22:15:33 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:15:33 volumio volumio[31678]: info: Creating Spotify config file Jan 28 22:15:33 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:15:34 volumio go-librespot[31863]: time="2026-01-28T22:15:34+07:00" level=debug msg="obtained new client token: AADOoQR90WlkIijf3yBIWO2Q9B7DRnNwyQtrV1khoptJbj2A24e+tYvO/jUTP3ZxYDvgXA7Uxvx21S7Ij9itgu8PBTTZtFkZEDZlvDaKnNLjf3Z6dQz5dq/u3l0TS9REFsmDYikV0P2wB/cryPtl5JAzAebvveDftFJ2rtLX/jbpFAKAGBjrZ3+UT+OW62x0nChBpRvpUKch5Vw87VAe5NfJ83AtP3CWlX4fYemKDc6stYGiHPBoCc/QjvY=" Jan 28 22:15:34 volumio sudo[31889]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 22:15:34 volumio sudo[31889]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 22:15:34 volumio sudo[31889]: pam_unix(sudo:session): session closed for user root Jan 28 22:15:34 volumio go-librespot[31863]: time="2026-01-28T22:15:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:15:34 volumio go-librespot[31863]: time="2026-01-28T22:15:34+07:00" level=debug msg="completed keyexchange" Jan 28 22:15:34 volumio go-librespot[31863]: time="2026-01-28T22:15:34+07:00" level=debug msg="completed challenge" Jan 28 22:15:34 volumio go-librespot[31863]: time="2026-01-28T22:15:34+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 28 22:15:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:15:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:15:34 volumio volumio[31802]: Starting albumart workers Jan 28 22:15:34 volumio volumio[31803]: Starting albumart workers Jan 28 22:15:35 volumio volumio[31801]: Starting albumart workers Jan 28 22:15:35 volumio volumio[31678]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 22:15:35 volumio volumio[31678]: info: [1769613335430] CoreMusicLibrary::Adding element YouTube Music Jan 28 22:15:35 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 22:15:35 volumio volumio[31678]: Cannot find translation for source YouTube Music Jan 28 22:15:35 volumio volumio[31678]: info: Volumio Calling Home Jan 28 22:15:35 volumio sudo[31906]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 22:15:35 volumio sudo[31906]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:15:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:15:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:15:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:15:35 volumio sudo[31906]: pam_unix(sudo:session): session closed for user root Jan 28 22:15:36 volumio volumio[31678]: info: MPD Permissions set Jan 28 22:15:36 volumio volumio[31678]: info: MPD Permissions set Jan 28 22:15:36 volumio volumio[31678]: info: Upmpdcli Daemon Started Jan 28 22:15:36 volumio volumio[31678]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 22:15:36 volumio volumio[31678]: info: Discovery: Found device Volumio Jan 28 22:15:36 volumio volumio[31678]: info: CoreCommandRouter::volumioGetState Jan 28 22:15:36 volumio volumio[31678]: info: CorePlayQueue::getTrack 0 Jan 28 22:15:36 volumio volumio[31678]: info: Volumio called home Jan 28 22:15:36 volumio volumio[31678]: info: Spotify config file written Jan 28 22:15:36 volumio volumio[31678]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 22:15:36 volumio volumio[31678]: info: Discovery: Found device Volumio Jan 28 22:15:36 volumio volumio[31678]: info: CoreCommandRouter::volumioGetState Jan 28 22:15:36 volumio volumio[31678]: info: CorePlayQueue::getTrack 0 Jan 28 22:15:36 volumio sudo[31919]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 22:15:36 volumio sudo[31919]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:15:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:15:36 volumio volumio[31678]: 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 28 22:15:36 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:15:36 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:15:36 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:15:36 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:15:36 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:15:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:15:36 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:15:36 volumio go-librespot[31927]: go-librespot daemon starting... Jan 28 22:15:36 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:15:36 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:15:36 volumio sudo[31919]: pam_unix(sudo:session): session closed for user root Jan 28 22:15:36 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:15:36 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:15:36 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:15:36 volumio go-librespot[31928]: time="2026-01-28T22:15:36+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:15:36 volumio go-librespot[31928]: time="2026-01-28T22:15:36+07:00" level=debug msg="app state loaded" Jan 28 22:15:36 volumio go-librespot[31928]: time="2026-01-28T22:15:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:15:36 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:15:36 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:15:36 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:15:36 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:15:36 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:15:36 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:15:36 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:15:36 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:15:36 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:15:36 volumio volumio[31678]: info: No need to fix Spotify hosts Jan 28 22:15:37 volumio go-librespot[31928]: time="2026-01-28T22:15: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 28 22:15:37 volumio go-librespot[31928]: time="2026-01-28T22:15: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 28 22:15:37 volumio go-librespot[31928]: time="2026-01-28T22:15: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 28 22:15:37 volumio go-librespot[31928]: time="2026-01-28T22:15:37+07:00" level=info msg="zeroconf server listening on port 38407" Jan 28 22:15:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:15:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:15:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:15:37 volumio volumio[31678]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 22:15:37 volumio volumio[31678]: SPOTIFY: BQCqxc9PjgwSXpCiz_anH0Kl7g9hX84kucO1kRa0pa15tICMOjg50KBeuPIsfr3RMj0CicHFGW_087mJ8bpG9Qm7GQIEuX78GDwyLXI_2nUFae7UDCZJyVwRpJE6gmvNj19J_Ij4G-WAU9ax2T8QsFXA4mkuZMN5mlCvaF6_9cYlV8IVW4lSVwjmhfbic-IwO3EDMYoxJ9IT7UKWtb27vzx1gq7yXYAi1CZbPO_pIHSGdz10GB0S_uW94GIcoeFDQ2e08TL4RfyHlR7oGWpCGL_d700Y8mTJaYuUfPLQgh4R-XGVkTfJk2_0 Jan 28 22:15:37 volumio volumio[31678]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 22:15:37 volumio volumio[31678]: info: New Spotify access token = BQCqxc9PjgwSXpCiz_anH0Kl7g9hX84kucO1kRa0pa15tICMOjg50KBeuPIsfr3RMj0CicHFGW_087mJ8bpG9Qm7GQIEuX78GDwyLXI_2nUFae7UDCZJyVwRpJE6gmvNj19J_Ij4G-WAU9ax2T8QsFXA4mkuZMN5mlCvaF6_9cYlV8IVW4lSVwjmhfbic-IwO3EDMYoxJ9IT7UKWtb27vzx1gq7yXYAi1CZbPO_pIHSGdz10GB0S_uW94GIcoeFDQ2e08TL4RfyHlR7oGWpCGL_d700Y8mTJaYuUfPLQgh4R-XGVkTfJk2_0 Jan 28 22:15:37 volumio go-librespot[31928]: time="2026-01-28T22:15:37+07:00" level=debug msg="obtained new client token: AACE9VlaY8zaWI3kVERqBmwqjCRabHqecGFwIfzXa64eOPI/boleq3xh2tbg2QYsWt30NF5vlqDBgKR1e616g+QdasYU91Hzwrtb2iIlrw1jhsC9zJN/uVLdBo0aVz0MxaHIMbBU750oLkRexPWyfwhYVBCcLHfpxf4xR4jYWbtxXc+dW7rYOid3LoEAkpCfx0iZCYNoAWirNGCpVlcPfi/xX4tpsJocBZ+pnAuYwxRjZmaJga1jpChU+JY=" Jan 28 22:15:37 volumio volumio[31678]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 22:15:37 volumio volumio[31678]: info: Starting Shairport Sync Jan 28 22:15:37 volumio volumio[31678]: info: Starting Shairport Sync Jan 28 22:15:37 volumio volumio[31678]: info: Starting Shairport Sync Jan 28 22:15:37 volumio sudo[31953]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 22:15:37 volumio go-librespot[31928]: time="2026-01-28T22:15:37+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 28 22:15:37 volumio sudo[31953]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:15:37 volumio sudo[31957]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 22:15:37 volumio sudo[31957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:15:37 volumio sudo[31955]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 22:15:37 volumio go-librespot[31928]: time="2026-01-28T22:15:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 22:15:37 volumio sudo[31955]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:15:38 volumio go-librespot[31928]: time="2026-01-28T22:15: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 28 22:15:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:15:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:15:38 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 22:15:38 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 22:15:38 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 22:15:38 volumio systemd[1]: shairport-sync.service: Consumed 2.353s CPU time. Jan 28 22:15:38 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 22:15:38 volumio sudo[31957]: pam_unix(sudo:session): session closed for user root Jan 28 22:15:38 volumio sudo[31953]: pam_unix(sudo:session): session closed for user root Jan 28 22:15:38 volumio sudo[31955]: pam_unix(sudo:session): session closed for user root Jan 28 22:15:38 volumio volumio[31678]: info: CoreCommandRouter::volumioGetState Jan 28 22:15:38 volumio volumio[31678]: info: CorePlayQueue::getTrack 0 Jan 28 22:15:38 volumio volumio[31678]: info: Shairport-Sync Started Jan 28 22:15:38 volumio volumio[31678]: Error adding Membership: Error: addMembership EINVAL Jan 28 22:15:38 volumio volumio[31678]: info: Shairport-Sync Started Jan 28 22:15:38 volumio volumio[31678]: info: Shairport-Sync Started Jan 28 22:15:38 volumio volumio[31678]: 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 28 22:15:38 volumio volumio[31678]: info: Spotify Successfully logged in Jan 28 22:15:38 volumio volumio[31678]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 22:15:38 volumio volumio[31678]: info: [1769613338549] CoreMusicLibrary::Adding element Spotify Jan 28 22:15:38 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 22:15:38 volumio volumio[31678]: Cannot find translation for source YouTube Music Jan 28 22:15:38 volumio volumio[31678]: Cannot find translation for source Spotify Jan 28 22:15:39 volumio volumio[31678]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 22:15:39 volumio volumio[31678]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 22:15:39 volumio volumio[31678]: info: VolumeController:: Volume=100 Mute =false Jan 28 22:15:39 volumio volumio[31678]: info: CoreCommandRouter::volumioGetState Jan 28 22:15:39 volumio volumio[31678]: info: CorePlayQueue::getTrack 0 Jan 28 22:15:39 volumio volumio[31678]: info: CoreStateMachine::pushState Jan 28 22:15:39 volumio volumio[31678]: info: CorePlayQueue::getTrack 0 Jan 28 22:15:39 volumio volumio[31678]: info: CoreCommandRouter::volumioPushState Jan 28 22:15:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:15:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:15:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:15:40 volumio volumio[31678]: info: go-librespot daemon successfully initialized Jan 28 22:15:41 volumio mpd[31904]: 2026-01-28T22:15:41 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 22:15:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Jan 28 22:15:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:15:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:15:41 volumio go-librespot[31996]: go-librespot daemon starting... Jan 28 22:15:41 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 22:15:41 volumio sudo[31855]: pam_unix(sudo:session): session closed for user root Jan 28 22:15:41 volumio sudo[31873]: pam_unix(sudo:session): session closed for user root Jan 28 22:15:41 volumio go-librespot[31997]: time="2026-01-28T22:15:41+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:15:41 volumio go-librespot[31997]: time="2026-01-28T22:15:41+07:00" level=debug msg="app state loaded" Jan 28 22:15:41 volumio go-librespot[31997]: time="2026-01-28T22:15:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:15:41 volumio volumio[31678]: info: Completed starting Core Plugins Jan 28 22:15:41 volumio volumio[31678]: info: ------------------------------------------- Jan 28 22:15:41 volumio volumio[31678]: info: ----- MyVolumio plugins startup ---- Jan 28 22:15:41 volumio volumio[31678]: info: ------------------------------------------- Jan 28 22:15:41 volumio volumio[31678]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 22:15:41 volumio volumio[31678]: error: MPD error: The expression evaluated to a falsy value: Jan 28 22:15:41 volumio volumio[31678]: assert.ok(self.idling) Jan 28 22:15:41 volumio volumio[31678]: error: The expression evaluated to a falsy value: Jan 28 22:15:41 volumio volumio[31678]: assert.ok(self.idling) Jan 28 22:15:41 volumio volumio[31678]: info: MPD running with PID31904 Jan 28 22:15:41 volumio volumio[31678]: ,establishing connection Jan 28 22:15:41 volumio volumio[31678]: error: updateQueue error: null Jan 28 22:15:41 volumio volumio[31678]: error: updateQueue error: null Jan 28 22:15:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:15:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:15:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:15:41 volumio go-librespot[31997]: time="2026-01-28T22:15: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 28 22:15:41 volumio go-librespot[31997]: time="2026-01-28T22:15: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 28 22:15:41 volumio go-librespot[31997]: time="2026-01-28T22:15: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 28 22:15:41 volumio go-librespot[31997]: time="2026-01-28T22:15:41+07:00" level=info msg="zeroconf server listening on port 33081" Jan 28 22:15:42 volumio go-librespot[31997]: time="2026-01-28T22:15:42+07:00" level=debug msg="obtained new client token: AAC/YWrhdtYRsayATSX+BJTlGc2G6ZNDw2oD5ApQLc4Nmo8/GxOwnpreso+X8amWvrmxCHB8LA4WG1S961ZfdEHIoV7qnsg1c/K/tEjbJ111wJRQD54hL3h1xec5VVxTqFSHy+pX9gmv8F80tHiZnEvDyj2d2p6p1DVbYsEaBs6fq9XRbzz3MzQ5g1azCrb5+kTFm/G5NQSQe6E/EuFmGwhMjsuJxAJ1LsW9dXlW+nT8bPMd1t5saqtw" Jan 28 22:15:42 volumio go-librespot[31997]: time="2026-01-28T22:15:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:15:42 volumio go-librespot[31997]: time="2026-01-28T22:15: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 28 22:15:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:15:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:15:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:15:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:15:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:15:43 volumio volumio[31678]: info: Initializing connection to go-librespot Websocket Jan 28 22:15:43 volumio volumio[31678]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 22:15:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jan 28 22:15:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:15:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:15:45 volumio go-librespot[32007]: go-librespot daemon starting... Jan 28 22:15:45 volumio go-librespot[32008]: time="2026-01-28T22:15:45+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:15:45 volumio go-librespot[32008]: time="2026-01-28T22:15:45+07:00" level=debug msg="app state loaded" Jan 28 22:15:45 volumio go-librespot[32008]: time="2026-01-28T22:15:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:15:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:15:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:15:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:15:46 volumio go-librespot[32008]: time="2026-01-28T22:15: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 28 22:15:46 volumio go-librespot[32008]: time="2026-01-28T22:15: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 28 22:15:46 volumio go-librespot[32008]: time="2026-01-28T22:15: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 28 22:15:46 volumio go-librespot[32008]: time="2026-01-28T22:15:46+07:00" level=info msg="zeroconf server listening on port 46605" Jan 28 22:15:46 volumio go-librespot[32008]: time="2026-01-28T22:15:46+07:00" level=debug msg="obtained new client token: AACI5knhJjEbwj18ovCyM1bD7MRr9rXtfht1zpW5d7jhc/AzxrjlcYBkUGaWtfes24V3DY5Cy17Zujlwp2/buZG4UX30KA6CBvWasYh7DuX42MyROFaIJzoes07tSVJDcg3LDwZU4I5O30mCBG4Ht2lb698pExfbvMmDZ4zjfRji6neBkcocZ+Iruc9y71gG9/8dVWGTXCuYXjdeHVckCBWLU0e/zLyShSoxPYbQuZCK8tHP24MettUV" Jan 28 22:15:46 volumio go-librespot[32008]: time="2026-01-28T22:15:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:15:46 volumio volumio[31678]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 22:15:46 volumio go-librespot[32008]: time="2026-01-28T22:15:46+07:00" level=debug msg="completed keyexchange" Jan 28 22:15:46 volumio go-librespot[32008]: time="2026-01-28T22:15:46+07:00" level=debug msg="completed challenge" Jan 28 22:15:46 volumio go-librespot[32008]: time="2026-01-28T22:15:46+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 22:15:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:15:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:15:46 volumio volumio[31678]: info: Initializing connection to go-librespot Websocket Jan 28 22:15:46 volumio volumio[31678]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 22:15:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:15:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:15:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:15:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:15:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:15:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:15:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Jan 28 22:15:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:15:49 volumio volumio[31678]: info: Initializing connection to go-librespot Websocket Jan 28 22:15:49 volumio volumio[31678]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 22:15:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:15:49 volumio go-librespot[32015]: go-librespot daemon starting... Jan 28 22:15:49 volumio go-librespot[32016]: time="2026-01-28T22:15:49+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:15:49 volumio go-librespot[32016]: time="2026-01-28T22:15:49+07:00" level=debug msg="app state loaded" Jan 28 22:15:49 volumio go-librespot[32016]: time="2026-01-28T22:15:49+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:15:50 volumio go-librespot[32016]: time="2026-01-28T22:15: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-gew1.spotify.com:80]" Jan 28 22:15:50 volumio go-librespot[32016]: time="2026-01-28T22:15:50+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 28 22:15:50 volumio go-librespot[32016]: time="2026-01-28T22:15:50+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 28 22:15:50 volumio volumio[31678]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 22:15:50 volumio volumio[31678]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 22:15:50 volumio volumio[31678]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 22:15:50 volumio volumio[31678]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 22:15:50 volumio volumio[31678]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 22:15:50 volumio volumio[31678]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 22:15:50 volumio volumio[31678]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 22:15:50 volumio volumio[31678]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 22:15:50 volumio volumio[31678]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 22:15:50 volumio volumio[31678]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 22:15:50 volumio volumio[31678]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 22:15:50 volumio volumio[31678]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 22:15:50 volumio volumio[31678]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 22:15:50 volumio volumio[31678]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 22:15:50 volumio volumio[31678]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 22:15:50 volumio volumio[31678]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 22:15:50 volumio volumio[31678]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 22:15:50 volumio volumio[31678]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 22:15:50 volumio volumio[31678]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 22:15:50 volumio volumio[31678]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 22:15:50 volumio volumio[31678]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 22:15:50 volumio volumio[31678]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 22:15:50 volumio volumio[31678]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 22:15:50 volumio volumio[31678]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 22:15:50 volumio volumio[31678]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 22:15:50 volumio volumio[31678]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 22:15:50 volumio go-librespot[32016]: time="2026-01-28T22:15:50+07:00" level=info msg="zeroconf server listening on port 36213" Jan 28 22:15:50 volumio volumio[31678]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 22:15:50 volumio volumio[31678]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 22:15:50 volumio volumio[31678]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 22:15:50 volumio volumio[31678]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 22:15:50 volumio volumio[31678]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 22:15:50 volumio volumio[31678]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 22:15:50 volumio volumio[31678]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 22:15:50 volumio volumio[31678]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 22:15:50 volumio volumio[31678]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 22:15:50 volumio volumio[31678]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 22:15:50 volumio go-librespot[32016]: time="2026-01-28T22:15:50+07:00" level=debug msg="obtained new client token: AACY6fGn1lJ0bOKTkUb8oyUryLWZWqrnTdmp55s8ZryUvf4D2qSvDKQJwPxwluOemjMuES4jTFLF1cpDX0B678NNFAY34N0CkQzl2okM5T57Y+D0xk5SDPZ5ivfIMl8Qb7fB/T6qpyQm/3Cy6tZ9KTD6WqaN9lFWt4plS7DqxWrtbSbLggjjswCNcHoGl2rPU1Avx557hMTS2Si466wb20LCpVVmaBCb1NefR2ohfW3Fda8uAX9TkXJqymU=" Jan 28 22:15:50 volumio go-librespot[32016]: time="2026-01-28T22:15:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:15:50 volumio go-librespot[32016]: time="2026-01-28T22:15:50+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 22:15:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:15:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:15:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:15:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:15:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:15:52 volumio volumio[31678]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 22:15:52 volumio volumio[31678]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 22:15:52 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:15:52 volumio volumio[31678]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:15:52 volumio volumio[31678]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 22:15:52 volumio volumio[31678]: info: MyVolumio login type: Token Jan 28 22:15:52 volumio volumio[31678]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 22:15:52 volumio volumio[31678]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 22:15:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:15:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:15:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:15:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Jan 28 22:15:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:15:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:15:53 volumio go-librespot[32038]: go-librespot daemon starting... Jan 28 22:15:53 volumio go-librespot[32039]: time="2026-01-28T22:15:53+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:15:53 volumio go-librespot[32039]: time="2026-01-28T22:15:53+07:00" level=debug msg="app state loaded" Jan 28 22:15:53 volumio go-librespot[32039]: time="2026-01-28T22:15:53+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:15:53 volumio volumio[31678]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 22:15:53 volumio volumio[31678]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 22:15:53 volumio volumio[31678]: info: Streaming services startup Jan 28 22:15:53 volumio volumio[31678]: info: Starting Streaming Daemon Jan 28 22:15:54 volumio sudo[32047]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 22:15:54 volumio sudo[32047]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:15:54 volumio volumio[31678]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 22:15:54 volumio sudo[32047]: pam_unix(sudo:session): session closed for user root Jan 28 22:15:54 volumio volumio[31678]: info: Initializing connection to go-librespot Websocket Jan 28 22:15:54 volumio volumio[31678]: error: Cannot start Volumio Streaming Daemon Jan 28 22:15:54 volumio volumio[31678]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 22:15:54 volumio volumio[31678]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 22:15:54 volumio go-librespot[32039]: time="2026-01-28T22:15:54+07:00" level=debug msg="new websocket client" Jan 28 22:15:54 volumio volumio[31678]: info: Connection to go-librespot Websocket established Jan 28 22:15:54 volumio go-librespot[32039]: time="2026-01-28T22:15:54+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 22:15:54 volumio go-librespot[32039]: time="2026-01-28T22:15:54+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 22:15:54 volumio go-librespot[32039]: time="2026-01-28T22:15:54+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 22:15:54 volumio go-librespot[32039]: time="2026-01-28T22:15:54+07:00" level=info msg="zeroconf server listening on port 46501" Jan 28 22:15:54 volumio go-librespot[32039]: time="2026-01-28T22:15:54+07:00" level=debug msg="obtained new client token: AAAivZFIncnz82duO1tne8VOmwXZFd+oIHKXHsEgx7wknicgQhAayhCVMqKO95ZhuxRtup9tW5gI4YQYbC2Cc3a9WEB47P1b4Rcd/oQR0+jTpF92XW/coeqbQhfSaQsc0pAD+C348QkkpUkAO/MXz35YmBEB0HciDuDdIrZEHiVq5dADdck71D+5KJbLVgK1qDHszsOR9xQY+R/7QreW3nBEfd0WUv9KaxcZ6jLTKhBJ19fyo0Oz/4IMhKg=" Jan 28 22:15:54 volumio go-librespot[32039]: time="2026-01-28T22:15:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:15:54 volumio go-librespot[32039]: time="2026-01-28T22:15:54+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 22:15:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:15:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:15:54 volumio volumio[31678]: info: Connection to go-librespot Websocket closed Jan 28 22:15:55 volumio volumio[31678]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 28 22:15:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:15:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:15:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:15:56 volumio volumio[31678]: info: MyVolumio token set successfully Jan 28 22:15:56 volumio volumio[31678]: info: MYVOLUMIO: Adding device Jan 28 22:15:56 volumio volumio[31678]: info: MYVOLUMIO: Evaluating Server Jan 28 22:15:56 volumio volumio[31678]: info: MyVolumio status changed Jan 28 22:15:56 volumio volumio[31678]: info: Streaming services startup Jan 28 22:15:56 volumio volumio[31678]: info: Starting Streaming Daemon Jan 28 22:15:56 volumio volumio[31678]: info: Removing browser output: myVolumio user plan is not superstar Jan 28 22:15:56 volumio volumio[31678]: info: Removing audio output: Jan 28 22:15:56 volumio volumio[31678]: info: Stoppping Tunnel 1 Jan 28 22:15:56 volumio sudo[32074]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 22:15:56 volumio sudo[32074]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:15:56 volumio sudo[32074]: pam_unix(sudo:session): session closed for user root Jan 28 22:15:56 volumio sudo[32077]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 28 22:15:56 volumio sudo[32077]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:15:56 volumio volumio[31678]: error: Cannot start Volumio Streaming Daemon Jan 28 22:15:56 volumio volumio[31678]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 22:15:56 volumio volumio[31678]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 22:15:56 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 28 22:15:56 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 28 22:15:56 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 28 22:15:56 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 28 22:15:56 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 28 22:15:56 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 28 22:15:56 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 28 22:15:56 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 28 22:15:57 volumio sudo[32077]: pam_unix(sudo:session): session closed for user root Jan 28 22:15:57 volumio volumio[31678]: info: Remote SSH Stopped Jan 28 22:15:57 volumio volumio[31678]: info: Getting Spotify volume Jan 28 22:15:57 volumio volumio[31678]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 22:15:57 volumio volumio[31678]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 22:15:57 volumio volumio[31678]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 28 22:15:57 volumio volumio[31678]: errno: -111, Jan 28 22:15:57 volumio volumio[31678]: code: 'ECONNREFUSED', Jan 28 22:15:57 volumio volumio[31678]: syscall: 'connect', Jan 28 22:15:57 volumio volumio[31678]: address: '127.0.0.1', Jan 28 22:15:57 volumio volumio[31678]: port: 9879, Jan 28 22:15:57 volumio volumio[31678]: response: undefined Jan 28 22:15:57 volumio volumio[31678]: } Jan 28 22:15:57 volumio volumio[31678]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 22:15:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:15:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:15:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:15:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Jan 28 22:15:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:15:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:15:58 volumio go-librespot[32091]: go-librespot daemon starting... Jan 28 22:15:58 volumio go-librespot[32092]: time="2026-01-28T22:15:58+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:15:58 volumio go-librespot[32092]: time="2026-01-28T22:15:58+07:00" level=debug msg="app state loaded" Jan 28 22:15:58 volumio go-librespot[32092]: time="2026-01-28T22:15:58+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:15:58 volumio go-librespot[32092]: time="2026-01-28T22:15:58+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 22:15:58 volumio go-librespot[32092]: time="2026-01-28T22:15:58+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 28 22:15:58 volumio go-librespot[32092]: time="2026-01-28T22:15:58+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 28 22:15:58 volumio go-librespot[32092]: time="2026-01-28T22:15:58+07:00" level=info msg="zeroconf server listening on port 37807" Jan 28 22:15:58 volumio go-librespot[32092]: time="2026-01-28T22:15:58+07:00" level=debug msg="obtained new client token: AADprwgSVZnMnShpBUkJHCMMU+LZ49SLhG5ktney5JHNDOc7gzbsxAefc9mbT4pUqyEteoM3XHWsjBJs4sQVg8LZc/5nDai5CeRDGsMjs+1QmpDtt5d7JRN+jgpf3qWHHB4Nwll0hXwy2lWbc/UEO8LOHZbU7F4Ifq7xhf0e8uLvkzAqxsQhBoMX6MpHVGjtF/9+RRq9QqtjObU2uOYXtF54K2H2xDwMw+LpWuecRu3T5L73/UaFlYN1QNc=" Jan 28 22:15:58 volumio sudo[32101]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 22:14' Jan 28 22:15:58 volumio sudo[32101]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:15:58 volumio go-librespot[32092]: time="2026-01-28T22:15:58+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:15:59 volumio go-librespot[32092]: time="2026-01-28T22:15:59+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 28 22:15:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:15:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:15:59 volumio sudo[32101]: pam_unix(sudo:session): session closed for user root Jan 28 22:15:59 volumio volumio-remote-updater[628]: [2026-01-28 22:15:59] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 28 22:15:59 volumio volumio-remote-updater[628]: [2026-01-28 22:15:59] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 28 22:15:59 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:15:59 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 22:15:59 volumio systemd[1]: volumio.service: Consumed 1min 2.965s CPU time. Jan 28 22:15:59 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 22:15:59 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 22:15:59 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10760. Jan 28 22:15:59 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 22:15:59 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 22:15:59 volumio systemd[1]: volumio.service: Consumed 1min 2.965s CPU time. Jan 28 22:15:59 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 22:15:59 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 22:15:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:15:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:15:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:16:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:16:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:16:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:16:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Jan 28 22:16:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:16:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:16:02 volumio go-librespot[32129]: go-librespot daemon starting... Jan 28 22:16:02 volumio go-librespot[32130]: time="2026-01-28T22:16:02+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:16:02 volumio go-librespot[32130]: time="2026-01-28T22:16:02+07:00" level=debug msg="app state loaded" Jan 28 22:16:02 volumio go-librespot[32130]: time="2026-01-28T22:16:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:16:02 volumio go-librespot[32130]: time="2026-01-28T22:16:02+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 28 22:16:02 volumio go-librespot[32130]: time="2026-01-28T22:16:02+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 28 22:16:02 volumio go-librespot[32130]: time="2026-01-28T22:16:02+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 28 22:16:02 volumio go-librespot[32130]: time="2026-01-28T22:16:02+07:00" level=info msg="zeroconf server listening on port 38025" Jan 28 22:16:03 volumio go-librespot[32130]: time="2026-01-28T22:16:03+07:00" level=debug msg="obtained new client token: AADKMXJQYcvOhLQXgyvV2/0ChyMr5n3bwwjy/Xa1peNtLNkoDloiwkT2/uM/ZpMWjEzFMfrtg9u5moyr5iFg/RXszk2rCMxOxFCby93rkcF/7d6hIRuwD6UQxivVdEWkX2l2DwWZLk+Qz9sTUYTAv1skn3ckiGUJlqp/nZdGNbkQ27Hm4K5g7bq4GmB8rNqddRBqIZahx8PUC0E42hgF9ObWnt0+v2VGnO4w6Gya8fhThVlKfJP6UE8q" Jan 28 22:16:03 volumio go-librespot[32130]: time="2026-01-28T22:16:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:16:03 volumio volumio[32114]: info: ------------------------------------------- Jan 28 22:16:03 volumio volumio[32114]: info: ----- Volumio3 ---- Jan 28 22:16:03 volumio volumio[32114]: info: ------------------------------------------- Jan 28 22:16:03 volumio volumio[32114]: info: ----- System startup ---- Jan 28 22:16:03 volumio volumio[32114]: info: ------------------------------------------- Jan 28 22:16:03 volumio go-librespot[32130]: time="2026-01-28T22:16:03+07:00" level=debug msg="completed keyexchange" Jan 28 22:16:03 volumio go-librespot[32130]: time="2026-01-28T22:16:03+07:00" level=debug msg="completed challenge" Jan 28 22:16:03 volumio go-librespot[32130]: time="2026-01-28T22:16: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 28 22:16:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:16:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:16:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:16:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:16:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:16:04 volumio volumio-remote-updater[628]: [2026-01-28 22:16:04] [connect] Successful connection Jan 28 22:16:04 volumio volumio[32114]: info: MYVOLUMIO Environment detected Jan 28 22:16:04 volumio volumio[32114]: info: Plugin folders cleanup Jan 28 22:16:04 volumio volumio[32114]: info: Scanning into folder /volumio/app/plugins/ Jan 28 22:16:04 volumio volumio[32114]: info: Scanning category audio_interface Jan 28 22:16:04 volumio volumio[32114]: info: Scanning category miscellanea Jan 28 22:16:04 volumio volumio[32114]: info: Scanning category music_service Jan 28 22:16:04 volumio volumio[32114]: info: Scanning category plugins.json Jan 28 22:16:04 volumio volumio[32114]: info: Scanning category system_controller Jan 28 22:16:04 volumio volumio[32114]: info: Scanning category user_interface Jan 28 22:16:04 volumio volumio[32114]: info: Scanning into folder /data/plugins/ Jan 28 22:16:04 volumio volumio[32114]: info: Scanning category music_service Jan 28 22:16:04 volumio volumio[32114]: info: Plugin folders cleanup completed Jan 28 22:16:04 volumio volumio[32114]: info: ------------------------------------------- Jan 28 22:16:04 volumio volumio[32114]: info: ----- Core plugins startup ---- Jan 28 22:16:04 volumio volumio[32114]: info: ------------------------------------------- Jan 28 22:16:04 volumio volumio[32114]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 22:16:04 volumio volumio[32114]: info: Adding plugin upnp to MyMusic Plugins Jan 28 22:16:04 volumio volumio[32114]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 22:16:04 volumio volumio[32114]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 22:16:04 volumio volumio[32114]: info: Loading plugins from folder /data/plugins/ Jan 28 22:16:04 volumio volumio[32114]: info: Loading plugin "system"... Jan 28 22:16:04 volumio volumio[32114]: info: Loading plugin "appearance"... Jan 28 22:16:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:16:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:16:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:16:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Jan 28 22:16:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:16:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:16:06 volumio go-librespot[32150]: go-librespot daemon starting... Jan 28 22:16:06 volumio go-librespot[32151]: time="2026-01-28T22:16:06+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:16:06 volumio go-librespot[32151]: time="2026-01-28T22:16:06+07:00" level=debug msg="app state loaded" Jan 28 22:16:06 volumio go-librespot[32151]: time="2026-01-28T22:16:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:16:06 volumio volumio[32114]: info: Loading plugin "network"... Jan 28 22:16:06 volumio volumio[32114]: info: Refreshing Cached IP Addresses Jan 28 22:16:06 volumio sudo[32158]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 22:16:06 volumio sudo[32158]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:16:06 volumio sudo[32158]: pam_unix(sudo:session): session closed for user root Jan 28 22:16:06 volumio sudo[32160]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 22:16:06 volumio sudo[32160]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:16:06 volumio volumio[32114]: info: Loading plugin "services"... Jan 28 22:16:06 volumio sudo[32160]: pam_unix(sudo:session): session closed for user root Jan 28 22:16:06 volumio volumio[32114]: info: Loading plugin "alsa_controller"... Jan 28 22:16:06 volumio sudo[32168]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 22:16:06 volumio sudo[32168]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:16:07 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 22:16:07 volumio volumio[32114]: info: Loading plugin "wizard"... Jan 28 22:16:07 volumio volumio[32114]: info: Loading plugin "networkfs"... Jan 28 22:16:07 volumio volumio[32114]: info: Starting Udev Watcher for removable devices Jan 28 22:16:07 volumio go-librespot[32151]: time="2026-01-28T22:16: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-gew1.spotify.com:80]" Jan 28 22:16:07 volumio go-librespot[32151]: time="2026-01-28T22:16:07+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 28 22:16:07 volumio go-librespot[32151]: time="2026-01-28T22:16:07+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 28 22:16:07 volumio volumio[32114]: info: Ignoring mount for partition: boot Jan 28 22:16:07 volumio volumio[32114]: info: Ignoring mount for partition: volumio Jan 28 22:16:07 volumio volumio[32114]: info: Ignoring mount for partition: volumio_data Jan 28 22:16:07 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 22:16:07 volumio volumio[32114]: info: Loading plugin "volumio_command_line_client"... Jan 28 22:16:07 volumio go-librespot[32151]: time="2026-01-28T22:16:07+07:00" level=info msg="zeroconf server listening on port 35635" Jan 28 22:16:07 volumio volumio[32114]: info: Loading plugin "upnp"... Jan 28 22:16:07 volumio volumio[32114]: info: [1769613367259] Starting Upmpd Daemon Jan 28 22:16:07 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 22:16:07 volumio volumio[32114]: info: Loading plugin "my_music"... Jan 28 22:16:07 volumio volumio[32114]: info: Loading plugin "mpd"... Jan 28 22:16:07 volumio go-librespot[32151]: time="2026-01-28T22:16:07+07:00" level=debug msg="obtained new client token: AAC+znycohXEOCwOqqMh/Wcz5wazDJJ3DTWD2pE1KsajiJ/nfoN03035ILP2wEYdZvmFA7CpHbJhc9kXqhaieLcn43KBaQuFV/2xE9R0fH3wdp99o90DDNZIA6NRw8vg0QpvQRWSVclO5eMKqlDiIwrfHm70k3KJMNF6Q4w5pcF5+xxZickn48Dl+ZUEbVFGWYOQi3Hha+QgkugfYkZt27+0X1bGWUjYYy8BcCEgvJ8Fl8WM0zUtwATx2pE=" Jan 28 22:16:07 volumio go-librespot[32151]: time="2026-01-28T22:16:07+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 28 22:16:07 volumio go-librespot[32151]: time="2026-01-28T22:16:07+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Jan 28 22:16:07 volumio go-librespot[32151]: time="2026-01-28T22:16:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Jan 28 22:16:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:16:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:16:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:16:07 volumio go-librespot[32151]: time="2026-01-28T22:16:07+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 28 22:16:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:16:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:16:07 volumio volumio[32114]: info: Loading plugin "upnp_browser"... Jan 28 22:16:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:16:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:16:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:16:09 volumio sudo[32168]: pam_unix(sudo:session): session closed for user root Jan 28 22:16:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Jan 28 22:16:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:16:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:16:10 volumio go-librespot[32193]: go-librespot daemon starting... Jan 28 22:16:10 volumio volumio[32114]: info: Starting UPNP Browser Jan 28 22:16:10 volumio volumio[32114]: info: Loading plugin "alarm-clock"... Jan 28 22:16:10 volumio go-librespot[32194]: time="2026-01-28T22:16:10+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:16:10 volumio go-librespot[32194]: time="2026-01-28T22:16:10+07:00" level=debug msg="app state loaded" Jan 28 22:16:10 volumio go-librespot[32194]: time="2026-01-28T22:16:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:16:11 volumio volumio[32114]: info: Loading plugin "airplay_emulation"... Jan 28 22:16:11 volumio volumio[32114]: info: Starting Shairport Sync Jan 28 22:16:11 volumio volumio[32114]: info: Loading plugin "last_100"... Jan 28 22:16:11 volumio volumio[32114]: info: Loading plugin "webradio"... Jan 28 22:16:11 volumio volumio[32114]: info: Loading plugin "i2s_dacs"... Jan 28 22:16:11 volumio go-librespot[32194]: time="2026-01-28T22:16:11+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 28 22:16:11 volumio go-librespot[32194]: time="2026-01-28T22:16:11+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 28 22:16:11 volumio go-librespot[32194]: time="2026-01-28T22:16:11+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 28 22:16:11 volumio volumio[32114]: info: Loading plugin "volumiodiscovery"... Jan 28 22:16:11 volumio go-librespot[32194]: time="2026-01-28T22:16:11+07:00" level=info msg="zeroconf server listening on port 45029" Jan 28 22:16:11 volumio volumio[32114]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 22:16:11 volumio volumio[32114]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 22:16:11 volumio volumio[32114]: *** WARNING *** For more information see Jan 28 22:16:11 volumio volumio[32114]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 22:16:11 volumio volumio[32114]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 22:16:11 volumio volumio[32114]: *** WARNING *** For more information see Jan 28 22:16:11 volumio node[32114]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 22:16:11 volumio node[32114]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 22:16:11 volumio node[32114]: *** WARNING *** For more information see Jan 28 22:16:11 volumio node[32114]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 22:16:11 volumio node[32114]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 22:16:11 volumio node[32114]: *** WARNING *** For more information see Jan 28 22:16:11 volumio volumio[32114]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 22:16:11 volumio volumio[32114]: info: Discovery: Started advertising with name: Volumio Jan 28 22:16:11 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 22:16:11 volumio volumio[32114]: info: Loading plugin "spop"... Jan 28 22:16:11 volumio go-librespot[32194]: time="2026-01-28T22:16:11+07:00" level=debug msg="obtained new client token: AAAKVds4GvxsDaYRPnQc9y7CM4pr66t9YgYJs00IMnV1Q2P+th9AmiVMf5ZTvr7So0y+MRRcmex4Up9+3Tsqd7i9E9rHnqtTiuyMo0/785YhhGr2PNHF2fstVkJMUxhjVwp3KHGdvOk8ypuLZOrMaXo/CjgthMbQpdd3TKm4tJ/4cr5Vf3F3Red8NV5bmpRf2PhLoyPeL7myRny2eJnY0C3cIcFOhewU6hZCQ1woPRk+hb05RnwZsXWlCSY=" Jan 28 22:16:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:16:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:16:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:16:11 volumio go-librespot[32194]: time="2026-01-28T22:16:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:16:11 volumio go-librespot[32194]: time="2026-01-28T22:16:11+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 28 22:16:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:16:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:16:13 volumio volumio[32114]: info: Loading plugin "ytcr"... Jan 28 22:16:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:16:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:16:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:16:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Jan 28 22:16:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:16:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:16:15 volumio go-librespot[32204]: go-librespot daemon starting... Jan 28 22:16:15 volumio go-librespot[32205]: time="2026-01-28T22:16:15+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:16:15 volumio go-librespot[32205]: time="2026-01-28T22:16:15+07:00" level=debug msg="app state loaded" Jan 28 22:16:15 volumio go-librespot[32205]: time="2026-01-28T22:16:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:16:15 volumio go-librespot[32205]: time="2026-01-28T22:16:15+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 28 22:16:15 volumio go-librespot[32205]: time="2026-01-28T22:16:15+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 28 22:16:15 volumio go-librespot[32205]: time="2026-01-28T22:16:15+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 28 22:16:15 volumio go-librespot[32205]: time="2026-01-28T22:16:15+07:00" level=info msg="zeroconf server listening on port 44147" Jan 28 22:16:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:16:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:16:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:16:15 volumio go-librespot[32205]: time="2026-01-28T22:16:15+07:00" level=debug msg="obtained new client token: AAAPtmLb9zy09eoVbNX0QBIzNSuD89Xfah2LIjNtHuktW3YrXOUedLH4c1zbTIep4e62+GignBW9BF6a1AFa94ns2FgB61hEQMKjljstxpnAK4IoZIExy//yRI0PMZ9aJyRrJwDVxU4BOcQ/YuTm0bqfusBdY4SO9ojk5mWcesA0wNzw8UH2GainHJw7u1mkJ69fVv1i+70CJtUtKt18sVQM6LrGsyJLTccuTzCLS3Ma26m+l9lrjN1EljM=" Jan 28 22:16:15 volumio go-librespot[32205]: time="2026-01-28T22:16:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:16:16 volumio go-librespot[32205]: time="2026-01-28T22:16:16+07:00" level=debug msg="completed keyexchange" Jan 28 22:16:16 volumio go-librespot[32205]: time="2026-01-28T22:16:16+07:00" level=debug msg="completed challenge" Jan 28 22:16:16 volumio volumio[32114]: info: Loading plugin "ytmusic"... Jan 28 22:16:16 volumio go-librespot[32205]: time="2026-01-28T22:16:16+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 28 22:16:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:16:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:16:16 volumio volumio-remote-updater[628]: [2026-01-28 22:16:16] [connect] Successful connection Jan 28 22:16:17 volumio volumio[32114]: info: Loading plugin "outputs"... Jan 28 22:16:17 volumio volumio[32114]: info: Loading plugin "albumart"... Jan 28 22:16:17 volumio volumio[32114]: info: Plugin example_plugin is not enabled Jan 28 22:16:17 volumio volumio[32114]: info: Loading plugin "inputs"... Jan 28 22:16:17 volumio volumio[32114]: info: Loading plugin "updater_comm"... Jan 28 22:16:17 volumio volumio[32114]: info: Plugin mpdemulation is not enabled Jan 28 22:16:17 volumio volumio[32114]: info: Loading plugin "rest_api"... Jan 28 22:16:17 volumio volumio[32114]: info: Loading plugin "websocket"... Jan 28 22:16:17 volumio volumio[32114]: info: Starting Socket.io Server version 1.7.4 Jan 28 22:16:17 volumio volumio[32114]: info: Loading plugin "RoonBridge"... Jan 28 22:16:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:16:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:16:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:16:17 volumio volumio[32114]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 22:16:17 volumio volumio[32114]: info: Loading i18n strings for locale en Jan 28 22:16:18 volumio volumio[32114]: Updating browse sources language Jan 28 22:16:18 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 22:16:18 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 22:16:18 volumio volumio[32114]: info: CoreCommandRouter::initPlayerControls Jan 28 22:16:18 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:16:18 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:16:18 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:16:18 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:16:18 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:16:18 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:16:18 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:16:18 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:16:18 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 22:16:18 volumio volumio[32114]: Express server listening on port 3000 Jan 28 22:16:18 volumio volumio[32114]: [Metrics] WebUI: 16s 14.08ms Jan 28 22:16:18 volumio volumio[32114]: info: CoreStateMachine::resetVolumioState Jan 28 22:16:18 volumio volumio[32114]: info: CoreStateMachine::getcurrentVolume Jan 28 22:16:18 volumio volumio[32114]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 22:16:18 volumio volumio[32226]: Forking 3 albumart workers Jan 28 22:16:18 volumio sudo[32243]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 22:16:18 volumio sudo[32246]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 22:16:18 volumio sudo[32246]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:16:18 volumio sudo[32243]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:16:18 volumio sudo[32243]: pam_unix(sudo:session): session closed for user root Jan 28 22:16:18 volumio sudo[32246]: pam_unix(sudo:session): session closed for user root Jan 28 22:16:18 volumio volumio[32114]: info: Volumio Network Manager: Network status updated: 1 Jan 28 22:16:18 volumio volumio[32114]: info: VolumeController:: Volume=100 Mute =false Jan 28 22:16:18 volumio volumio[32114]: info: CoreStateMachine::pushState Jan 28 22:16:18 volumio volumio[32114]: info: CorePlayQueue::getTrack 0 Jan 28 22:16:18 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 22:16:18 volumio volumio[32114]: info: CoreCommandRouter::volumioPushState Jan 28 22:16:18 volumio volumio[32114]: info: CoreStateMachine::updateTrackBlock Jan 28 22:16:18 volumio volumio[32114]: info: CorePlayQueue::getTrackBlock Jan 28 22:16:18 volumio volumio[32114]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 22:16:18 volumio volumio-remote-updater[628]: [2026-01-28 22:16:18] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769613376 101 Jan 28 22:16:18 volumio volumio[32114]: 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 28 22:16:19 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:16:19 volumio volumio[32114]: info: Reloading queue from file Jan 28 22:16:19 volumio volumio[32114]: info: CoreStateMachine::setRepeat null single undefined Jan 28 22:16:19 volumio volumio[32114]: info: CoreStateMachine::pushState Jan 28 22:16:19 volumio volumio[32114]: info: CorePlayQueue::getTrack 0 Jan 28 22:16:19 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 22:16:19 volumio volumio[32114]: info: CoreCommandRouter::volumioPushState Jan 28 22:16:19 volumio volumio[32114]: info: CoreStateMachine::setRandom null Jan 28 22:16:19 volumio volumio[32114]: info: CoreStateMachine::pushState Jan 28 22:16:19 volumio volumio[32114]: info: CorePlayQueue::getTrack 0 Jan 28 22:16:19 volumio volumio[32114]: info: CoreCommandRouter::volumioPushState Jan 28 22:16:19 volumio volumio[32114]: info: Setting Device type: Raspberry PI Jan 28 22:16:19 volumio volumio[32114]: info: Completed loading Core Plugins Jan 28 22:16:19 volumio volumio[32114]: info: Preparing to generate the ALSA configuration file Jan 28 22:16:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Jan 28 22:16:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:16:19 volumio volumio[32114]: info: VolumeController:: Volume=100 Mute =false Jan 28 22:16:19 volumio volumio[32114]: info: CoreStateMachine::pushState Jan 28 22:16:19 volumio volumio[32114]: info: CorePlayQueue::getTrack 0 Jan 28 22:16:19 volumio volumio[32114]: info: CoreCommandRouter::volumioPushState Jan 28 22:16:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:16:19 volumio go-librespot[32286]: go-librespot daemon starting... Jan 28 22:16:19 volumio volumio[32114]: info: Asound.conf file unchanged, so no further update is needed Jan 28 22:16:19 volumio volumio[32114]: info: Output device has changed, restarting MPD Jan 28 22:16:19 volumio sudo[32288]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 22:16:19 volumio go-librespot[32289]: time="2026-01-28T22:16:19+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:16:19 volumio go-librespot[32289]: time="2026-01-28T22:16:19+07:00" level=debug msg="app state loaded" Jan 28 22:16:19 volumio go-librespot[32289]: time="2026-01-28T22:16:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:16:19 volumio sudo[32288]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:16:19 volumio volumio[32114]: info: Output device has changed, restarting Shairport Sync Jan 28 22:16:19 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:16:19 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:16:19 volumio sudo[32297]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 22:16:19 volumio sudo[32297]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:16:19 volumio sudo[32297]: pam_unix(sudo:session): session closed for user root Jan 28 22:16:19 volumio volumio[32114]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 22:16:19 volumio volumio[32114]: info: ___________ START PLUGINS ___________ Jan 28 22:16:19 volumio sudo[32288]: pam_unix(sudo:session): session closed for user root Jan 28 22:16:19 volumio sudo[32300]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 22:16:19 volumio sudo[32300]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:16:19 volumio volumio[32114]: info: ControllerMpd::onStart: Initializing MPD Jan 28 22:16:19 volumio volumio[32114]: info: Creating MPD Configuration file Jan 28 22:16:19 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 22:16:19 volumio volumio[32114]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 22:16:19 volumio volumio[32114]: info: [1769613379708] CoreMusicLibrary::Adding element Media Servers Jan 28 22:16:19 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 22:16:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:16:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:16:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:16:19 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 22:16:19 volumio sudo[32309]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 22:16:19 volumio sudo[32309]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:16:19 volumio sudo[32309]: pam_unix(sudo:session): session closed for user root Jan 28 22:16:19 volumio volumio[32114]: info: UPNP Browser: Client initialized successfully Jan 28 22:16:19 volumio sudo[32311]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 22:16:19 volumio sudo[32311]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:16:19 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 22:16:19 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 22:16:19 volumio systemd[1]: mpd.service: Consumed 7.288s CPU time. Jan 28 22:16:19 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 22:16:19 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 22:16:19 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 22:16:19 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:16:19 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:16:20 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 22:16:20 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 22:16:20 volumio volumio[32114]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 22:16:20 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:16:20 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:16:20 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 22:16:20 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 22:16:20 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 22:16:20 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 22:16:20 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 22:16:20 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 22:16:20 volumio go-librespot[32289]: time="2026-01-28T22:16:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 22:16:20 volumio go-librespot[32289]: time="2026-01-28T22:16:20+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 28 22:16:20 volumio go-librespot[32289]: time="2026-01-28T22:16:20+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 28 22:16:20 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 22:16:20 volumio go-librespot[32289]: time="2026-01-28T22:16:20+07:00" level=info msg="zeroconf server listening on port 43297" Jan 28 22:16:20 volumio volumio[32114]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 22:16:20 volumio volumio[32114]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 22:16:20 volumio volumio[32114]: info: [1769613380235] CoreMusicLibrary::Adding element Last_100 Jan 28 22:16:20 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 22:16:20 volumio volumio[32114]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 22:16:20 volumio volumio[32114]: info: [1769613380269] CoreMusicLibrary::Adding element Webradio Jan 28 22:16:20 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 22:16:20 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 22:16:20 volumio volumio[32114]: info: Initializing BBC Radios Jan 28 22:16:20 volumio go-librespot[32289]: time="2026-01-28T22:16:20+07:00" level=debug msg="obtained new client token: AAAT4oFdME4dU0RWJHV5SQ/GA0qamRAt9PUeocvk+VDjO/QUOkZYiAXMB/KpCO4zMPhamXc+NN+n7L2Mlrj8W6y/QhvVdr0mPBMHBZtOiyrbSFmZM5IHJLiJcr6TkJYrhYjsH/dnCSjJ+OhFEa/PggXgE3KpiB1UPBekAQh966/mI17ugtdTKFlNbwokYEEYQ9t3OzgraMsj/j2h4x7DAgvZxivkZNwOaDK6yr990aAtWh8iFqzuNv1WZtc=" Jan 28 22:16:20 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 22:16:20 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:16:20 volumio go-librespot[32289]: time="2026-01-28T22:16:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:16:20 volumio volumio[32114]: info: Creating Spotify config file Jan 28 22:16:20 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:16:20 volumio go-librespot[32289]: time="2026-01-28T22:16: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 28 22:16:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:16:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:16:20 volumio sudo[32325]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 22:16:20 volumio sudo[32325]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 22:16:20 volumio sudo[32325]: pam_unix(sudo:session): session closed for user root Jan 28 22:16:21 volumio volumio[32240]: Starting albumart workers Jan 28 22:16:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:16:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:16:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:16:21 volumio volumio[32244]: Starting albumart workers Jan 28 22:16:21 volumio volumio[32242]: Starting albumart workers Jan 28 22:16:22 volumio volumio[32114]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 22:16:22 volumio volumio[32114]: info: [1769613382304] CoreMusicLibrary::Adding element YouTube Music Jan 28 22:16:22 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 22:16:22 volumio volumio[32114]: Cannot find translation for source YouTube Music Jan 28 22:16:22 volumio volumio[32114]: info: Volumio Calling Home Jan 28 22:16:22 volumio sudo[32342]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 22:16:22 volumio sudo[32342]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:16:22 volumio sudo[32342]: pam_unix(sudo:session): session closed for user root Jan 28 22:16:23 volumio volumio[32114]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 22:16:23 volumio volumio[32114]: info: Discovery: Found device Volumio Jan 28 22:16:23 volumio volumio[32114]: info: CoreCommandRouter::volumioGetState Jan 28 22:16:23 volumio volumio[32114]: info: CorePlayQueue::getTrack 0 Jan 28 22:16:23 volumio volumio[32114]: info: MPD Permissions set Jan 28 22:16:23 volumio volumio[32114]: info: MPD Permissions set Jan 28 22:16:23 volumio volumio[32114]: info: Upmpdcli Daemon Started Jan 28 22:16:23 volumio volumio[32114]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 22:16:23 volumio volumio[32114]: info: Discovery: Found device Volumio Jan 28 22:16:23 volumio volumio[32114]: info: CoreCommandRouter::volumioGetState Jan 28 22:16:23 volumio volumio[32114]: info: CorePlayQueue::getTrack 0 Jan 28 22:16:23 volumio volumio[32114]: info: Spotify config file written Jan 28 22:16:23 volumio volumio[32114]: 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 28 22:16:23 volumio volumio[32114]: info: Volumio called home Jan 28 22:16:23 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:16:23 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:16:23 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:16:23 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:16:23 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:16:23 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:16:23 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:16:23 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:16:23 volumio sudo[32348]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 22:16:23 volumio sudo[32348]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:16:23 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:16:23 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:16:23 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:16:23 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:16:23 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:16:23 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:16:23 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:16:23 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:16:23 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:16:23 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:16:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:16:23 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:16:23 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:16:23 volumio volumio[32114]: info: No need to fix Spotify hosts Jan 28 22:16:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:16:23 volumio sudo[32348]: pam_unix(sudo:session): session closed for user root Jan 28 22:16:23 volumio go-librespot[32362]: go-librespot daemon starting... Jan 28 22:16:23 volumio go-librespot[32370]: time="2026-01-28T22:16:23+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:16:23 volumio go-librespot[32370]: time="2026-01-28T22:16:23+07:00" level=debug msg="app state loaded" Jan 28 22:16:23 volumio go-librespot[32370]: time="2026-01-28T22:16:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:16:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:16:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:16:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:16:24 volumio go-librespot[32370]: time="2026-01-28T22:16: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 28 22:16:24 volumio go-librespot[32370]: time="2026-01-28T22:16: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 28 22:16:24 volumio go-librespot[32370]: time="2026-01-28T22:16: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 28 22:16:24 volumio go-librespot[32370]: time="2026-01-28T22:16:24+07:00" level=info msg="zeroconf server listening on port 34237" Jan 28 22:16:24 volumio go-librespot[32370]: time="2026-01-28T22:16:24+07:00" level=debug msg="obtained new client token: AAA5ARW8E3Lna/aFRh/sRWMURGxU+ssb7GIHbM3bqV6vKKLoHt5LLOObaC+EFHR14JtYy5NfBJ7IWzNmZiovbWY0F48BHigmepeqSWTpPnZ2uKLzkkTPRcfGzTD/QtU7Nw9oTlCnzpKupNCcX78MY4jA5Sivn1WGuiXAfjLu622qG4inBKJ8quOSlDZCg1lAEi3IrebM2demQWAWoXowTm4RZWEYTL84dBzNUcTTTQCMcahyULkTLz6OU8Q=" Jan 28 22:16:24 volumio volumio[32114]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 22:16:24 volumio volumio[32114]: SPOTIFY: BQCnIQoJEPSTxMxcaAVRgA5vxw7lFak5MNnkcjS3mYDo2yyBqXjcnRXPqogemJ1TjJZ8F3_5DiEWs5DMarXWDQXMHwGn4C_Q9TE4CB4A1IzrV-CvCfyTuTatQAk5jCAqG1XkcXeUJYTAsjL7vXsatD2Xl9e2Ohrd8I_OnGkH45PsfqLZa4TQ6-QlL3Ga-lYam8F-jpYQnP5rsmfKe8h7FymHNzaqFH6keSQ3dej5piTfiByPXLVY_5lliDZNXCxPaFQfLtqlCZep0O0_tc33wu627w4FOHhNmahEgPxPDZq46h_lmGAhypAW Jan 28 22:16:24 volumio volumio[32114]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 22:16:24 volumio volumio[32114]: info: New Spotify access token = BQCnIQoJEPSTxMxcaAVRgA5vxw7lFak5MNnkcjS3mYDo2yyBqXjcnRXPqogemJ1TjJZ8F3_5DiEWs5DMarXWDQXMHwGn4C_Q9TE4CB4A1IzrV-CvCfyTuTatQAk5jCAqG1XkcXeUJYTAsjL7vXsatD2Xl9e2Ohrd8I_OnGkH45PsfqLZa4TQ6-QlL3Ga-lYam8F-jpYQnP5rsmfKe8h7FymHNzaqFH6keSQ3dej5piTfiByPXLVY_5lliDZNXCxPaFQfLtqlCZep0O0_tc33wu627w4FOHhNmahEgPxPDZq46h_lmGAhypAW Jan 28 22:16:24 volumio volumio[32114]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 22:16:24 volumio volumio[32114]: info: Starting Shairport Sync Jan 28 22:16:24 volumio volumio[32114]: info: Starting Shairport Sync Jan 28 22:16:24 volumio volumio[32114]: info: Starting Shairport Sync Jan 28 22:16:24 volumio go-librespot[32370]: time="2026-01-28T22:16:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:16:24 volumio sudo[32388]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 22:16:24 volumio sudo[32388]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:16:24 volumio go-librespot[32370]: time="2026-01-28T22:16:24+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 28 22:16:24 volumio sudo[32392]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 22:16:24 volumio sudo[32392]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:16:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:16:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:16:24 volumio sudo[32390]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 22:16:24 volumio sudo[32390]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:16:24 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 22:16:25 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 22:16:25 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 22:16:25 volumio systemd[1]: shairport-sync.service: Consumed 2.380s CPU time. Jan 28 22:16:25 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 22:16:25 volumio sudo[32392]: pam_unix(sudo:session): session closed for user root Jan 28 22:16:25 volumio sudo[32390]: pam_unix(sudo:session): session closed for user root Jan 28 22:16:25 volumio sudo[32388]: pam_unix(sudo:session): session closed for user root Jan 28 22:16:25 volumio volumio[32114]: info: Shairport-Sync Started Jan 28 22:16:25 volumio volumio[32114]: Error adding Membership: Error: addMembership EINVAL Jan 28 22:16:25 volumio volumio[32114]: info: Shairport-Sync Started Jan 28 22:16:25 volumio volumio[32114]: info: Shairport-Sync Started Jan 28 22:16:25 volumio volumio[32114]: info: CoreCommandRouter::volumioGetState Jan 28 22:16:25 volumio volumio[32114]: info: CorePlayQueue::getTrack 0 Jan 28 22:16:25 volumio volumio[32114]: 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 28 22:16:25 volumio volumio[32114]: info: Spotify Successfully logged in Jan 28 22:16:25 volumio volumio[32114]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 22:16:25 volumio volumio[32114]: info: [1769613385569] CoreMusicLibrary::Adding element Spotify Jan 28 22:16:25 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 22:16:25 volumio volumio[32114]: Cannot find translation for source YouTube Music Jan 28 22:16:25 volumio volumio[32114]: Cannot find translation for source Spotify Jan 28 22:16:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:16:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:16:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:16:26 volumio volumio[32114]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 22:16:26 volumio volumio[32114]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 22:16:26 volumio volumio[32114]: info: VolumeController:: Volume=100 Mute =false Jan 28 22:16:26 volumio volumio[32114]: info: CoreCommandRouter::volumioGetState Jan 28 22:16:26 volumio volumio[32114]: info: CorePlayQueue::getTrack 0 Jan 28 22:16:26 volumio volumio[32114]: info: CoreStateMachine::pushState Jan 28 22:16:26 volumio volumio[32114]: info: CorePlayQueue::getTrack 0 Jan 28 22:16:26 volumio volumio[32114]: info: CoreCommandRouter::volumioPushState Jan 28 22:16:27 volumio volumio[32114]: info: go-librespot daemon successfully initialized Jan 28 22:16:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:16:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:16:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:16:27 volumio mpd[32340]: 2026-01-28T22:16:27 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 22:16:27 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 22:16:27 volumio sudo[32311]: pam_unix(sudo:session): session closed for user root Jan 28 22:16:27 volumio sudo[32300]: pam_unix(sudo:session): session closed for user root Jan 28 22:16:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Jan 28 22:16:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:16:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:16:27 volumio go-librespot[32430]: go-librespot daemon starting... Jan 28 22:16:28 volumio go-librespot[32432]: time="2026-01-28T22:16:28+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:16:28 volumio go-librespot[32432]: time="2026-01-28T22:16:28+07:00" level=debug msg="app state loaded" Jan 28 22:16:28 volumio go-librespot[32432]: time="2026-01-28T22:16:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:16:28 volumio volumio[32114]: error: MPD error: The expression evaluated to a falsy value: Jan 28 22:16:28 volumio volumio[32114]: assert.ok(self.idling) Jan 28 22:16:28 volumio volumio[32114]: error: The expression evaluated to a falsy value: Jan 28 22:16:28 volumio volumio[32114]: assert.ok(self.idling) Jan 28 22:16:28 volumio volumio[32114]: info: MPD running with PID32340 Jan 28 22:16:28 volumio volumio[32114]: ,establishing connection Jan 28 22:16:28 volumio volumio[32114]: error: updateQueue error: null Jan 28 22:16:28 volumio volumio[32114]: info: Completed starting Core Plugins Jan 28 22:16:28 volumio volumio[32114]: info: ------------------------------------------- Jan 28 22:16:28 volumio volumio[32114]: info: ----- MyVolumio plugins startup ---- Jan 28 22:16:28 volumio volumio[32114]: info: ------------------------------------------- Jan 28 22:16:28 volumio volumio[32114]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 22:16:28 volumio volumio[32114]: error: updateQueue error: null Jan 28 22:16:28 volumio go-librespot[32432]: time="2026-01-28T22:16:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 22:16:28 volumio go-librespot[32432]: time="2026-01-28T22:16:28+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 28 22:16:28 volumio go-librespot[32432]: time="2026-01-28T22:16:28+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 28 22:16:28 volumio go-librespot[32432]: time="2026-01-28T22:16:28+07:00" level=info msg="zeroconf server listening on port 36603" Jan 28 22:16:28 volumio go-librespot[32432]: time="2026-01-28T22:16:28+07:00" level=debug msg="obtained new client token: AAAO8//t3it/SAPSj0i1rUmQys6C1rlx89n7W/e0vgp45LWpjKVSGMAw032Rab+aDqLM8XYUDvXHh4rBVFYnKdWs6yWg0WQqxOScoNBlSdlbJCFdDEi6PML5EnBXUXk5JnBni7beHboeAZCxsohIfkVaF+FOodoz6rUFajJVEbYszvUbhg0yxI+tA4WL6DtcUK6MjTxsiLNXd6aULMFy7RVRuj7hXDkuDaJMKXmfQW8u8F9kHtg3NFWpdqk=" Jan 28 22:16:28 volumio go-librespot[32432]: time="2026-01-28T22:16:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:16:29 volumio go-librespot[32432]: time="2026-01-28T22:16:29+07:00" level=debug msg="completed keyexchange" Jan 28 22:16:29 volumio go-librespot[32432]: time="2026-01-28T22:16:29+07:00" level=debug msg="completed challenge" Jan 28 22:16:29 volumio go-librespot[32432]: time="2026-01-28T22:16: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 28 22:16:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:16:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:16:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:16:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:16:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:16:30 volumio volumio[32114]: info: Initializing connection to go-librespot Websocket Jan 28 22:16:30 volumio volumio[32114]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 22:16:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:16:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:16:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:16:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Jan 28 22:16:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:16:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:16:32 volumio go-librespot[32439]: go-librespot daemon starting... Jan 28 22:16:32 volumio go-librespot[32440]: time="2026-01-28T22:16:32+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:16:32 volumio go-librespot[32440]: time="2026-01-28T22:16:32+07:00" level=debug msg="app state loaded" Jan 28 22:16:32 volumio go-librespot[32440]: time="2026-01-28T22:16:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:16:32 volumio go-librespot[32440]: time="2026-01-28T22:16:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 22:16:32 volumio go-librespot[32440]: time="2026-01-28T22:16:32+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 28 22:16:32 volumio go-librespot[32440]: time="2026-01-28T22:16:32+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 28 22:16:32 volumio go-librespot[32440]: time="2026-01-28T22:16:32+07:00" level=info msg="zeroconf server listening on port 41535" Jan 28 22:16:32 volumio volumio[32114]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 22:16:33 volumio go-librespot[32440]: time="2026-01-28T22:16:33+07:00" level=debug msg="obtained new client token: AABqaS1XotgpLp+wQOYRvTLpkdrVojnrpAJJRyyAVzvJksDD3Q8wEiwTTKANlH7WHYIF9B+YF1PMOD4bYWktIF93lae596TpgOP3H+D4qeSJY0WJo87EGtVpjfNfOGjFBcx8DzAzpEy37X+wkYgGYto3cRIvbvuOXfYyTEhKnFtz8E8hPc3P5sx+W/5skG1WbbBlBHyrNFHTNqkE8qHYNkyWnrYju+sNRb+r4KE+uepwYFGO1rsIfw==" Jan 28 22:16:33 volumio go-librespot[32440]: time="2026-01-28T22:16:33+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 28 22:16:33 volumio go-librespot[32440]: time="2026-01-28T22:16:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 22:16:33 volumio go-librespot[32440]: time="2026-01-28T22:16:33+07:00" level=debug msg="completed keyexchange" Jan 28 22:16:33 volumio go-librespot[32440]: time="2026-01-28T22:16:33+07:00" level=debug msg="completed challenge" Jan 28 22:16:33 volumio go-librespot[32440]: time="2026-01-28T22:16: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 28 22:16:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:16:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:16:33 volumio volumio[32114]: info: Initializing connection to go-librespot Websocket Jan 28 22:16:33 volumio volumio[32114]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 22:16:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:16:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:16:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:16:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:16:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:16:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:16:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Jan 28 22:16:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:16:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:16:36 volumio go-librespot[32447]: go-librespot daemon starting... Jan 28 22:16:36 volumio go-librespot[32448]: time="2026-01-28T22:16:36+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:16:36 volumio go-librespot[32448]: time="2026-01-28T22:16:36+07:00" level=debug msg="app state loaded" Jan 28 22:16:36 volumio go-librespot[32448]: time="2026-01-28T22:16:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:16:36 volumio volumio[32114]: info: Initializing connection to go-librespot Websocket Jan 28 22:16:36 volumio go-librespot[32448]: time="2026-01-28T22:16:36+07:00" level=debug msg="new websocket client" Jan 28 22:16:36 volumio volumio[32114]: info: Connection to go-librespot Websocket established Jan 28 22:16:37 volumio volumio[32114]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 22:16:37 volumio volumio[32114]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 22:16:37 volumio volumio[32114]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 22:16:37 volumio volumio[32114]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 22:16:37 volumio volumio[32114]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 22:16:37 volumio volumio[32114]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 22:16:37 volumio volumio[32114]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 22:16:37 volumio volumio[32114]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 22:16:37 volumio volumio[32114]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 22:16:37 volumio volumio[32114]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 22:16:37 volumio volumio[32114]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 22:16:37 volumio volumio[32114]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 22:16:37 volumio volumio[32114]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 22:16:37 volumio volumio[32114]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 22:16:37 volumio volumio[32114]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 22:16:37 volumio volumio[32114]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 22:16:37 volumio volumio[32114]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 22:16:37 volumio volumio[32114]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 22:16:37 volumio volumio[32114]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 22:16:37 volumio volumio[32114]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 22:16:37 volumio volumio[32114]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 22:16:37 volumio volumio[32114]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 22:16:37 volumio volumio[32114]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 22:16:37 volumio volumio[32114]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 22:16:37 volumio volumio[32114]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 22:16:37 volumio volumio[32114]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 22:16:37 volumio volumio[32114]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 22:16:37 volumio volumio[32114]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 22:16:37 volumio volumio[32114]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 22:16:37 volumio volumio[32114]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 22:16:37 volumio volumio[32114]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 22:16:37 volumio volumio[32114]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 22:16:37 volumio volumio[32114]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 22:16:37 volumio volumio[32114]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 22:16:37 volumio volumio[32114]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 22:16:37 volumio volumio[32114]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 22:16:37 volumio go-librespot[32448]: time="2026-01-28T22:16: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 28 22:16:37 volumio go-librespot[32448]: time="2026-01-28T22:16: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 28 22:16:37 volumio go-librespot[32448]: time="2026-01-28T22:16: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 28 22:16:37 volumio go-librespot[32448]: time="2026-01-28T22:16:37+07:00" level=info msg="zeroconf server listening on port 34455" Jan 28 22:16:37 volumio go-librespot[32448]: time="2026-01-28T22:16:37+07:00" level=debug msg="obtained new client token: AACYnT9syBLR25UO55H0SGeYluusFBZkR/+Cry9x3ExLnvvU2ahGTdMS/ObJesBjZFS5B7SyDR4hA8SHo/CYo8YJuHmcJddblYe9TG2e3YUDIJZR6KK9C5X/aT4G2j5K7gg6qj0ay2WLEWIouL8xm05te5tb06mvlWGXNFXIQWOqYc0KIlds0veJno7NHfKp0GaTVhvPifL6qOgOLCiq8N5OK88AQykGD3VRshjoe4TKilhdbH+nK9UHHec=" Jan 28 22:16:37 volumio go-librespot[32448]: time="2026-01-28T22:16:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:16:37 volumio go-librespot[32448]: time="2026-01-28T22:16:37+07:00" level=debug msg="completed keyexchange" Jan 28 22:16:37 volumio go-librespot[32448]: time="2026-01-28T22:16:37+07:00" level=debug msg="completed challenge" Jan 28 22:16:37 volumio go-librespot[32448]: time="2026-01-28T22:16:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 22:16:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:16:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:16:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:16:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:16:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:16:39 volumio volumio[32114]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 22:16:39 volumio volumio[32114]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 22:16:39 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:16:39 volumio volumio[32114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:16:39 volumio volumio[32114]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 22:16:39 volumio volumio[32114]: info: MyVolumio login type: Token Jan 28 22:16:39 volumio volumio[32114]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 22:16:39 volumio volumio[32114]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 22:16:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:16:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:16:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:16:40 volumio volumio[32114]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 22:16:40 volumio volumio[32114]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 22:16:40 volumio volumio[32114]: info: Streaming services startup Jan 28 22:16:40 volumio volumio[32114]: info: Starting Streaming Daemon Jan 28 22:16:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Jan 28 22:16:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:16:40 volumio sudo[32474]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 22:16:40 volumio volumio[32114]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 22:16:40 volumio sudo[32474]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:16:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:16:40 volumio go-librespot[32477]: go-librespot daemon starting... Jan 28 22:16:40 volumio go-librespot[32481]: time="2026-01-28T22:16:40+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:16:40 volumio go-librespot[32481]: time="2026-01-28T22:16:40+07:00" level=debug msg="app state loaded" Jan 28 22:16:40 volumio go-librespot[32481]: time="2026-01-28T22:16:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:16:40 volumio sudo[32474]: pam_unix(sudo:session): session closed for user root Jan 28 22:16:40 volumio volumio[32114]: info: Getting Spotify volume Jan 28 22:16:40 volumio volumio[32114]: info: Connection to go-librespot Websocket closed Jan 28 22:16:40 volumio volumio[32114]: error: Cannot start Volumio Streaming Daemon Jan 28 22:16:40 volumio volumio[32114]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 22:16:40 volumio volumio[32114]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 22:16:41 volumio volumio[32114]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 28 22:16:41 volumio volumio[32114]: info: CoreCommandRouter::volumioGetState Jan 28 22:16:41 volumio volumio[32114]: info: CorePlayQueue::getTrack 0 Jan 28 22:16:41 volumio volumio[32114]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 28 22:16:41 volumio volumio[32114]: SPOTIFY: SPOTIFY VOLUME undefined Jan 28 22:16:41 volumio volumio[32114]: SPOTIFY: VOLUMIO VOLUME 100 Jan 28 22:16:41 volumio volumio[32114]: info: Aligning Spotify Volume to Volumio Volume Jan 28 22:16:41 volumio volumio[32114]: info: CoreCommandRouter::volumioGetState Jan 28 22:16:41 volumio volumio[32114]: info: CorePlayQueue::getTrack 0 Jan 28 22:16:41 volumio volumio[32114]: info: Setting Spotify Volume from Volumio: 100 Jan 28 22:16:41 volumio go-librespot[32481]: time="2026-01-28T22:16: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 22:16:41 volumio go-librespot[32481]: time="2026-01-28T22:16:41+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 28 22:16:41 volumio go-librespot[32481]: time="2026-01-28T22:16:41+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 28 22:16:41 volumio go-librespot[32481]: time="2026-01-28T22:16:41+07:00" level=info msg="zeroconf server listening on port 43057" Jan 28 22:16:41 volumio go-librespot[32481]: time="2026-01-28T22:16:41+07:00" level=debug msg="obtained new client token: AAAFb1kHlzfdn6pFf9VZlYNrjWdKFsLwyXkDQqoxvLKdfW+VFo+oj6xe/WrOjbE3eS9s6v0SPTEUVy+jyPPQvLrjRKL1y/tX5rFtqD9fE4I52W9okqVp48DZY39lqCjxINdwmB1I1EcCo1cjFBiAsI/97IQ2JIoZ3rSlK3xHcdj8C7DlK1QqojwXF/eERS33V+H5o4xTkVSgdSqsDF1THvV2P78L8ZHoQV2xmR2x859hBuN3PxBvITjeM9M=" Jan 28 22:16:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:16:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:16:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:16:41 volumio go-librespot[32481]: time="2026-01-28T22:16:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:16:41 volumio go-librespot[32481]: time="2026-01-28T22:16:41+07:00" level=debug msg="completed keyexchange" Jan 28 22:16:41 volumio go-librespot[32481]: time="2026-01-28T22:16:41+07:00" level=debug msg="completed challenge" Jan 28 22:16:41 volumio go-librespot[32481]: time="2026-01-28T22:16:41+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 28 22:16:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:16:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:16:42 volumio volumio[32114]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 28 22:16:42 volumio volumio[32114]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 22:16:42 volumio volumio[32114]: Error: socket hang up Jan 28 22:16:42 volumio volumio[32114]: at connResetException (node:internal/errors:720:14) Jan 28 22:16:42 volumio volumio[32114]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 22:16:42 volumio volumio[32114]: at Socket.emit (node:events:526:35) Jan 28 22:16:42 volumio volumio[32114]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 22:16:42 volumio volumio[32114]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 22:16:42 volumio volumio[32114]: code: 'ECONNRESET', Jan 28 22:16:42 volumio volumio[32114]: response: undefined Jan 28 22:16:42 volumio volumio[32114]: } Jan 28 22:16:42 volumio volumio[32114]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 22:16:43 volumio sudo[32503]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 22:15' Jan 28 22:16:43 volumio sudo[32503]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:16:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:16:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:16:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 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"