Jan 27 21:28:00 volumio go-librespot[30366]: time="2026-01-27T21:28:00+07:00" level=debug msg="obtained new client token: AABSeipyQ52vtn8Mf/6/r5pndQeX3XoB6M7uCUX8A1qVTsIzNWTzSFdTY85f9k98JVVn7NbbRdOsVPke/xnNyr2hNEdmpTQF6ogS6q1SFW8IBDR5kKOkmgvUWjjyO06kFN/2f0ki7gfhRabm9rG71Wwfs9GE3xQRj6UVUlu/icfudgpCTulrUBaE7Rhv5x8CkNsnPkNb+IE4r/uxS4xg4v8LhNMehB+pryfNQLZBDTQcVT6rP4S1tfY+" Jan 27 21:28:00 volumio go-librespot[30366]: time="2026-01-27T21:28:00+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 27 21:28:00 volumio go-librespot[30366]: time="2026-01-27T21:28:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 21:28:00 volumio go-librespot[30366]: time="2026-01-27T21:28:00+07:00" level=debug msg="completed keyexchange" Jan 27 21:28:00 volumio go-librespot[30366]: time="2026-01-27T21:28:00+07:00" level=debug msg="completed challenge" Jan 27 21:28:00 volumio go-librespot[30366]: time="2026-01-27T21:28:00+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 21:28:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:28:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:28:00 volumio volumio[30005]: info: Initializing connection to go-librespot Websocket Jan 27 21:28:00 volumio volumio[30005]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:28:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 27 21:28:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:03 volumio go-librespot[30373]: go-librespot daemon starting... Jan 27 21:28:03 volumio go-librespot[30374]: time="2026-01-27T21:28:03+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:28:03 volumio go-librespot[30374]: time="2026-01-27T21:28:03+07:00" level=debug msg="app state loaded" Jan 27 21:28:03 volumio go-librespot[30374]: time="2026-01-27T21:28:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:28:03 volumio volumio[30005]: info: Initializing connection to go-librespot Websocket Jan 27 21:28:03 volumio go-librespot[30374]: time="2026-01-27T21:28:03+07:00" level=debug msg="new websocket client" Jan 27 21:28:03 volumio volumio[30005]: info: Connection to go-librespot Websocket established Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 27 21:28:03 volumio volumio[30005]: info: Adding plugin bluetooth to MyMusic Plugins Jan 27 21:28:03 volumio volumio[30005]: info: Adding plugin multiroom to MyMusic Plugins Jan 27 21:28:03 volumio volumio[30005]: info: Adding plugin metavolumio to MyMusic Plugins Jan 27 21:28:03 volumio volumio[30005]: info: Adding plugin cd_controller to MyMusic Plugins Jan 27 21:28:03 volumio volumio[30005]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 27 21:28:03 volumio volumio[30005]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 27 21:28:03 volumio volumio[30005]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 27 21:28:03 volumio volumio[30005]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 27 21:28:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:04 volumio go-librespot[30374]: time="2026-01-27T21:28:04+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 21:28:04 volumio go-librespot[30374]: time="2026-01-27T21:28:04+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 27 21:28:04 volumio go-librespot[30374]: time="2026-01-27T21:28:04+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 27 21:28:04 volumio go-librespot[30374]: time="2026-01-27T21:28:04+07:00" level=info msg="zeroconf server listening on port 46511" Jan 27 21:28:04 volumio go-librespot[30374]: time="2026-01-27T21:28:04+07:00" level=debug msg="obtained new client token: AAAui3x5PkrzTcp49/HhArF5FTCMYlw6tis5/wOYWeVCAjQti6O+48YjNVfwT1TfBNuA8ooOk6vgU53kdy+IOt6TLAehIRclkjDKH+IwafmmfOSA9GODoXK30mkW9VsMRERuhQZq/Vzsy7BYd68iAF7nHGXGh55wOlzHNxGbv4esON6LF0TLq/xER6v1WN+VktZIkACrpA0oBNn6lIhnhNXHnDr8l2hvapLIj37+CqZsYoDbNi8BYoB+IR0=" Jan 27 21:28:04 volumio go-librespot[30374]: time="2026-01-27T21:28:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:28:04 volumio go-librespot[30374]: time="2026-01-27T21:28:04+07:00" level=debug msg="completed keyexchange" Jan 27 21:28:04 volumio go-librespot[30374]: time="2026-01-27T21:28:04+07:00" level=debug msg="completed challenge" Jan 27 21:28:04 volumio go-librespot[30374]: time="2026-01-27T21:28:04+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 21:28:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:28:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:28:05 volumio volumio[30005]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 27 21:28:05 volumio volumio[30005]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 27 21:28:05 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:28:05 volumio volumio[30005]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:28:05 volumio volumio[30005]: info: Starting MyVolumio Remote Streaming Endpoints Jan 27 21:28:05 volumio volumio[30005]: info: MyVolumio login type: Token Jan 27 21:28:05 volumio volumio[30005]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 27 21:28:05 volumio volumio[30005]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 27 21:28:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:07 volumio volumio[30005]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 27 21:28:07 volumio volumio[30005]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 27 21:28:07 volumio volumio[30005]: info: Streaming services startup Jan 27 21:28:07 volumio volumio[30005]: info: Starting Streaming Daemon Jan 27 21:28:07 volumio sudo[30397]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 21:28:07 volumio volumio[30005]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 27 21:28:07 volumio sudo[30397]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:07 volumio sudo[30397]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:07 volumio volumio[30005]: info: Getting Spotify volume Jan 27 21:28:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 27 21:28:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:07 volumio volumio[30005]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 21:28:07 volumio volumio[30005]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:28:07 volumio volumio[30005]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 27 21:28:07 volumio volumio[30005]: errno: -111, Jan 27 21:28:07 volumio volumio[30005]: code: 'ECONNREFUSED', Jan 27 21:28:07 volumio volumio[30005]: syscall: 'connect', Jan 27 21:28:07 volumio volumio[30005]: address: '127.0.0.1', Jan 27 21:28:07 volumio volumio[30005]: port: 9879, Jan 27 21:28:07 volumio volumio[30005]: response: undefined Jan 27 21:28:07 volumio volumio[30005]: } Jan 27 21:28:07 volumio volumio[30005]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 21:28:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:07 volumio go-librespot[30403]: go-librespot daemon starting... Jan 27 21:28:07 volumio go-librespot[30407]: time="2026-01-27T21:28:07+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:28:07 volumio go-librespot[30407]: time="2026-01-27T21:28:07+07:00" level=debug msg="app state loaded" Jan 27 21:28:07 volumio go-librespot[30407]: time="2026-01-27T21:28:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:28:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:08 volumio go-librespot[30407]: time="2026-01-27T21:28:08+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 21:28:08 volumio go-librespot[30407]: time="2026-01-27T21:28:08+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 27 21:28:08 volumio go-librespot[30407]: time="2026-01-27T21:28:08+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 27 21:28:08 volumio go-librespot[30407]: time="2026-01-27T21:28:08+07:00" level=info msg="zeroconf server listening on port 34511" Jan 27 21:28:08 volumio go-librespot[30407]: time="2026-01-27T21:28:08+07:00" level=debug msg="obtained new client token: AABewF2VgACV86J5ob1y/oxyB+tYAYg7815Bsi6Uzs9PgHOL+3Mvs7r3cNoTrcdgbCXg55p87464caxN5ozBBrDshv9ltQTIExp2v2eV2ymuhGl8PgE5qo2oKFWu0oWnYirDhDajphiWkdqPocYNFrRpkfdTfdKgBQN7ww/Hocvou3Hmjb1gYk2boKmN7MgM15NkgEeDS0vc2aD1FZCfOShzq9luJ/CBSHWY4YyTnbvZotcJImabyO/J0Bs=" Jan 27 21:28:08 volumio go-librespot[30407]: time="2026-01-27T21:28:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:28:08 volumio go-librespot[30407]: time="2026-01-27T21:28:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 21:28:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:28:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:28:09 volumio sudo[30425]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 21:27' Jan 27 21:28:09 volumio sudo[30425]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:09 volumio sudo[30425]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:09 volumio volumio-remote-updater[628]: [2026-01-27 21:28:09] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 27 21:28:09 volumio volumio-remote-updater[628]: [2026-01-27 21:28:09] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 27 21:28:09 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:28:09 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 27 21:28:09 volumio systemd[1]: volumio.service: Consumed 57.401s CPU time. Jan 27 21:28:09 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 21:28:09 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 21:28:09 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 9164. Jan 27 21:28:09 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 21:28:09 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 27 21:28:09 volumio systemd[1]: volumio.service: Consumed 57.401s CPU time. Jan 27 21:28:09 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 27 21:28:09 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 21:28:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 27 21:28:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:12 volumio go-librespot[30454]: go-librespot daemon starting... Jan 27 21:28:12 volumio go-librespot[30455]: time="2026-01-27T21:28:12+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:28:12 volumio go-librespot[30455]: time="2026-01-27T21:28:12+07:00" level=debug msg="app state loaded" Jan 27 21:28:12 volumio go-librespot[30455]: time="2026-01-27T21:28:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:28:12 volumio go-librespot[30455]: time="2026-01-27T21:28:12+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 21:28:12 volumio go-librespot[30455]: time="2026-01-27T21:28:12+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 27 21:28:12 volumio go-librespot[30455]: time="2026-01-27T21:28:12+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 27 21:28:12 volumio go-librespot[30455]: time="2026-01-27T21:28:12+07:00" level=info msg="zeroconf server listening on port 43967" Jan 27 21:28:12 volumio go-librespot[30455]: time="2026-01-27T21:28:12+07:00" level=debug msg="obtained new client token: AADXZLHDARwkABtEG/iOA0HKCiT5cVvea0hLenGNmAyYSJUVZ4DqeZoxC+YPhYbwa6mBUd7r1GSsuWtIS/pcd4XO0VF//9U4aO/pu+34+F+gGajCs9TZN8w+RyFx/mILsVXTcupvgZrwiSXxstD/wGZ3x9wP7g5IyA2O4en6/96yKFQpNUBSMfmxKRMR3e9qxwZ0+zIvRqXqoyssXzgRWEoQxWY+FAirHiuQstcOTrn/KLlvlmd4VB9O0S0=" Jan 27 21:28:13 volumio go-librespot[30455]: time="2026-01-27T21:28:13+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 27 21:28:13 volumio go-librespot[30455]: time="2026-01-27T21:28:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 21:28:13 volumio go-librespot[30455]: time="2026-01-27T21:28:13+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 21:28:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:28:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:28:13 volumio volumio[30438]: info: ------------------------------------------- Jan 27 21:28:13 volumio volumio[30438]: info: ----- Volumio3 ---- Jan 27 21:28:13 volumio volumio[30438]: info: ------------------------------------------- Jan 27 21:28:13 volumio volumio[30438]: info: ----- System startup ---- Jan 27 21:28:13 volumio volumio[30438]: info: ------------------------------------------- Jan 27 21:28:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:14 volumio volumio-remote-updater[628]: [2026-01-27 21:28:14] [connect] Successful connection Jan 27 21:28:14 volumio volumio[30438]: info: MYVOLUMIO Environment detected Jan 27 21:28:14 volumio volumio[30438]: info: Plugin folders cleanup Jan 27 21:28:14 volumio volumio[30438]: info: Scanning into folder /volumio/app/plugins/ Jan 27 21:28:14 volumio volumio[30438]: info: Scanning category audio_interface Jan 27 21:28:14 volumio volumio[30438]: info: Scanning category miscellanea Jan 27 21:28:14 volumio volumio[30438]: info: Scanning category music_service Jan 27 21:28:14 volumio volumio[30438]: info: Scanning category plugins.json Jan 27 21:28:14 volumio volumio[30438]: info: Scanning category system_controller Jan 27 21:28:14 volumio volumio[30438]: info: Scanning category user_interface Jan 27 21:28:14 volumio volumio[30438]: info: Scanning into folder /data/plugins/ Jan 27 21:28:14 volumio volumio[30438]: info: Scanning category music_service Jan 27 21:28:14 volumio volumio[30438]: info: Plugin folders cleanup completed Jan 27 21:28:14 volumio volumio[30438]: info: ------------------------------------------- Jan 27 21:28:14 volumio volumio[30438]: info: ----- Core plugins startup ---- Jan 27 21:28:14 volumio volumio[30438]: info: ------------------------------------------- Jan 27 21:28:14 volumio volumio[30438]: info: Loading plugins from folder /volumio/app/plugins/ Jan 27 21:28:14 volumio volumio[30438]: info: Adding plugin upnp to MyMusic Plugins Jan 27 21:28:14 volumio volumio[30438]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 27 21:28:15 volumio volumio[30438]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 27 21:28:15 volumio volumio[30438]: info: Loading plugins from folder /data/plugins/ Jan 27 21:28:15 volumio volumio[30438]: info: Loading plugin "system"... Jan 27 21:28:15 volumio volumio[30438]: info: Loading plugin "appearance"... Jan 27 21:28:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 27 21:28:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:16 volumio go-librespot[30475]: go-librespot daemon starting... Jan 27 21:28:16 volumio go-librespot[30476]: time="2026-01-27T21:28:16+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:28:16 volumio go-librespot[30476]: time="2026-01-27T21:28:16+07:00" level=debug msg="app state loaded" Jan 27 21:28:16 volumio go-librespot[30476]: time="2026-01-27T21:28:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:28:16 volumio go-librespot[30476]: time="2026-01-27T21:28:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 21:28:16 volumio go-librespot[30476]: time="2026-01-27T21:28:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 27 21:28:16 volumio go-librespot[30476]: time="2026-01-27T21:28:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 27 21:28:16 volumio go-librespot[30476]: time="2026-01-27T21:28:16+07:00" level=info msg="zeroconf server listening on port 34141" Jan 27 21:28:17 volumio volumio[30438]: info: Loading plugin "network"... Jan 27 21:28:17 volumio volumio[30438]: info: Refreshing Cached IP Addresses Jan 27 21:28:17 volumio sudo[30484]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 21:28:17 volumio sudo[30484]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:17 volumio sudo[30486]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 21:28:17 volumio sudo[30484]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:17 volumio sudo[30486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:17 volumio sudo[30486]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:17 volumio volumio[30438]: info: Loading plugin "services"... Jan 27 21:28:17 volumio volumio[30438]: info: Loading plugin "alsa_controller"... Jan 27 21:28:17 volumio sudo[30495]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 27 21:28:17 volumio sudo[30495]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:17 volumio go-librespot[30476]: time="2026-01-27T21:28:17+07:00" level=debug msg="obtained new client token: AABCU4rAdy4WagoZnMUseBKjkxX9O4EfykQi2/eJ2S01PYlt0k22wkLQMftiHQXn/Er7+HEbnBrty9gAX2hGWYmAm6vXieGfdkQI0vg3/Kvr/7OkycI26ORty+e0F8M7t38mm1Pf6zfQ7iM59/YmpIDGX8qbPy/jD0w88I7xBmP6qLXUuBsHyw8mq5S3qcZFf+bTfqDB41OI2VA8HYBgwpgWH8VzVSnfSG4VG/ogRdaUD2fADBp2pmdI" Jan 27 21:28:17 volumio go-librespot[30476]: time="2026-01-27T21:28:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:28:17 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 21:28:17 volumio volumio[30438]: info: Loading plugin "wizard"... Jan 27 21:28:17 volumio volumio[30438]: info: Loading plugin "networkfs"... Jan 27 21:28:17 volumio volumio[30438]: info: Starting Udev Watcher for removable devices Jan 27 21:28:17 volumio volumio[30438]: info: Ignoring mount for partition: boot Jan 27 21:28:17 volumio volumio[30438]: info: Ignoring mount for partition: volumio Jan 27 21:28:17 volumio volumio[30438]: info: Ignoring mount for partition: volumio_data Jan 27 21:28:17 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 21:28:17 volumio volumio[30438]: info: Loading plugin "volumio_command_line_client"... Jan 27 21:28:17 volumio volumio[30438]: info: Loading plugin "upnp"... Jan 27 21:28:17 volumio volumio[30438]: info: [1769524097459] Starting Upmpd Daemon Jan 27 21:28:17 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 21:28:17 volumio volumio[30438]: info: Loading plugin "my_music"... Jan 27 21:28:17 volumio volumio[30438]: info: Loading plugin "mpd"... Jan 27 21:28:17 volumio go-librespot[30476]: time="2026-01-27T21:28:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.107:35162->104.199.241.202:4070: read: connection reset by peer" Jan 27 21:28:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:28:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:28:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:18 volumio volumio[30438]: info: Loading plugin "upnp_browser"... Jan 27 21:28:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:20 volumio sudo[30495]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 27 21:28:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:21 volumio volumio[30438]: info: Starting UPNP Browser Jan 27 21:28:21 volumio volumio[30438]: info: Loading plugin "alarm-clock"... Jan 27 21:28:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:21 volumio go-librespot[30520]: go-librespot daemon starting... Jan 27 21:28:21 volumio go-librespot[30521]: time="2026-01-27T21:28:21+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:28:21 volumio go-librespot[30521]: time="2026-01-27T21:28:21+07:00" level=debug msg="app state loaded" Jan 27 21:28:21 volumio go-librespot[30521]: time="2026-01-27T21:28:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:28:21 volumio volumio[30438]: info: Loading plugin "airplay_emulation"... Jan 27 21:28:21 volumio volumio[30438]: info: Starting Shairport Sync Jan 27 21:28:21 volumio volumio[30438]: info: Loading plugin "last_100"... Jan 27 21:28:21 volumio volumio[30438]: info: Loading plugin "webradio"... Jan 27 21:28:21 volumio volumio[30438]: info: Loading plugin "i2s_dacs"... Jan 27 21:28:21 volumio volumio[30438]: info: Loading plugin "volumiodiscovery"... Jan 27 21:28:21 volumio go-librespot[30521]: time="2026-01-27T21:28:21+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 21:28:21 volumio go-librespot[30521]: time="2026-01-27T21:28:21+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 27 21:28:21 volumio go-librespot[30521]: time="2026-01-27T21:28:21+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 27 21:28:21 volumio go-librespot[30521]: time="2026-01-27T21:28:21+07:00" level=info msg="zeroconf server listening on port 35035" Jan 27 21:28:21 volumio volumio[30438]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 21:28:21 volumio volumio[30438]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 21:28:21 volumio volumio[30438]: *** WARNING *** For more information see Jan 27 21:28:21 volumio volumio[30438]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 21:28:21 volumio volumio[30438]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 21:28:21 volumio volumio[30438]: *** WARNING *** For more information see Jan 27 21:28:21 volumio node[30438]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 21:28:21 volumio node[30438]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 21:28:21 volumio node[30438]: *** WARNING *** For more information see Jan 27 21:28:21 volumio node[30438]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 21:28:21 volumio node[30438]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 21:28:21 volumio node[30438]: *** WARNING *** For more information see Jan 27 21:28:21 volumio volumio[30438]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 27 21:28:21 volumio volumio[30438]: info: Discovery: Started advertising with name: Volumio Jan 27 21:28:21 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 21:28:21 volumio volumio[30438]: info: Loading plugin "spop"... Jan 27 21:28:21 volumio go-librespot[30521]: time="2026-01-27T21:28:21+07:00" level=debug msg="obtained new client token: AABVqLUeDbySrwd4+2cys8lvGbnXdNdgWXTeo9JVDQd+fq2YhBiZ88C6szG3Aa7Dyych7HdOhSgvI/hZJfzcn2C88ii1998Csuxhz53jXake+3TgRl1wAF+Zk3++Li5wnil2VkpOkeuISJyp/u6okir/jUpkvnHwPdXVGJ9gb4sM8t+8D2Ond+WHX1nMpOpiuRoF1ets3rqfOzkE4HA8AE5okITUBqkPnkjLFjDqpmYG6cMwT19fS+IAQ9s=" Jan 27 21:28:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:22 volumio go-librespot[30521]: time="2026-01-27T21:28:22+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 27 21:28:22 volumio go-librespot[30521]: time="2026-01-27T21:28:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 21:28:22 volumio go-librespot[30521]: time="2026-01-27T21:28:22+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 21:28:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:28:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:28:23 volumio volumio[30438]: info: Loading plugin "ytcr"... Jan 27 21:28:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 27 21:28:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:25 volumio go-librespot[30530]: go-librespot daemon starting... Jan 27 21:28:25 volumio go-librespot[30531]: time="2026-01-27T21:28:25+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:28:25 volumio go-librespot[30531]: time="2026-01-27T21:28:25+07:00" level=debug msg="app state loaded" Jan 27 21:28:25 volumio go-librespot[30531]: time="2026-01-27T21:28:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:28:25 volumio go-librespot[30531]: time="2026-01-27T21:28:25+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:28:25 volumio go-librespot[30531]: time="2026-01-27T21:28:25+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 21:28:25 volumio go-librespot[30531]: time="2026-01-27T21:28:25+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 21:28:25 volumio go-librespot[30531]: time="2026-01-27T21:28:25+07:00" level=info msg="zeroconf server listening on port 34987" Jan 27 21:28:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:26 volumio go-librespot[30531]: time="2026-01-27T21:28:26+07:00" level=debug msg="obtained new client token: AABLWLA6imrvSRlm8pdosO5ghEP8AuBU+j4duqa8iPJVMVkX8vdpubQwKtL9szqo8OSmjmDZ9Fj2yrTlWo5falXHY7nRiUcmzh5+4E7KhiTZCpTwXzujEHtb191N6EH/opWqzVeu8VqpGgmtXmko0wLOIs2wASrAMwVjWRGeOJE1hu1IHj4HJKFa1pLGgs/sKAuI9PAK5VHsMmxsQe1G9DYKGeoauGHAa0VO2BTfOPulV4k/u7HDZq8T" Jan 27 21:28:26 volumio go-librespot[30531]: time="2026-01-27T21:28:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:28:26 volumio go-librespot[30531]: time="2026-01-27T21:28:26+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 21:28:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:28:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:28:26 volumio volumio[30438]: info: Loading plugin "ytmusic"... Jan 27 21:28:27 volumio volumio-remote-updater[628]: [2026-01-27 21:28:27] [connect] Successful connection Jan 27 21:28:27 volumio volumio[30438]: info: Loading plugin "outputs"... Jan 27 21:28:27 volumio volumio[30438]: info: Loading plugin "albumart"... Jan 27 21:28:27 volumio volumio[30438]: info: Plugin example_plugin is not enabled Jan 27 21:28:27 volumio volumio[30438]: info: Loading plugin "inputs"... Jan 27 21:28:27 volumio volumio[30438]: info: Loading plugin "updater_comm"... Jan 27 21:28:27 volumio volumio[30438]: info: Plugin mpdemulation is not enabled Jan 27 21:28:27 volumio volumio[30438]: info: Loading plugin "rest_api"... Jan 27 21:28:27 volumio volumio[30438]: info: Loading plugin "websocket"... Jan 27 21:28:27 volumio volumio[30438]: info: Starting Socket.io Server version 1.7.4 Jan 27 21:28:27 volumio volumio[30438]: info: Loading plugin "RoonBridge"... Jan 27 21:28:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:28 volumio volumio[30438]: info: Applying required configuration parameters for plugin RoonBridge Jan 27 21:28:28 volumio volumio[30438]: info: Loading i18n strings for locale en Jan 27 21:28:28 volumio volumio[30438]: Updating browse sources language Jan 27 21:28:28 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:28:28 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 21:28:28 volumio volumio[30438]: info: CoreCommandRouter::initPlayerControls Jan 27 21:28:28 volumio volumio[30553]: Forking 3 albumart workers Jan 27 21:28:28 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:28 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:28 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:28 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:28 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:28 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:28 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:28 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:28 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 21:28:28 volumio volumio[30438]: Express server listening on port 3000 Jan 27 21:28:28 volumio volumio[30438]: [Metrics] WebUI: 16s 150.04ms Jan 27 21:28:28 volumio volumio[30438]: info: CoreStateMachine::resetVolumioState Jan 27 21:28:28 volumio volumio[30438]: info: CoreStateMachine::getcurrentVolume Jan 27 21:28:28 volumio volumio[30438]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 21:28:28 volumio sudo[30596]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 21:28:28 volumio sudo[30596]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:28 volumio sudo[30598]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 21:28:28 volumio sudo[30598]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:28 volumio sudo[30598]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:28 volumio sudo[30596]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:28 volumio volumio[30438]: info: Volumio Network Manager: Network status updated: 1 Jan 27 21:28:29 volumio volumio[30438]: info: VolumeController:: Volume=100 Mute =false Jan 27 21:28:29 volumio volumio[30438]: info: CoreStateMachine::pushState Jan 27 21:28:29 volumio volumio[30438]: info: CorePlayQueue::getTrack 0 Jan 27 21:28:29 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 21:28:29 volumio volumio[30438]: info: CoreCommandRouter::volumioPushState Jan 27 21:28:29 volumio volumio[30438]: info: CoreStateMachine::updateTrackBlock Jan 27 21:28:29 volumio volumio[30438]: info: CorePlayQueue::getTrackBlock Jan 27 21:28:29 volumio volumio[30438]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 21:28:29 volumio volumio-remote-updater[628]: [2026-01-27 21:28:29] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769524107 101 Jan 27 21:28:29 volumio volumio[30438]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 27 21:28:29 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:28:29 volumio volumio[30438]: info: Reloading queue from file Jan 27 21:28:29 volumio volumio[30438]: info: CoreStateMachine::setRepeat null single undefined Jan 27 21:28:29 volumio volumio[30438]: info: CoreStateMachine::pushState Jan 27 21:28:29 volumio volumio[30438]: info: CorePlayQueue::getTrack 0 Jan 27 21:28:29 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 21:28:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 27 21:28:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:29 volumio volumio[30438]: info: CoreCommandRouter::volumioPushState Jan 27 21:28:29 volumio volumio[30438]: info: CoreStateMachine::setRandom null Jan 27 21:28:29 volumio volumio[30438]: info: CoreStateMachine::pushState Jan 27 21:28:29 volumio volumio[30438]: info: CorePlayQueue::getTrack 0 Jan 27 21:28:29 volumio volumio[30438]: info: CoreCommandRouter::volumioPushState Jan 27 21:28:29 volumio volumio[30438]: info: Setting Device type: Raspberry PI Jan 27 21:28:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:29 volumio go-librespot[30612]: go-librespot daemon starting... Jan 27 21:28:29 volumio volumio[30438]: info: Completed loading Core Plugins Jan 27 21:28:29 volumio volumio[30438]: info: Preparing to generate the ALSA configuration file Jan 27 21:28:29 volumio go-librespot[30614]: time="2026-01-27T21:28:29+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:28:29 volumio go-librespot[30614]: time="2026-01-27T21:28:29+07:00" level=debug msg="app state loaded" Jan 27 21:28:29 volumio go-librespot[30614]: time="2026-01-27T21:28:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:28:29 volumio volumio[30438]: info: VolumeController:: Volume=100 Mute =false Jan 27 21:28:29 volumio volumio[30438]: info: CoreStateMachine::pushState Jan 27 21:28:29 volumio volumio[30438]: info: CorePlayQueue::getTrack 0 Jan 27 21:28:29 volumio volumio[30438]: info: CoreCommandRouter::volumioPushState Jan 27 21:28:29 volumio volumio[30438]: info: Asound.conf file unchanged, so no further update is needed Jan 27 21:28:29 volumio volumio[30438]: info: Output device has changed, restarting MPD Jan 27 21:28:29 volumio volumio[30438]: info: Output device has changed, restarting Shairport Sync Jan 27 21:28:29 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:29 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:28:29 volumio sudo[30622]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 27 21:28:29 volumio sudo[30622]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:29 volumio sudo[30627]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 21:28:29 volumio sudo[30627]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:30 volumio volumio[30438]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 21:28:30 volumio volumio[30438]: info: ___________ START PLUGINS ___________ Jan 27 21:28:30 volumio sudo[30625]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 21:28:30 volumio sudo[30625]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:30 volumio volumio[30438]: info: ControllerMpd::onStart: Initializing MPD Jan 27 21:28:30 volumio volumio[30438]: info: Creating MPD Configuration file Jan 27 21:28:30 volumio sudo[30625]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:30 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 27 21:28:30 volumio sudo[30636]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 21:28:30 volumio sudo[30636]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:30 volumio sudo[30622]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:30 volumio sudo[30636]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:30 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 21:28:30 volumio volumio[30438]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 21:28:30 volumio volumio[30438]: info: [1769524110147] CoreMusicLibrary::Adding element Media Servers Jan 27 21:28:30 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:28:30 volumio volumio[30438]: info: UPNP Browser: Client initialized successfully Jan 27 21:28:30 volumio sudo[30639]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 21:28:30 volumio sudo[30639]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:30 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 21:28:30 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 21:28:30 volumio systemd[1]: mpd.service: Consumed 7.443s CPU time. Jan 27 21:28:30 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 21:28:30 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 21:28:30 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 21:28:30 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:30 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:28:30 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 21:28:30 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 21:28:30 volumio volumio[30438]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 21:28:30 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:30 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:28:30 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 21:28:30 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 21:28:30 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 21:28:30 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 21:28:30 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 21:28:30 volumio go-librespot[30614]: time="2026-01-27T21:28:30+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:28:30 volumio go-librespot[30614]: time="2026-01-27T21:28:30+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 21:28:30 volumio go-librespot[30614]: time="2026-01-27T21:28:30+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 21:28:30 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 21:28:30 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 21:28:30 volumio go-librespot[30614]: time="2026-01-27T21:28:30+07:00" level=info msg="zeroconf server listening on port 40907" Jan 27 21:28:30 volumio volumio[30438]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 21:28:30 volumio volumio[30438]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 21:28:30 volumio volumio[30438]: info: [1769524110465] CoreMusicLibrary::Adding element Last_100 Jan 27 21:28:30 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:28:30 volumio volumio[30438]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 21:28:30 volumio volumio[30438]: info: [1769524110502] CoreMusicLibrary::Adding element Webradio Jan 27 21:28:30 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:28:30 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 21:28:30 volumio volumio[30438]: info: Initializing BBC Radios Jan 27 21:28:30 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 21:28:30 volumio go-librespot[30614]: time="2026-01-27T21:28:30+07:00" level=debug msg="obtained new client token: AABvdwlpXRX0CdCZGHaucFVNKbnnPRTE4/fCCbYVF2wos0/tqF9XECrvSuxqz7ItMYFCvQsM381o5hMNU/FlQuhqghVX/9T4NGukuTa3A+bNFTuLrEu/f9YUwUBbMvezKTfjlp88kbvzs8f6vpSOOWnyvl8pUxoJ7wSNSnJxyoYsfc8wRPoLqp3w8raMdDQBaTgClVw7EyKcByiCHQK9i7xWNjY7v+WBkt4CYbjCTU39DrcAEDUg29B9x4g=" Jan 27 21:28:30 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:28:30 volumio volumio[30438]: info: Creating Spotify config file Jan 27 21:28:30 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:30 volumio go-librespot[30614]: time="2026-01-27T21:28:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:28:30 volumio go-librespot[30614]: time="2026-01-27T21:28:30+07:00" level=debug msg="completed keyexchange" Jan 27 21:28:30 volumio go-librespot[30614]: time="2026-01-27T21:28:30+07:00" level=debug msg="completed challenge" Jan 27 21:28:30 volumio sudo[30652]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 27 21:28:30 volumio sudo[30652]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 27 21:28:30 volumio sudo[30652]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:30 volumio go-librespot[30614]: time="2026-01-27T21:28:30+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 21:28:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:28:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:28:31 volumio volumio[30438]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 21:28:31 volumio volumio[30438]: info: [1769524111807] CoreMusicLibrary::Adding element YouTube Music Jan 27 21:28:31 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:28:31 volumio volumio[30438]: Cannot find translation for source YouTube Music Jan 27 21:28:31 volumio volumio[30438]: info: Volumio Calling Home Jan 27 21:28:31 volumio sudo[30669]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 27 21:28:31 volumio sudo[30669]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:32 volumio sudo[30669]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:32 volumio volumio[30565]: Starting albumart workers Jan 27 21:28:32 volumio volumio[30438]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 21:28:32 volumio volumio[30438]: info: Discovery: Found device Volumio Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::volumioGetState Jan 27 21:28:32 volumio volumio[30438]: info: CorePlayQueue::getTrack 0 Jan 27 21:28:32 volumio volumio[30564]: Starting albumart workers Jan 27 21:28:32 volumio volumio[30438]: info: MPD Permissions set Jan 27 21:28:32 volumio volumio[30438]: info: MPD Permissions set Jan 27 21:28:32 volumio volumio[30438]: info: Upmpdcli Daemon Started Jan 27 21:28:32 volumio volumio[30438]: info: Spotify config file written Jan 27 21:28:32 volumio volumio[30438]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 27 21:28:32 volumio sudo[30675]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 21:28:32 volumio sudo[30675]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:32 volumio volumio[30567]: Starting albumart workers Jan 27 21:28:32 volumio volumio[30438]: info: Volumio called home Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:32 volumio go-librespot[30679]: go-librespot daemon starting... Jan 27 21:28:32 volumio sudo[30675]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:28:32 volumio volumio[30438]: info: No need to fix Spotify hosts Jan 27 21:28:33 volumio go-librespot[30683]: time="2026-01-27T21:28:33+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:28:33 volumio go-librespot[30683]: time="2026-01-27T21:28:33+07:00" level=debug msg="app state loaded" Jan 27 21:28:33 volumio go-librespot[30683]: time="2026-01-27T21:28:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:28:33 volumio volumio[30438]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 21:28:33 volumio volumio[30438]: info: Discovery: Found device Volumio Jan 27 21:28:33 volumio volumio[30438]: info: CoreCommandRouter::volumioGetState Jan 27 21:28:33 volumio volumio[30438]: info: CorePlayQueue::getTrack 0 Jan 27 21:28:33 volumio go-librespot[30683]: time="2026-01-27T21:28:33+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:28:33 volumio go-librespot[30683]: time="2026-01-27T21:28:33+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 21:28:33 volumio go-librespot[30683]: time="2026-01-27T21:28:33+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 21:28:33 volumio go-librespot[30683]: time="2026-01-27T21:28:33+07:00" level=info msg="zeroconf server listening on port 36569" Jan 27 21:28:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:34 volumio go-librespot[30683]: time="2026-01-27T21:28:34+07:00" level=debug msg="obtained new client token: AAASM2iS4F7jxYpKlSmqG0djtOLeiV0T0QU2t+aQnKDynQ6x5oKBWyJwNQpnba6njgP0ZJAG8m4jv1uVW5gg9KMeBYV0sHaiaomjiI/ljFdnGlz5yBp/WYJJjBMnBE7wH4DpGxiOb8nU9YisdvG92Xj4M0XoBpdQBB6unDzAZ64LjvOs7KObg8zlqaqnVA7dHcuGbjLV1gKtF8qnXmbPYdlQ34fGOGnzen476cLMrqFdOkH7DPbkpdtv" Jan 27 21:28:34 volumio go-librespot[30683]: time="2026-01-27T21:28:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:28:34 volumio go-librespot[30683]: time="2026-01-27T21:28:34+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 21:28:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:28:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:28:34 volumio volumio[30438]: info: Starting Shairport Sync Jan 27 21:28:34 volumio volumio[30438]: info: Starting Shairport Sync Jan 27 21:28:34 volumio volumio[30438]: info: Starting Shairport Sync Jan 27 21:28:34 volumio sudo[30710]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 21:28:34 volumio sudo[30717]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 21:28:34 volumio sudo[30717]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:34 volumio sudo[30710]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:34 volumio volumio[30438]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 21:28:34 volumio volumio[30438]: SPOTIFY: BQAJbIptB0JlYTd_SOtfatkBVxhQ4bLn1A4QO1VIw_Z4iRiUflCIlH1NXLD6xBbP367rQWYD7qbJ2gyiuE2UlRa7cpnfN6m7iVFiRkSSNxWtfeVZecg5AGdGW0iPrAp7UnrUpGxOA82XXZOzu067hwjRkFG9EuhG8BXaWqJV303pzk--YnWWqIEc9YcJf0OEEqz3ZLqTc5Ey97RPf6bwSr6ONsaPGrxON97SD0kDzkvyr-V9X_ffShUU6BAQ2SLeMEwimYc8gB5SsiO_8seTPWSRwYuIz-hjpjlcuC5Lv6zoPwA6c1XqKgRr Jan 27 21:28:34 volumio volumio[30438]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 21:28:34 volumio volumio[30438]: info: New Spotify access token = BQAJbIptB0JlYTd_SOtfatkBVxhQ4bLn1A4QO1VIw_Z4iRiUflCIlH1NXLD6xBbP367rQWYD7qbJ2gyiuE2UlRa7cpnfN6m7iVFiRkSSNxWtfeVZecg5AGdGW0iPrAp7UnrUpGxOA82XXZOzu067hwjRkFG9EuhG8BXaWqJV303pzk--YnWWqIEc9YcJf0OEEqz3ZLqTc5Ey97RPf6bwSr6ONsaPGrxON97SD0kDzkvyr-V9X_ffShUU6BAQ2SLeMEwimYc8gB5SsiO_8seTPWSRwYuIz-hjpjlcuC5Lv6zoPwA6c1XqKgRr Jan 27 21:28:34 volumio volumio[30438]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 27 21:28:34 volumio sudo[30719]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 21:28:35 volumio sudo[30719]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:35 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 21:28:35 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 21:28:35 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 21:28:35 volumio systemd[1]: shairport-sync.service: Consumed 2.239s CPU time. Jan 27 21:28:35 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 21:28:35 volumio sudo[30717]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:35 volumio sudo[30710]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:35 volumio sudo[30719]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:35 volumio volumio[30438]: info: Shairport-Sync Started Jan 27 21:28:35 volumio volumio[30438]: Error adding Membership: Error: addMembership EINVAL Jan 27 21:28:35 volumio volumio[30438]: info: Shairport-Sync Started Jan 27 21:28:35 volumio volumio[30438]: info: Shairport-Sync Started Jan 27 21:28:35 volumio volumio[30438]: info: CoreCommandRouter::volumioGetState Jan 27 21:28:35 volumio volumio[30438]: info: CorePlayQueue::getTrack 0 Jan 27 21:28:35 volumio volumio[30438]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Jan 27 21:28:35 volumio volumio[30438]: info: Spotify Successfully logged in Jan 27 21:28:35 volumio volumio[30438]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 21:28:35 volumio volumio[30438]: info: [1769524115781] CoreMusicLibrary::Adding element Spotify Jan 27 21:28:35 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:28:35 volumio volumio[30438]: Cannot find translation for source YouTube Music Jan 27 21:28:35 volumio volumio[30438]: Cannot find translation for source Spotify Jan 27 21:28:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:36 volumio volumio[30438]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 27 21:28:36 volumio volumio[30438]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 21:28:36 volumio volumio[30438]: info: VolumeController:: Volume=100 Mute =false Jan 27 21:28:36 volumio volumio[30438]: info: CoreCommandRouter::volumioGetState Jan 27 21:28:36 volumio volumio[30438]: info: CorePlayQueue::getTrack 0 Jan 27 21:28:36 volumio volumio[30438]: info: CoreStateMachine::pushState Jan 27 21:28:36 volumio volumio[30438]: info: CorePlayQueue::getTrack 0 Jan 27 21:28:36 volumio volumio[30438]: info: CoreCommandRouter::volumioPushState Jan 27 21:28:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 27 21:28:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:37 volumio volumio[30438]: info: go-librespot daemon successfully initialized Jan 27 21:28:37 volumio go-librespot[30755]: go-librespot daemon starting... Jan 27 21:28:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:37 volumio go-librespot[30756]: time="2026-01-27T21:28:37+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:28:37 volumio go-librespot[30756]: time="2026-01-27T21:28:37+07:00" level=debug msg="app state loaded" Jan 27 21:28:37 volumio go-librespot[30756]: time="2026-01-27T21:28:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:28:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:38 volumio go-librespot[30756]: time="2026-01-27T21:28:38+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:28:38 volumio go-librespot[30756]: time="2026-01-27T21:28:38+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 21:28:38 volumio go-librespot[30756]: time="2026-01-27T21:28:38+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 21:28:38 volumio go-librespot[30756]: time="2026-01-27T21:28:38+07:00" level=info msg="zeroconf server listening on port 38555" Jan 27 21:28:38 volumio mpd[30667]: 2026-01-27T21:28:38 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 27 21:28:38 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 27 21:28:38 volumio sudo[30639]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:38 volumio sudo[30627]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:38 volumio go-librespot[30756]: time="2026-01-27T21:28:38+07:00" level=debug msg="obtained new client token: AABKx5/gRWFW1f0xEgXtHVjJtn1sfnAUhWDSFOnjFeLU1/098b8oE8AP+gO/uTNsEjlVTGL7M6edfwwgRpWYICYKT5Lim6aai8vY3Gl/BEe4uA/Cr8YuMGhSUxFzF2D2WlMiEFGMej4U2rdW6KUqVoNmkw/8m95G7C54DDbDUm+kZCk8cVR4PznNmZl8Ws01mMauurAb7OQb+HP16jpzTzqyLJ8KcV5aGuWjY47PzjnDkovl9JeCXMrKXrc=" Jan 27 21:28:38 volumio go-librespot[30756]: time="2026-01-27T21:28:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:28:38 volumio go-librespot[30756]: time="2026-01-27T21:28:38+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 21:28:38 volumio volumio[30438]: error: MPD error: The expression evaluated to a falsy value: Jan 27 21:28:38 volumio volumio[30438]: assert.ok(self.idling) Jan 27 21:28:38 volumio volumio[30438]: error: The expression evaluated to a falsy value: Jan 27 21:28:38 volumio volumio[30438]: assert.ok(self.idling) Jan 27 21:28:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:28:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:28:38 volumio volumio[30438]: info: MPD running with PID30667 Jan 27 21:28:38 volumio volumio[30438]: ,establishing connection Jan 27 21:28:38 volumio volumio[30438]: error: updateQueue error: null Jan 27 21:28:38 volumio volumio[30438]: info: Completed starting Core Plugins Jan 27 21:28:38 volumio volumio[30438]: info: ------------------------------------------- Jan 27 21:28:38 volumio volumio[30438]: info: ----- MyVolumio plugins startup ---- Jan 27 21:28:38 volumio volumio[30438]: info: ------------------------------------------- Jan 27 21:28:38 volumio volumio[30438]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 27 21:28:38 volumio volumio[30438]: error: updateQueue error: null Jan 27 21:28:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:40 volumio volumio[30438]: info: Initializing connection to go-librespot Websocket Jan 27 21:28:40 volumio volumio[30438]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:28:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Jan 27 21:28:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:41 volumio go-librespot[30767]: go-librespot daemon starting... Jan 27 21:28:41 volumio go-librespot[30768]: time="2026-01-27T21:28:41+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:28:41 volumio go-librespot[30768]: time="2026-01-27T21:28:41+07:00" level=debug msg="app state loaded" Jan 27 21:28:41 volumio go-librespot[30768]: time="2026-01-27T21:28:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:28:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:42 volumio go-librespot[30768]: time="2026-01-27T21:28:42+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:28:42 volumio go-librespot[30768]: time="2026-01-27T21:28:42+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 21:28:42 volumio go-librespot[30768]: time="2026-01-27T21:28:42+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 21:28:42 volumio go-librespot[30768]: time="2026-01-27T21:28:42+07:00" level=info msg="zeroconf server listening on port 35937" Jan 27 21:28:42 volumio go-librespot[30768]: time="2026-01-27T21:28:42+07:00" level=debug msg="obtained new client token: AABOlKHRAqbpjOtVRTXOLwVUho6tFbpOdb9X6ZpmfYYMOd6/9u2yDlfUANqWncxAQg0Vy2/MaOO0Y0by9iF39u3brJ1VTI/ON3iPjni0RMCKtkQjEPWr6YwfJD3cMWvJju9AgpZmpStaX6+/YXPKgMtyjUo93y+N90R6CDOv1/DGXJtxXaA8pxzJECdpoZIB4VXgm8x49k+1G8Xy2LOGF0f/J99HbhptMFRXMH/v+uQiGThdVBpzvRj25iI=" Jan 27 21:28:42 volumio go-librespot[30768]: time="2026-01-27T21:28:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:28:42 volumio go-librespot[30768]: time="2026-01-27T21:28:42+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 21:28:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:28:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:28:43 volumio volumio[30438]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 27 21:28:43 volumio volumio[30438]: info: Initializing connection to go-librespot Websocket Jan 27 21:28:43 volumio volumio[30438]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:28:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jan 27 21:28:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:46 volumio go-librespot[30775]: go-librespot daemon starting... Jan 27 21:28:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:46 volumio go-librespot[30776]: time="2026-01-27T21:28:46+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:28:46 volumio go-librespot[30776]: time="2026-01-27T21:28:46+07:00" level=debug msg="app state loaded" Jan 27 21:28:46 volumio go-librespot[30776]: time="2026-01-27T21:28:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:28:46 volumio go-librespot[30776]: time="2026-01-27T21:28:46+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:28:46 volumio go-librespot[30776]: time="2026-01-27T21:28:46+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 21:28:46 volumio go-librespot[30776]: time="2026-01-27T21:28:46+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 21:28:46 volumio go-librespot[30776]: time="2026-01-27T21:28:46+07:00" level=info msg="zeroconf server listening on port 34445" Jan 27 21:28:46 volumio volumio[30438]: info: Initializing connection to go-librespot Websocket Jan 27 21:28:46 volumio go-librespot[30776]: time="2026-01-27T21:28:46+07:00" level=debug msg="new websocket client" Jan 27 21:28:46 volumio volumio[30438]: info: Connection to go-librespot Websocket established Jan 27 21:28:46 volumio go-librespot[30776]: time="2026-01-27T21:28:46+07:00" level=debug msg="obtained new client token: AAADFYpxIO+Vye1nItQcNwFIs+qkbhFEYNJzCgJ5iXktJK9AcrgIzOJsFo5uqdFEMyGOcy2+BJEzdnw4De0/tuUHZQfgfoXQVP8CsMm7WO0Nipv6VY64Zap6GJ0NuK5lUwQ6z5ZSLnRWNApN+JEiKTgCijb3e8U5SAdvvPAc8p79cb6jqKDXkotltrJl4svUHonOY6TfVJq4dV1MGBiO9dyfsGZTCGqywiPondRKuAPgHJWSFhTnL5J7hJs=" Jan 27 21:28:46 volumio go-librespot[30776]: time="2026-01-27T21:28:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:28:46 volumio go-librespot[30776]: time="2026-01-27T21:28:46+07:00" level=debug msg="completed keyexchange" Jan 27 21:28:46 volumio go-librespot[30776]: time="2026-01-27T21:28:46+07:00" level=debug msg="completed challenge" Jan 27 21:28:47 volumio go-librespot[30776]: time="2026-01-27T21:28:47+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 21:28:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:28:47 volumio volumio[30438]: info: Connection to go-librespot Websocket closed Jan 27 21:28:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 27 21:28:47 volumio volumio[30438]: info: Adding plugin bluetooth to MyMusic Plugins Jan 27 21:28:47 volumio volumio[30438]: info: Adding plugin multiroom to MyMusic Plugins Jan 27 21:28:47 volumio volumio[30438]: info: Adding plugin metavolumio to MyMusic Plugins Jan 27 21:28:47 volumio volumio[30438]: info: Adding plugin cd_controller to MyMusic Plugins Jan 27 21:28:47 volumio volumio[30438]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 27 21:28:47 volumio volumio[30438]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 27 21:28:47 volumio volumio[30438]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 27 21:28:47 volumio volumio[30438]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 27 21:28:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:49 volumio volumio[30438]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 27 21:28:49 volumio volumio[30438]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 27 21:28:49 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:28:49 volumio volumio[30438]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:28:49 volumio volumio[30438]: info: Starting MyVolumio Remote Streaming Endpoints Jan 27 21:28:49 volumio volumio[30438]: info: MyVolumio login type: Token Jan 27 21:28:49 volumio volumio[30438]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 27 21:28:49 volumio volumio[30438]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 27 21:28:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Jan 27 21:28:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:50 volumio go-librespot[30798]: go-librespot daemon starting... Jan 27 21:28:50 volumio go-librespot[30801]: time="2026-01-27T21:28:50+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:28:50 volumio go-librespot[30801]: time="2026-01-27T21:28:50+07:00" level=debug msg="app state loaded" Jan 27 21:28:50 volumio go-librespot[30801]: time="2026-01-27T21:28:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:28:50 volumio go-librespot[30801]: time="2026-01-27T21:28:50+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:28:50 volumio go-librespot[30801]: time="2026-01-27T21:28:50+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 21:28:50 volumio go-librespot[30801]: time="2026-01-27T21:28:50+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 21:28:50 volumio go-librespot[30801]: time="2026-01-27T21:28:50+07:00" level=info msg="zeroconf server listening on port 33515" Jan 27 21:28:51 volumio go-librespot[30801]: time="2026-01-27T21:28:51+07:00" level=debug msg="obtained new client token: AAAksMwUohlPKLZTyqB0iHoTZtgLrWJctRnf1mf7v47gkCcDNPmCXRD6Wc5wtxjJWDqi4Xrqf2PSUBiPeCZk9xbXrAWE/Ps72PtdALZ76P3NI9NoXYdqKtXyluAOCZw5a+tFRdMl7dFxnM1k+QoPxsKeaIVZOojXTwEh7QiNeZhVCe9V7GW39zmF4/YDczGOJPI1GFGs6/r45H1qeMlYOhQ/PqIG7DrzxZUOk65HQnpRSe4Jmp/YXYk+" Jan 27 21:28:51 volumio volumio[30438]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 27 21:28:51 volumio volumio[30438]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 27 21:28:51 volumio volumio[30438]: info: Streaming services startup Jan 27 21:28:51 volumio volumio[30438]: info: Starting Streaming Daemon Jan 27 21:28:51 volumio go-librespot[30801]: time="2026-01-27T21:28:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:28:51 volumio sudo[30810]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 21:28:51 volumio sudo[30810]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:51 volumio volumio[30438]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 27 21:28:51 volumio go-librespot[30801]: time="2026-01-27T21:28:51+07:00" level=debug msg="completed keyexchange" Jan 27 21:28:51 volumio sudo[30810]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:51 volumio go-librespot[30801]: time="2026-01-27T21:28:51+07:00" level=debug msg="completed challenge" Jan 27 21:28:51 volumio volumio[30438]: info: Getting Spotify volume Jan 27 21:28:51 volumio volumio[30438]: info: Initializing connection to go-librespot Websocket Jan 27 21:28:51 volumio go-librespot[30801]: time="2026-01-27T21:28:51+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 21:28:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:28:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:28:51 volumio volumio[30438]: error: Cannot start Volumio Streaming Daemon Jan 27 21:28:51 volumio volumio[30438]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 21:28:51 volumio volumio[30438]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 21:28:51 volumio volumio[30438]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 21:28:51 volumio volumio[30438]: Error: socket hang up Jan 27 21:28:51 volumio volumio[30438]: at connResetException (node:internal/errors:720:14) Jan 27 21:28:51 volumio volumio[30438]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 27 21:28:51 volumio volumio[30438]: at Socket.emit (node:events:526:35) Jan 27 21:28:51 volumio volumio[30438]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 27 21:28:51 volumio volumio[30438]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 27 21:28:51 volumio volumio[30438]: code: 'ECONNRESET', Jan 27 21:28:51 volumio volumio[30438]: response: undefined Jan 27 21:28:51 volumio volumio[30438]: } Jan 27 21:28:51 volumio volumio[30438]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 21:28:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:52 volumio sudo[30830]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 21:27' Jan 27 21:28:52 volumio sudo[30830]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:28:53 volumio sudo[30830]: pam_unix(sudo:session): session closed for user root Jan 27 21:28:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Jan 27 21:28:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:54 volumio go-librespot[30838]: go-librespot daemon starting... Jan 27 21:28:54 volumio go-librespot[30839]: time="2026-01-27T21:28:54+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:28:54 volumio go-librespot[30839]: time="2026-01-27T21:28:54+07:00" level=debug msg="app state loaded" Jan 27 21:28:54 volumio go-librespot[30839]: time="2026-01-27T21:28:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:28:54 volumio volumio-remote-updater[628]: [2026-01-27 21:28:54] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Jan 27 21:28:54 volumio volumio-remote-updater[628]: [2026-01-27 21:28:54] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Jan 27 21:28:54 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:28:54 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 27 21:28:54 volumio systemd[1]: volumio.service: Consumed 57.819s CPU time. Jan 27 21:28:54 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 21:28:54 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 21:28:54 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 9165. Jan 27 21:28:55 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 21:28:55 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 27 21:28:55 volumio systemd[1]: volumio.service: Consumed 57.819s CPU time. Jan 27 21:28:55 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 27 21:28:55 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 21:28:55 volumio go-librespot[30839]: time="2026-01-27T21:28:55+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 21:28:55 volumio go-librespot[30839]: time="2026-01-27T21:28:55+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 27 21:28:55 volumio go-librespot[30839]: time="2026-01-27T21:28:55+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 27 21:28:55 volumio go-librespot[30839]: time="2026-01-27T21:28:55+07:00" level=info msg="zeroconf server listening on port 35081" Jan 27 21:28:55 volumio go-librespot[30839]: time="2026-01-27T21:28:55+07:00" level=debug msg="obtained new client token: AACTbM6EvdJBjXUnOQjw+bXGWQXMd6xAqZHpRzpx83IYkPwTL2YQX38EwZWDgJutcLHP9jNYQO+kBDG/2MctFfYyVzZZBwhuP5ru436Xa63ZnejVCi+vDhPN21dT9p4amCeySymVXyh+Rh9UngS8laTSL+3XYE//C7mnbtbav902GnxoePjjrMpvvGC4Pwxpe6b71fbQnISGzoIhHP5Pup7M4paeO0LKyktrnSbot4qFISae6Z6jyWXzu9c=" Jan 27 21:28:55 volumio go-librespot[30839]: time="2026-01-27T21:28:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:28:55 volumio go-librespot[30839]: time="2026-01-27T21:28:55+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 21:28:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:28:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:28:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:28:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:28:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:28:58 volumio volumio[30857]: info: ------------------------------------------- Jan 27 21:28:58 volumio volumio[30857]: info: ----- Volumio3 ---- Jan 27 21:28:58 volumio volumio[30857]: info: ------------------------------------------- Jan 27 21:28:58 volumio volumio[30857]: info: ----- System startup ---- Jan 27 21:28:58 volumio volumio[30857]: info: ------------------------------------------- Jan 27 21:28:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Jan 27 21:28:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:28:58 volumio go-librespot[30878]: go-librespot daemon starting... Jan 27 21:28:58 volumio go-librespot[30879]: time="2026-01-27T21:28:58+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:28:58 volumio go-librespot[30879]: time="2026-01-27T21:28:58+07:00" level=debug msg="app state loaded" Jan 27 21:28:58 volumio go-librespot[30879]: time="2026-01-27T21:28:58+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:28:59 volumio go-librespot[30879]: time="2026-01-27T21:28:59+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:28:59 volumio go-librespot[30879]: time="2026-01-27T21:28:59+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 21:28:59 volumio go-librespot[30879]: time="2026-01-27T21:28:59+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 21:28:59 volumio go-librespot[30879]: time="2026-01-27T21:28:59+07:00" level=info msg="zeroconf server listening on port 33363" Jan 27 21:28:59 volumio go-librespot[30879]: time="2026-01-27T21:28:59+07:00" level=debug msg="obtained new client token: AAA5dbE55owmmWoRU+2GjYDFOk/sEmXZCV8ScfwrZnCzF4R2jjC0RTAnoCHLEj4xJoDAYBCJABrMyISnDq7G4za/Rm3kdq+mrgBKPcyyrNncxcGwZVr91jgMulp6enPgUeStksCiAUIqxduspgHTMy8Un52SEzfzrMPIsj+RxxwvLPgVT7carCQa8y6+C3TGrdZLu5bBd5iGcvFCzOXfmYR529zhy4WrijpXYcSl/tSj0AMY0SGKE88nFRY=" Jan 27 21:28:59 volumio go-librespot[30879]: time="2026-01-27T21:28:59+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:28:59 volumio go-librespot[30879]: time="2026-01-27T21:28: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 27 21:28:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:28:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:28:59 volumio volumio-remote-updater[628]: [2026-01-27 21:28:59] [connect] Successful connection Jan 27 21:29:00 volumio volumio[30857]: info: MYVOLUMIO Environment detected Jan 27 21:29:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:29:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:29:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:29:00 volumio volumio[30857]: info: Plugin folders cleanup Jan 27 21:29:00 volumio volumio[30857]: info: Scanning into folder /volumio/app/plugins/ Jan 27 21:29:00 volumio volumio[30857]: info: Scanning category audio_interface Jan 27 21:29:00 volumio volumio[30857]: info: Scanning category miscellanea Jan 27 21:29:00 volumio volumio[30857]: info: Scanning category music_service Jan 27 21:29:00 volumio volumio[30857]: info: Scanning category plugins.json Jan 27 21:29:00 volumio volumio[30857]: info: Scanning category system_controller Jan 27 21:29:00 volumio volumio[30857]: info: Scanning category user_interface Jan 27 21:29:00 volumio volumio[30857]: info: Scanning into folder /data/plugins/ Jan 27 21:29:00 volumio volumio[30857]: info: Scanning category music_service Jan 27 21:29:00 volumio volumio[30857]: info: Plugin folders cleanup completed Jan 27 21:29:00 volumio volumio[30857]: info: ------------------------------------------- Jan 27 21:29:00 volumio volumio[30857]: info: ----- Core plugins startup ---- Jan 27 21:29:00 volumio volumio[30857]: info: ------------------------------------------- Jan 27 21:29:00 volumio volumio[30857]: info: Loading plugins from folder /volumio/app/plugins/ Jan 27 21:29:00 volumio volumio[30857]: info: Adding plugin upnp to MyMusic Plugins Jan 27 21:29:00 volumio volumio[30857]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 27 21:29:00 volumio volumio[30857]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 27 21:29:00 volumio volumio[30857]: info: Loading plugins from folder /data/plugins/ Jan 27 21:29:00 volumio volumio[30857]: info: Loading plugin "system"... Jan 27 21:29:00 volumio volumio[30857]: info: Loading plugin "appearance"... Jan 27 21:29:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:29:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:29:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:29:02 volumio volumio[30857]: info: Loading plugin "network"... Jan 27 21:29:02 volumio volumio[30857]: info: Refreshing Cached IP Addresses Jan 27 21:29:02 volumio sudo[30893]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 21:29:02 volumio sudo[30893]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:29:02 volumio sudo[30895]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 21:29:02 volumio sudo[30895]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:29:02 volumio sudo[30893]: pam_unix(sudo:session): session closed for user root Jan 27 21:29:02 volumio volumio[30857]: info: Loading plugin "services"... Jan 27 21:29:02 volumio sudo[30895]: pam_unix(sudo:session): session closed for user root Jan 27 21:29:02 volumio volumio[30857]: info: Loading plugin "alsa_controller"... Jan 27 21:29:02 volumio sudo[30905]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 27 21:29:02 volumio sudo[30905]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:29:02 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 21:29:02 volumio volumio[30857]: info: Loading plugin "wizard"... Jan 27 21:29:02 volumio volumio[30857]: info: Loading plugin "networkfs"... Jan 27 21:29:02 volumio volumio[30857]: info: Starting Udev Watcher for removable devices Jan 27 21:29:02 volumio volumio[30857]: info: Ignoring mount for partition: boot Jan 27 21:29:02 volumio volumio[30857]: info: Ignoring mount for partition: volumio Jan 27 21:29:02 volumio volumio[30857]: info: Ignoring mount for partition: volumio_data Jan 27 21:29:02 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 21:29:02 volumio volumio[30857]: info: Loading plugin "volumio_command_line_client"... Jan 27 21:29:02 volumio volumio[30857]: info: Loading plugin "upnp"... Jan 27 21:29:02 volumio volumio[30857]: info: [1769524142545] Starting Upmpd Daemon Jan 27 21:29:02 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 21:29:02 volumio volumio[30857]: info: Loading plugin "my_music"... Jan 27 21:29:02 volumio volumio[30857]: info: Loading plugin "mpd"... Jan 27 21:29:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Jan 27 21:29:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:29:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:29:03 volumio go-librespot[30926]: go-librespot daemon starting... Jan 27 21:29:03 volumio go-librespot[30927]: time="2026-01-27T21:29:03+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:29:03 volumio go-librespot[30927]: time="2026-01-27T21:29:03+07:00" level=debug msg="app state loaded" Jan 27 21:29:03 volumio go-librespot[30927]: time="2026-01-27T21:29:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:29:03 volumio volumio[30857]: info: Loading plugin "upnp_browser"... Jan 27 21:29:03 volumio go-librespot[30927]: time="2026-01-27T21:29:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:29:03 volumio go-librespot[30927]: time="2026-01-27T21:29:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 21:29:03 volumio go-librespot[30927]: time="2026-01-27T21:29:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 21:29:03 volumio go-librespot[30927]: time="2026-01-27T21:29:03+07:00" level=info msg="zeroconf server listening on port 43135" Jan 27 21:29:03 volumio go-librespot[30927]: time="2026-01-27T21:29:03+07:00" level=debug msg="obtained new client token: AACaaRnkd3qMbUFF6kZjSWh03WShKhR8sfMecESK0plxRUwlCmi5a597tjHfvKYRZmhFNbA/qEqitZwVfRxOpl1uHKW/PcQl1uXUcvT+Z/8SXbfTevDdVeHBdVL9rPjKSdWrBi8BQTGHbtnEEeUz3vMrTZ1zGYOANYqatel2R10LOtmNlQh1AihgMIAmhewUhtHGGDUZlAJ0dm4/yUt+4eOtOmcfDHlc4EYJmelY52HrustpMvHZFkhvgTk=" Jan 27 21:29:04 volumio go-librespot[30927]: time="2026-01-27T21:29:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:29:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:29:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:29:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:29:04 volumio go-librespot[30927]: time="2026-01-27T21:29:04+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 21:29:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:29:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:29:05 volumio sudo[30905]: pam_unix(sudo:session): session closed for user root Jan 27 21:29:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:29:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:29:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:29:06 volumio volumio[30857]: info: Starting UPNP Browser Jan 27 21:29:06 volumio volumio[30857]: info: Loading plugin "alarm-clock"... Jan 27 21:29:06 volumio volumio[30857]: info: Loading plugin "airplay_emulation"... Jan 27 21:29:06 volumio volumio[30857]: info: Starting Shairport Sync Jan 27 21:29:06 volumio volumio[30857]: info: Loading plugin "last_100"... Jan 27 21:29:06 volumio volumio[30857]: info: Loading plugin "webradio"... Jan 27 21:29:06 volumio volumio[30857]: info: Loading plugin "i2s_dacs"... Jan 27 21:29:06 volumio volumio[30857]: info: Loading plugin "volumiodiscovery"... Jan 27 21:29:06 volumio volumio[30857]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 21:29:06 volumio volumio[30857]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 21:29:06 volumio volumio[30857]: *** WARNING *** For more information see Jan 27 21:29:06 volumio volumio[30857]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 21:29:06 volumio volumio[30857]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 21:29:06 volumio volumio[30857]: *** WARNING *** For more information see Jan 27 21:29:06 volumio node[30857]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 21:29:06 volumio node[30857]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 21:29:06 volumio node[30857]: *** WARNING *** For more information see Jan 27 21:29:06 volumio node[30857]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 21:29:06 volumio node[30857]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 21:29:06 volumio node[30857]: *** WARNING *** For more information see Jan 27 21:29:06 volumio volumio[30857]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 27 21:29:06 volumio volumio[30857]: info: Discovery: Started advertising with name: Volumio Jan 27 21:29:06 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 21:29:06 volumio volumio[30857]: info: Loading plugin "spop"... Jan 27 21:29:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Jan 27 21:29:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:29:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:29:07 volumio go-librespot[30937]: go-librespot daemon starting... Jan 27 21:29:07 volumio go-librespot[30938]: time="2026-01-27T21:29:07+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:29:07 volumio go-librespot[30938]: time="2026-01-27T21:29:07+07:00" level=debug msg="app state loaded" Jan 27 21:29:07 volumio go-librespot[30938]: time="2026-01-27T21:29:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:29:07 volumio go-librespot[30938]: time="2026-01-27T21:29: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 27 21:29:07 volumio go-librespot[30938]: time="2026-01-27T21:29: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 27 21:29:07 volumio go-librespot[30938]: time="2026-01-27T21:29: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 27 21:29:07 volumio go-librespot[30938]: time="2026-01-27T21:29:07+07:00" level=info msg="zeroconf server listening on port 41655" Jan 27 21:29:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:29:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:29:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:29:08 volumio go-librespot[30938]: time="2026-01-27T21:29:08+07:00" level=debug msg="obtained new client token: AACM8w3niaG7Qv80zK2uDMXzBFZ8/8S41dZ5V8oafJLWtghwzVDXV0kUJ4XglFxZ1YjUh1+JD2i2gnA9SvOrfV/IpjBhH9q1n9E9adurqLK9XcSXMHpr6QcUT+vucIsor2b7NiIpbwfjJODJ9lOJwx+juJQ2u4MfEu0wjQ5i8jF5vAfSoC9dFhD8quI2jlCrpJPpG0TJx7wfmyg+nZa2PhCfHf5WG7SCh+eIPC5VTLX87efIx8Us0h5I" Jan 27 21:29:08 volumio go-librespot[30938]: time="2026-01-27T21:29:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:29:08 volumio go-librespot[30938]: time="2026-01-27T21:29:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 21:29:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:29:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:29:08 volumio volumio[30857]: info: Loading plugin "ytcr"... Jan 27 21:29:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:29:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:29:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:29:11 volumio volumio[30857]: info: Loading plugin "ytmusic"... Jan 27 21:29:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Jan 27 21:29:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:29:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:29:11 volumio go-librespot[30946]: go-librespot daemon starting... Jan 27 21:29:11 volumio go-librespot[30947]: time="2026-01-27T21:29:11+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:29:11 volumio go-librespot[30947]: time="2026-01-27T21:29:11+07:00" level=debug msg="app state loaded" Jan 27 21:29:11 volumio go-librespot[30947]: time="2026-01-27T21:29:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:29:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:29:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:29:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:29:12 volumio go-librespot[30947]: time="2026-01-27T21:29:12+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:29:12 volumio go-librespot[30947]: time="2026-01-27T21:29:12+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 21:29:12 volumio go-librespot[30947]: time="2026-01-27T21:29:12+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 21:29:12 volumio go-librespot[30947]: time="2026-01-27T21:29:12+07:00" level=info msg="zeroconf server listening on port 45267" Jan 27 21:29:12 volumio volumio-remote-updater[628]: [2026-01-27 21:29:12] [connect] Successful connection Jan 27 21:29:12 volumio go-librespot[30947]: time="2026-01-27T21:29:12+07:00" level=debug msg="obtained new client token: AAB3E5KQow/nGbL3yooS9BrcNuxnpgAj85jCoCyQvUmeRlWi9dP+H4j/Er/7DJNO9NnOBEKV5XNxf+2rs7VEwtseovNca/qY76NcNZpndFXt4A7bpvBn9fYOkzO9x/2sHCCGYMv8muriJouVG4yOZQTZDT5L66kEPtpVp3JnZbdEVmFaZ5ytN3QhvtvmdxW3xrSUm0wF+iSEXptBfKD0D+iVxo03LtK8/WfMRpGgSb2u8udCxhyXenr/48w=" Jan 27 21:29:12 volumio volumio[30857]: info: Loading plugin "outputs"... Jan 27 21:29:12 volumio volumio[30857]: info: Loading plugin "albumart"... Jan 27 21:29:12 volumio go-librespot[30947]: time="2026-01-27T21:29:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:29:12 volumio volumio[30857]: info: Plugin example_plugin is not enabled Jan 27 21:29:12 volumio volumio[30857]: info: Loading plugin "inputs"... Jan 27 21:29:12 volumio volumio[30857]: info: Loading plugin "updater_comm"... Jan 27 21:29:12 volumio go-librespot[30947]: time="2026-01-27T21:29:12+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 21:29:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:29:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:29:12 volumio volumio[30857]: info: Plugin mpdemulation is not enabled Jan 27 21:29:12 volumio volumio[30857]: info: Loading plugin "rest_api"... Jan 27 21:29:12 volumio volumio[30857]: info: Loading plugin "websocket"... Jan 27 21:29:12 volumio volumio[30857]: info: Starting Socket.io Server version 1.7.4 Jan 27 21:29:12 volumio volumio[30857]: info: Loading plugin "RoonBridge"... Jan 27 21:29:13 volumio volumio[30857]: info: Applying required configuration parameters for plugin RoonBridge Jan 27 21:29:13 volumio volumio[30857]: info: Loading i18n strings for locale en Jan 27 21:29:13 volumio volumio[30857]: Updating browse sources language Jan 27 21:29:13 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:29:13 volumio volumio[30968]: Forking 3 albumart workers Jan 27 21:29:13 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 21:29:13 volumio volumio[30857]: info: CoreCommandRouter::initPlayerControls Jan 27 21:29:13 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:29:13 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:29:13 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:29:13 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:29:13 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:29:13 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:29:13 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:29:13 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:29:13 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 21:29:13 volumio volumio[30857]: Express server listening on port 3000 Jan 27 21:29:13 volumio volumio[30857]: [Metrics] WebUI: 15s 995.06ms Jan 27 21:29:13 volumio volumio[30857]: info: CoreStateMachine::resetVolumioState Jan 27 21:29:13 volumio volumio[30857]: info: CoreStateMachine::getcurrentVolume Jan 27 21:29:13 volumio volumio[30857]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 21:29:13 volumio sudo[31013]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 21:29:13 volumio volumio[30857]: info: Volumio Network Manager: Network status updated: 1 Jan 27 21:29:13 volumio sudo[31013]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:29:13 volumio sudo[31013]: pam_unix(sudo:session): session closed for user root Jan 27 21:29:13 volumio sudo[31015]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 21:29:13 volumio sudo[31015]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:29:13 volumio sudo[31015]: pam_unix(sudo:session): session closed for user root Jan 27 21:29:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:29:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:29:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:29:14 volumio volumio[30857]: info: VolumeController:: Volume=100 Mute =false Jan 27 21:29:14 volumio volumio[30857]: info: CoreStateMachine::pushState Jan 27 21:29:14 volumio volumio[30857]: info: CorePlayQueue::getTrack 0 Jan 27 21:29:14 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 21:29:14 volumio volumio[30857]: info: CoreCommandRouter::volumioPushState Jan 27 21:29:14 volumio volumio[30857]: info: CoreStateMachine::updateTrackBlock Jan 27 21:29:14 volumio volumio[30857]: info: CorePlayQueue::getTrackBlock Jan 27 21:29:14 volumio volumio[30857]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 21:29:14 volumio volumio-remote-updater[628]: [2026-01-27 21:29:14] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769524152 101 Jan 27 21:29:14 volumio volumio[30857]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 27 21:29:14 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:29:14 volumio volumio[30857]: info: Reloading queue from file Jan 27 21:29:14 volumio volumio[30857]: info: CoreStateMachine::setRepeat null single undefined Jan 27 21:29:14 volumio volumio[30857]: info: CoreStateMachine::pushState Jan 27 21:29:14 volumio volumio[30857]: info: CorePlayQueue::getTrack 0 Jan 27 21:29:14 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 21:29:14 volumio volumio[30857]: info: CoreCommandRouter::volumioPushState Jan 27 21:29:14 volumio volumio[30857]: info: CoreStateMachine::setRandom null Jan 27 21:29:14 volumio volumio[30857]: info: CoreStateMachine::pushState Jan 27 21:29:14 volumio volumio[30857]: info: CorePlayQueue::getTrack 0 Jan 27 21:29:14 volumio volumio[30857]: info: CoreCommandRouter::volumioPushState Jan 27 21:29:14 volumio volumio[30857]: info: Setting Device type: Raspberry PI Jan 27 21:29:14 volumio volumio[30857]: info: Completed loading Core Plugins Jan 27 21:29:14 volumio volumio[30857]: info: Preparing to generate the ALSA configuration file Jan 27 21:29:14 volumio volumio[30857]: info: VolumeController:: Volume=100 Mute =false Jan 27 21:29:14 volumio volumio[30857]: info: CoreStateMachine::pushState Jan 27 21:29:14 volumio volumio[30857]: info: CorePlayQueue::getTrack 0 Jan 27 21:29:14 volumio volumio[30857]: info: CoreCommandRouter::volumioPushState Jan 27 21:29:14 volumio volumio[30857]: info: Asound.conf file unchanged, so no further update is needed Jan 27 21:29:14 volumio volumio[30857]: info: Output device has changed, restarting MPD Jan 27 21:29:14 volumio volumio[30857]: info: Output device has changed, restarting Shairport Sync Jan 27 21:29:14 volumio sudo[31029]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 27 21:29:14 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:29:14 volumio sudo[31029]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:29:14 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:29:14 volumio sudo[31031]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 21:29:14 volumio sudo[31031]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:29:14 volumio sudo[31031]: pam_unix(sudo:session): session closed for user root Jan 27 21:29:14 volumio sudo[31033]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 21:29:14 volumio sudo[31033]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:29:14 volumio volumio[30857]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 21:29:14 volumio sudo[31029]: pam_unix(sudo:session): session closed for user root Jan 27 21:29:14 volumio volumio[30857]: info: ___________ START PLUGINS ___________ Jan 27 21:29:14 volumio volumio[30857]: info: ControllerMpd::onStart: Initializing MPD Jan 27 21:29:14 volumio volumio[30857]: info: Creating MPD Configuration file Jan 27 21:29:14 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 27 21:29:15 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 21:29:15 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 21:29:15 volumio systemd[1]: mpd.service: Consumed 7.470s CPU time. Jan 27 21:29:15 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 21:29:15 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 21:29:15 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 21:29:15 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 21:29:15 volumio volumio[30857]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 21:29:15 volumio sudo[31042]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 21:29:15 volumio volumio[30857]: info: [1769524155171] CoreMusicLibrary::Adding element Media Servers Jan 27 21:29:15 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:29:15 volumio sudo[31042]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:29:15 volumio sudo[31042]: pam_unix(sudo:session): session closed for user root Jan 27 21:29:15 volumio sudo[31044]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 21:29:15 volumio sudo[31044]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:29:15 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 21:29:15 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 21:29:15 volumio volumio[30857]: info: UPNP Browser: Client initialized successfully Jan 27 21:29:15 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:29:15 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:29:15 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 21:29:15 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 21:29:15 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 21:29:15 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 21:29:15 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 21:29:15 volumio volumio[30857]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 21:29:15 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:29:15 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:29:15 volumio volumio[30857]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 21:29:15 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 21:29:15 volumio volumio[30857]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 21:29:15 volumio volumio[30857]: info: [1769524155425] CoreMusicLibrary::Adding element Last_100 Jan 27 21:29:15 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:29:15 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 21:29:15 volumio volumio[30857]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 21:29:15 volumio volumio[30857]: info: [1769524155441] CoreMusicLibrary::Adding element Webradio Jan 27 21:29:15 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:29:15 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 21:29:15 volumio volumio[30857]: info: Initializing BBC Radios Jan 27 21:29:15 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 21:29:15 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:29:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Jan 27 21:29:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:29:15 volumio volumio[30857]: info: Creating Spotify config file Jan 27 21:29:15 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:29:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:29:15 volumio go-librespot[31072]: go-librespot daemon starting... Jan 27 21:29:15 volumio go-librespot[31073]: time="2026-01-27T21:29:15+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:29:15 volumio sudo[31058]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 27 21:29:15 volumio sudo[31058]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 27 21:29:15 volumio sudo[31058]: pam_unix(sudo:session): session closed for user root Jan 27 21:29:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:29:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:29:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:29:16 volumio volumio[30979]: Starting albumart workers Jan 27 21:29:16 volumio go-librespot[31073]: time="2026-01-27T21:29:16+07:00" level=info msg="zeroconf server listening on port 43281" Jan 27 21:29:16 volumio volumio[30978]: Starting albumart workers Jan 27 21:29:17 volumio volumio[30980]: Starting albumart workers Jan 27 21:29:17 volumio volumio[30857]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 21:29:17 volumio volumio[30857]: info: [1769524157276] CoreMusicLibrary::Adding element YouTube Music Jan 27 21:29:17 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:29:17 volumio volumio[30857]: Cannot find translation for source YouTube Music Jan 27 21:29:17 volumio volumio[30857]: info: Volumio Calling Home Jan 27 21:29:17 volumio sudo[31084]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 27 21:29:17 volumio sudo[31084]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:29:17 volumio sudo[31084]: pam_unix(sudo:session): session closed for user root Jan 27 21:29:18 volumio volumio[30857]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 21:29:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:29:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:29:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:29:18 volumio volumio[30857]: info: Discovery: Found device Volumio Jan 27 21:29:18 volumio volumio[30857]: info: CoreCommandRouter::volumioGetState Jan 27 21:29:18 volumio volumio[30857]: info: CorePlayQueue::getTrack 0 Jan 27 21:29:18 volumio volumio[30857]: info: MPD Permissions set Jan 27 21:29:18 volumio volumio[30857]: info: MPD Permissions set Jan 27 21:29:18 volumio volumio[30857]: info: Upmpdcli Daemon Started Jan 27 21:29:18 volumio volumio[30857]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 21:29:18 volumio volumio[30857]: info: Discovery: Found device Volumio Jan 27 21:29:18 volumio volumio[30857]: info: CoreCommandRouter::volumioGetState Jan 27 21:29:18 volumio volumio[30857]: info: CorePlayQueue::getTrack 0 Jan 27 21:29:18 volumio volumio[30857]: info: Volumio called home Jan 27 21:29:18 volumio volumio[30857]: info: Spotify config file written Jan 27 21:29:18 volumio sudo[31096]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 21:29:18 volumio sudo[31096]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:29:18 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 27 21:29:18 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 27 21:29:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:29:18 volumio volumio[30857]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 27 21:29:18 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:29:18 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:29:18 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:29:18 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:29:18 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:29:18 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:29:18 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:29:18 volumio go-librespot[31098]: go-librespot daemon starting... Jan 27 21:29:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:29:18 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:29:18 volumio sudo[31096]: pam_unix(sudo:session): session closed for user root Jan 27 21:29:18 volumio go-librespot[31099]: time="2026-01-27T21:29:18+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:29:18 volumio go-librespot[31099]: time="2026-01-27T21:29:18+07:00" level=debug msg="app state loaded" Jan 27 21:29:18 volumio go-librespot[31099]: time="2026-01-27T21:29:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:29:18 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:29:18 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:29:18 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:29:18 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:29:18 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:29:18 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:29:18 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:29:18 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:29:18 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:29:18 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:29:19 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:29:19 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:29:19 volumio volumio[30857]: info: No need to fix Spotify hosts Jan 27 21:29:19 volumio go-librespot[31099]: time="2026-01-27T21:29:19+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:29:19 volumio go-librespot[31099]: time="2026-01-27T21:29:19+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 21:29:19 volumio go-librespot[31099]: time="2026-01-27T21:29:19+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 21:29:19 volumio go-librespot[31099]: time="2026-01-27T21:29:19+07:00" level=info msg="zeroconf server listening on port 42301" Jan 27 21:29:19 volumio volumio[30857]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 21:29:19 volumio volumio[30857]: SPOTIFY: BQBXaneAs3wRKqYLHFWQUbLhbok2xV6xlf2eyunxmDjF5verVtIApgvLf6MauI18gh58FX2yprX-Pc9t55bysWegbLdrAPMWZHT2RTFi7X2VIxqW7DRrRAHQpE6iXVnWE34qbXkY7pz9fp3u7742D12fwmvHdnXwq-8qrAlg88KFxZ8L7_lws3bpRnUhY8yw1P-jBqrcdrwj1ZenYCN6FlCYZMBo5KO64IUwNrEUf85-w8pa2L6VWoUItQmgn-JRghJnt8lvbQiXIfkNndwAj9uTUN_BFadBImDW5r-W_F9aER6G8W-HEFFc Jan 27 21:29:19 volumio volumio[30857]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 21:29:19 volumio volumio[30857]: info: New Spotify access token = BQBXaneAs3wRKqYLHFWQUbLhbok2xV6xlf2eyunxmDjF5verVtIApgvLf6MauI18gh58FX2yprX-Pc9t55bysWegbLdrAPMWZHT2RTFi7X2VIxqW7DRrRAHQpE6iXVnWE34qbXkY7pz9fp3u7742D12fwmvHdnXwq-8qrAlg88KFxZ8L7_lws3bpRnUhY8yw1P-jBqrcdrwj1ZenYCN6FlCYZMBo5KO64IUwNrEUf85-w8pa2L6VWoUItQmgn-JRghJnt8lvbQiXIfkNndwAj9uTUN_BFadBImDW5r-W_F9aER6G8W-HEFFc Jan 27 21:29:19 volumio volumio[30857]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 27 21:29:19 volumio volumio[30857]: info: Starting Shairport Sync Jan 27 21:29:19 volumio go-librespot[31099]: time="2026-01-27T21:29:19+07:00" level=debug msg="obtained new client token: AAA5h5dOFWOUP8Z/LvU+VRmDLUI4ZZM4TvziEyCZg842J5qJoDw/509RUw4Qo/XKxhlddGVpaT/9oVaVyHTj+NoKenkisdYmLk7xTRPz5Z0XOfdZlVrXqut78hY1iad2ZUsi8xziWLBAKTE3fDoaIrKQpFDk9eRMAHEhTASydsDI5P+AgFMNs1cVPsxylhMi7rgrf4ZpjsyGLJOcJovy8BP0NEyDeHOI6cS9Ozxr78uBCNnqzRmtBKRwiIo=" Jan 27 21:29:19 volumio volumio[30857]: info: Starting Shairport Sync Jan 27 21:29:19 volumio volumio[30857]: info: Starting Shairport Sync Jan 27 21:29:19 volumio go-librespot[31099]: time="2026-01-27T21:29:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:29:19 volumio sudo[31129]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 21:29:19 volumio sudo[31129]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:29:19 volumio sudo[31133]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 21:29:19 volumio sudo[31133]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:29:19 volumio sudo[31131]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 21:29:19 volumio sudo[31131]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:29:20 volumio go-librespot[31099]: time="2026-01-27T21:29:20+07:00" level=debug msg="completed keyexchange" Jan 27 21:29:20 volumio go-librespot[31099]: time="2026-01-27T21:29:20+07:00" level=debug msg="completed challenge" Jan 27 21:29:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:29:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:29:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:29:20 volumio go-librespot[31099]: time="2026-01-27T21:29:20+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 21:29:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:29:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:29:20 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 21:29:20 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 21:29:20 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 21:29:20 volumio systemd[1]: shairport-sync.service: Consumed 2.369s CPU time. Jan 27 21:29:20 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 21:29:20 volumio sudo[31131]: pam_unix(sudo:session): session closed for user root Jan 27 21:29:20 volumio sudo[31129]: pam_unix(sudo:session): session closed for user root Jan 27 21:29:20 volumio sudo[31133]: pam_unix(sudo:session): session closed for user root Jan 27 21:29:20 volumio volumio[30857]: info: Shairport-Sync Started Jan 27 21:29:20 volumio volumio[30857]: Error adding Membership: Error: addMembership EINVAL Jan 27 21:29:20 volumio volumio[30857]: info: Shairport-Sync Started Jan 27 21:29:20 volumio volumio[30857]: info: Shairport-Sync Started Jan 27 21:29:20 volumio volumio[30857]: info: CoreCommandRouter::volumioGetState Jan 27 21:29:20 volumio volumio[30857]: info: CorePlayQueue::getTrack 0 Jan 27 21:29:20 volumio volumio[30857]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Jan 27 21:29:20 volumio volumio[30857]: info: Spotify Successfully logged in Jan 27 21:29:20 volumio volumio[30857]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 21:29:20 volumio volumio[30857]: info: [1769524160732] CoreMusicLibrary::Adding element Spotify Jan 27 21:29:20 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:29:20 volumio volumio[30857]: Cannot find translation for source YouTube Music Jan 27 21:29:20 volumio volumio[30857]: Cannot find translation for source Spotify Jan 27 21:29:21 volumio volumio[30857]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 27 21:29:21 volumio volumio[30857]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 21:29:21 volumio volumio[30857]: info: VolumeController:: Volume=100 Mute =false Jan 27 21:29:21 volumio volumio[30857]: info: CoreCommandRouter::volumioGetState Jan 27 21:29:21 volumio volumio[30857]: info: CorePlayQueue::getTrack 0 Jan 27 21:29:21 volumio volumio[30857]: info: CoreStateMachine::pushState Jan 27 21:29:21 volumio volumio[30857]: info: CorePlayQueue::getTrack 0 Jan 27 21:29:21 volumio volumio[30857]: info: CoreCommandRouter::volumioPushState Jan 27 21:29:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:29:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:29:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:29:22 volumio volumio[30857]: info: go-librespot daemon successfully initialized Jan 27 21:29:23 volumio mpd[31080]: 2026-01-27T21:29:23 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 27 21:29:23 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 27 21:29:23 volumio sudo[31033]: pam_unix(sudo:session): session closed for user root Jan 27 21:29:23 volumio sudo[31044]: pam_unix(sudo:session): session closed for user root Jan 27 21:29:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 27 21:29:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:29:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:29:23 volumio volumio[30857]: error: MPD error: The expression evaluated to a falsy value: Jan 27 21:29:23 volumio volumio[30857]: assert.ok(self.idling) Jan 27 21:29:23 volumio volumio[30857]: error: The expression evaluated to a falsy value: Jan 27 21:29:23 volumio volumio[30857]: assert.ok(self.idling) Jan 27 21:29:23 volumio go-librespot[31173]: go-librespot daemon starting... Jan 27 21:29:23 volumio volumio[30857]: error: updateQueue error: null Jan 27 21:29:23 volumio volumio[30857]: info: MPD running with PID31080 Jan 27 21:29:23 volumio volumio[30857]: ,establishing connection Jan 27 21:29:23 volumio go-librespot[31174]: time="2026-01-27T21:29:23+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:29:23 volumio go-librespot[31174]: time="2026-01-27T21:29:23+07:00" level=debug msg="app state loaded" Jan 27 21:29:23 volumio go-librespot[31174]: time="2026-01-27T21:29:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:29:23 volumio volumio[30857]: info: Completed starting Core Plugins Jan 27 21:29:23 volumio volumio[30857]: info: ------------------------------------------- Jan 27 21:29:23 volumio volumio[30857]: info: ----- MyVolumio plugins startup ---- Jan 27 21:29:23 volumio volumio[30857]: info: ------------------------------------------- Jan 27 21:29:23 volumio volumio[30857]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 27 21:29:23 volumio volumio[30857]: error: updateQueue error: null Jan 27 21:29:23 volumio go-librespot[31174]: time="2026-01-27T21:29:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 21:29:23 volumio go-librespot[31174]: time="2026-01-27T21:29:23+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 27 21:29:23 volumio go-librespot[31174]: time="2026-01-27T21:29:23+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 27 21:29:23 volumio go-librespot[31174]: time="2026-01-27T21:29:23+07:00" level=info msg="zeroconf server listening on port 43913" Jan 27 21:29:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:29:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:29:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:29:24 volumio go-librespot[31174]: time="2026-01-27T21:29:24+07:00" level=debug msg="obtained new client token: AAAKH1BDfeNYTY2caD3BN3XAdlhZDbdBMkg7xLXLvY1+5rRqU0sTv/OX6yPSy55rhbtD/NRXHB4DA38W+fAfWHoSDPh8Oehz24RQjcMr9Fx6H70TenmXb//PsObRvCOuqZtVJwsc4njkUQH9KpOWUKMDBRJyci6FUrXGJ4uszC1/pA5cFaZo82TqKz6ItPyychRIm57iJWKI+b41gqOpgfe2ofjhr3e0Euq1lLATiAgvmW7p6G8/T/0R" Jan 27 21:29:24 volumio go-librespot[31174]: time="2026-01-27T21:29:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:29:24 volumio go-librespot[31174]: time="2026-01-27T21:29: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 27 21:29:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:29:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:29:25 volumio volumio[30857]: info: Initializing connection to go-librespot Websocket Jan 27 21:29:25 volumio volumio[30857]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:29:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:29:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:29:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:29:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 27 21:29:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:29:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:29:27 volumio go-librespot[31183]: go-librespot daemon starting... Jan 27 21:29:27 volumio go-librespot[31184]: time="2026-01-27T21:29:27+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:29:27 volumio go-librespot[31184]: time="2026-01-27T21:29:27+07:00" level=debug msg="app state loaded" Jan 27 21:29:27 volumio go-librespot[31184]: time="2026-01-27T21:29:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:29:28 volumio go-librespot[31184]: time="2026-01-27T21:29:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:29:28 volumio go-librespot[31184]: time="2026-01-27T21:29:28+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 21:29:28 volumio go-librespot[31184]: time="2026-01-27T21:29:28+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 21:29:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:29:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:29:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:29:28 volumio go-librespot[31184]: time="2026-01-27T21:29:28+07:00" level=info msg="zeroconf server listening on port 45285" Jan 27 21:29:28 volumio volumio[30857]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 27 21:29:28 volumio go-librespot[31184]: time="2026-01-27T21:29:28+07:00" level=debug msg="obtained new client token: AAC7V05sOzt/nndzUL8M0TlqZ1QOfCKhRVLnjPoQNdhi1II8MNEfttAXkxjYLmhBOS4xQG3VsCApx5XsAX4s025Dztkrr3NAC+23iRoAWG+UmBng0vEXbNlIdlThZkOi1VwVNqvmxaS5q/9WRboqq2WimKt29ODUrbnFRD7bP01NLfue7Vkc6eaEnZuFKi35h+xuTW0juL8lyRfoLx8xWbziDn4ZVvkqsMIrwvmnZuwuqAw3ppmQenqS0rI=" Jan 27 21:29:28 volumio go-librespot[31184]: time="2026-01-27T21:29:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:29:28 volumio go-librespot[31184]: time="2026-01-27T21:29:28+07:00" level=debug msg="completed keyexchange" Jan 27 21:29:28 volumio go-librespot[31184]: time="2026-01-27T21:29:28+07:00" level=debug msg="completed challenge" Jan 27 21:29:28 volumio go-librespot[31184]: time="2026-01-27T21:29:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 21:29:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:29:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:29:28 volumio volumio[30857]: info: Initializing connection to go-librespot Websocket Jan 27 21:29:28 volumio volumio[30857]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:29:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:29:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:29:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:29:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 27 21:29:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:29:31 volumio volumio[30857]: info: Initializing connection to go-librespot Websocket Jan 27 21:29:31 volumio volumio[30857]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:29:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:29:31 volumio go-librespot[31191]: go-librespot daemon starting... Jan 27 21:29:31 volumio go-librespot[31192]: time="2026-01-27T21:29:31+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:29:31 volumio go-librespot[31192]: time="2026-01-27T21:29:31+07:00" level=debug msg="app state loaded" Jan 27 21:29:31 volumio go-librespot[31192]: time="2026-01-27T21:29:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:29:32 volumio volumio[30857]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 27 21:29:32 volumio volumio[30857]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 27 21:29:32 volumio volumio[30857]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 27 21:29:32 volumio volumio[30857]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 27 21:29:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:29:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:29:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:29:32 volumio volumio[30857]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 27 21:29:32 volumio volumio[30857]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 27 21:29:32 volumio volumio[30857]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 27 21:29:32 volumio volumio[30857]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 27 21:29:32 volumio volumio[30857]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 27 21:29:32 volumio volumio[30857]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 27 21:29:32 volumio volumio[30857]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 27 21:29:32 volumio volumio[30857]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 27 21:29:32 volumio volumio[30857]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 27 21:29:32 volumio volumio[30857]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 27 21:29:32 volumio volumio[30857]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 27 21:29:32 volumio volumio[30857]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 27 21:29:32 volumio volumio[30857]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 27 21:29:32 volumio volumio[30857]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 27 21:29:32 volumio volumio[30857]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 27 21:29:32 volumio volumio[30857]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 27 21:29:32 volumio volumio[30857]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 27 21:29:32 volumio volumio[30857]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 27 21:29:32 volumio volumio[30857]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 27 21:29:32 volumio volumio[30857]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 27 21:29:32 volumio volumio[30857]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 27 21:29:32 volumio volumio[30857]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 27 21:29:32 volumio volumio[30857]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 27 21:29:32 volumio volumio[30857]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 27 21:29:32 volumio volumio[30857]: info: Adding plugin bluetooth to MyMusic Plugins Jan 27 21:29:32 volumio volumio[30857]: info: Adding plugin multiroom to MyMusic Plugins Jan 27 21:29:32 volumio volumio[30857]: info: Adding plugin metavolumio to MyMusic Plugins Jan 27 21:29:32 volumio volumio[30857]: info: Adding plugin cd_controller to MyMusic Plugins Jan 27 21:29:32 volumio volumio[30857]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 27 21:29:32 volumio volumio[30857]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 27 21:29:32 volumio volumio[30857]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 27 21:29:32 volumio volumio[30857]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 27 21:29:32 volumio go-librespot[31192]: time="2026-01-27T21:29:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 21:29:32 volumio go-librespot[31192]: time="2026-01-27T21:29:32+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 27 21:29:32 volumio go-librespot[31192]: time="2026-01-27T21:29:32+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 27 21:29:32 volumio go-librespot[31192]: time="2026-01-27T21:29:32+07:00" level=info msg="zeroconf server listening on port 34109" Jan 27 21:29:32 volumio go-librespot[31192]: time="2026-01-27T21:29:32+07:00" level=debug msg="obtained new client token: AADuHJlVlwqOD0lqqkqXC9gHa4QjO9+tE0MBBtOkRDT6jV2WduQRPOAI8gQzPYDnJORAKu9yoCrHG3KKGxNvo6MjcA310s6X+nRS+4ZKbJOajJDzAQG1eabnz5BpaksiTwFRsJGfVZp7os/9bKA9Lcs2TIeGZ11nmN+HtIX1XloY99uNPYKPweT7AaUN0pcL1nnrcSoJL9Q8mgLsnEc4e+rRgsBf95QlQ+dzZFMujdb34RmXKmBQesF+jxI=" Jan 27 21:29:32 volumio go-librespot[31192]: time="2026-01-27T21:29:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:29:32 volumio go-librespot[31192]: time="2026-01-27T21:29:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 21:29:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:29:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:29:33 volumio volumio[30857]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 27 21:29:33 volumio volumio[30857]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 27 21:29:33 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:29:33 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:29:34 volumio volumio[30857]: info: Starting MyVolumio Remote Streaming Endpoints Jan 27 21:29:34 volumio volumio[30857]: info: MyVolumio login type: Token Jan 27 21:29:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:29:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:29:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:29:34 volumio volumio[30857]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 27 21:29:34 volumio volumio[30857]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 27 21:29:35 volumio volumio[30857]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 27 21:29:35 volumio volumio[30857]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 27 21:29:35 volumio volumio[30857]: info: Streaming services startup Jan 27 21:29:35 volumio volumio[30857]: info: Starting Streaming Daemon Jan 27 21:29:35 volumio sudo[31214]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 21:29:35 volumio sudo[31214]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:29:35 volumio volumio[30857]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 27 21:29:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 27 21:29:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:29:36 volumio volumio[30857]: info: Initializing connection to go-librespot Websocket Jan 27 21:29:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:29:36 volumio go-librespot[31220]: go-librespot daemon starting... Jan 27 21:29:36 volumio volumio[30857]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:29:36 volumio sudo[31214]: pam_unix(sudo:session): session closed for user root Jan 27 21:29:36 volumio volumio[30857]: error: Cannot start Volumio Streaming Daemon Jan 27 21:29:36 volumio volumio[30857]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 21:29:36 volumio volumio[30857]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 21:29:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:29:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:29:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:29:36 volumio go-librespot[31222]: time="2026-01-27T21:29:36+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:29:36 volumio go-librespot[31222]: time="2026-01-27T21:29:36+07:00" level=debug msg="app state loaded" Jan 27 21:29:36 volumio go-librespot[31222]: time="2026-01-27T21:29:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:29:36 volumio go-librespot[31222]: time="2026-01-27T21:29:36+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 21:29:36 volumio go-librespot[31222]: time="2026-01-27T21:29:36+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 27 21:29:36 volumio go-librespot[31222]: time="2026-01-27T21:29:36+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 27 21:29:36 volumio go-librespot[31222]: time="2026-01-27T21:29:36+07:00" level=info msg="zeroconf server listening on port 37467" Jan 27 21:29:36 volumio go-librespot[31222]: time="2026-01-27T21:29:36+07:00" level=debug msg="obtained new client token: AADu74cfMCROLVMgW9HgOG4zk1NKi8aY1yHuPkPqRV3Vx4XXgFnA5uHobw0Rc5PEIwMCJfF4vyq+Qp7qaZmwZ4Miq+vDhOalJ13+PwhI/PuWa59NTbD4Oq0WPPbwR+H35+eQWKompTgnGM48eCmUfUC7k86TEqV3gwgpdpTs6TDl3l54TzxFBJ2avOkjIYJZJeODiIsYIMzwGvgIcbF/GWnfjRgVf0GKJcw+0mWRhwCwxbjdEaGq6/+4Q3Y=" Jan 27 21:29:36 volumio volumio[30857]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 27 21:29:36 volumio go-librespot[31222]: time="2026-01-27T21:29:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:29:37 volumio go-librespot[31222]: time="2026-01-27T21:29:37+07:00" level=debug msg="completed keyexchange" Jan 27 21:29:37 volumio go-librespot[31222]: time="2026-01-27T21:29:37+07:00" level=debug msg="completed challenge" Jan 27 21:29:37 volumio go-librespot[31222]: time="2026-01-27T21:29:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 21:29:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:29:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:29:37 volumio volumio[30857]: info: MyVolumio token set successfully Jan 27 21:29:37 volumio volumio[30857]: info: MYVOLUMIO: Adding device Jan 27 21:29:37 volumio volumio[30857]: info: MYVOLUMIO: Evaluating Server Jan 27 21:29:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:29:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:29:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:29:38 volumio volumio[30857]: info: MyVolumio status changed Jan 27 21:29:38 volumio volumio[30857]: info: Streaming services startup Jan 27 21:29:38 volumio volumio[30857]: info: Starting Streaming Daemon Jan 27 21:29:38 volumio volumio[30857]: info: Removing browser output: myVolumio user plan is not superstar Jan 27 21:29:38 volumio volumio[30857]: info: Removing audio output: Jan 27 21:29:38 volumio volumio[30857]: info: Stoppping Tunnel 1 Jan 27 21:29:38 volumio sudo[31255]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 21:29:38 volumio sudo[31255]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:29:38 volumio sudo[31255]: pam_unix(sudo:session): session closed for user root Jan 27 21:29:38 volumio volumio[30857]: error: Cannot start Volumio Streaming Daemon Jan 27 21:29:38 volumio volumio[30857]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 21:29:38 volumio volumio[30857]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 21:29:38 volumio sudo[31258]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 27 21:29:38 volumio sudo[31258]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:29:38 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 21:29:38 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 21:29:38 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 21:29:38 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 21:29:38 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 21:29:38 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 21:29:38 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 21:29:38 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 21:29:38 volumio sudo[31258]: pam_unix(sudo:session): session closed for user root Jan 27 21:29:38 volumio volumio[30857]: info: Remote SSH Stopped Jan 27 21:29:39 volumio volumio[30857]: info: Setting Geolocation for MyVolumio to as1 Jan 27 21:29:39 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:29:39 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:29:39 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:29:39 volumio volumio[30857]: info: Initializing connection to go-librespot Websocket Jan 27 21:29:39 volumio volumio[30857]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:29:39 volumio volumio[30857]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 27 21:29:40 volumio volumio[30857]: info: Updating MyVolumio device info Jan 27 21:29:40 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:29:40 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:29:40 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:29:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:29:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:29:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:29:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 27 21:29:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:29:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:29:40 volumio go-librespot[31260]: go-librespot daemon starting... Jan 27 21:29:40 volumio go-librespot[31261]: time="2026-01-27T21:29:40+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:29:40 volumio go-librespot[31261]: time="2026-01-27T21:29:40+07:00" level=debug msg="app state loaded" Jan 27 21:29:40 volumio go-librespot[31261]: time="2026-01-27T21:29:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:29:40 volumio volumio[30857]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jan 27 21:29:40 volumio go-librespot[31261]: time="2026-01-27T21:29:40+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:29:40 volumio go-librespot[31261]: time="2026-01-27T21:29:40+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 21:29:40 volumio go-librespot[31261]: time="2026-01-27T21:29:40+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 21:29:40 volumio go-librespot[31261]: time="2026-01-27T21:29:40+07:00" level=info msg="zeroconf server listening on port 41467" Jan 27 21:29:41 volumio go-librespot[31261]: time="2026-01-27T21:29:41+07:00" level=debug msg="obtained new client token: AAA72VNa/EUhjtEl8PL8WHaw0mxHxHx9ntRxREZ8vrodnh13Bv6iz2e2/HjMerzbb3RTMaIwwezdO4ZW9LtG5XusR9s6aEv9s72dPNgLFHf1y1uy9oJg056D5JdTFk8uUv3VxY3515TYOXUe0azAXIGhGzk3ECq2Zo+ZIr4iiVaoj36Jtqrtkn6U6FJVUm7eY7VTN21H4aJ5BMDz8daLZDJtPlqh1i2FJMvqfg7V1saGftKO4H70/Y3Z" Jan 27 21:29:41 volumio go-librespot[31261]: time="2026-01-27T21:29:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:29:41 volumio go-librespot[31261]: time="2026-01-27T21:29:41+07:00" level=debug msg="completed keyexchange" Jan 27 21:29:41 volumio go-librespot[31261]: time="2026-01-27T21:29:41+07:00" level=debug msg="completed challenge" Jan 27 21:29:41 volumio go-librespot[31261]: time="2026-01-27T21:29: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 27 21:29:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:29:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:29:42 volumio volumio[30857]: info: Initializing connection to go-librespot Websocket Jan 27 21:29:42 volumio volumio[30857]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:29:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:29:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:29:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:29:43 volumio volumio[30857]: info: MYVOLUMIO: Adding device Jan 27 21:29:43 volumio volumio[30857]: info: MYVOLUMIO: Evaluating Server Jan 27 21:29:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:29:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:29:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:29:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 27 21:29:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:29:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:29:44 volumio go-librespot[31300]: go-librespot daemon starting... Jan 27 21:29:44 volumio go-librespot[31301]: time="2026-01-27T21:29:44+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:29:44 volumio go-librespot[31301]: time="2026-01-27T21:29:44+07:00" level=debug msg="app state loaded" Jan 27 21:29:44 volumio go-librespot[31301]: time="2026-01-27T21:29:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:29:45 volumio volumio[30857]: info: Initializing connection to go-librespot Websocket Jan 27 21:29:45 volumio go-librespot[31301]: time="2026-01-27T21:29:45+07:00" level=debug msg="new websocket client" Jan 27 21:29:45 volumio volumio[30857]: info: Connection to go-librespot Websocket established Jan 27 21:29:45 volumio go-librespot[31301]: time="2026-01-27T21:29:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:29:45 volumio go-librespot[31301]: time="2026-01-27T21:29:45+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 21:29:45 volumio go-librespot[31301]: time="2026-01-27T21:29:45+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 21:29:45 volumio go-librespot[31301]: time="2026-01-27T21:29:45+07:00" level=info msg="zeroconf server listening on port 35467" Jan 27 21:29:45 volumio go-librespot[31301]: time="2026-01-27T21:29:45+07:00" level=debug msg="obtained new client token: AABZZiEcHXMEqZEFkLQXNutosRMkQnGD4MUYLOnkh9soo6KNH5UexjILwoZazpKmyjKq8M0Ya0cjWreXdGu1cK8Vy9R7uyrOiL1v92zCsN4T62P3+EFsxVQUVS/lAyuSSDpWjJb8gGoLJHaZrmFG+rV502ksnOZDDvGha8lqsYL5BRlVmz1VbGwN56/tPx61QpMpsv71wYJVM5qZUH7RJdgwstEJPN9yj+hGifVzoJ+LbOQoMaicjBnICvU=" Jan 27 21:29:45 volumio go-librespot[31301]: time="2026-01-27T21:29:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:29:45 volumio go-librespot[31301]: time="2026-01-27T21:29:45+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 21:29:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:29:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:29:45 volumio volumio[30857]: info: Connection to go-librespot Websocket closed Jan 27 21:29:45 volumio volumio[30857]: info: Setting Geolocation for MyVolumio to as1 Jan 27 21:29:45 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:29:45 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:29:45 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:29:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:29:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:29:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:29:46 volumio volumio[30857]: info: Updating MyVolumio device info Jan 27 21:29:46 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:29:46 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:29:46 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:29:47 volumio volumio[30857]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 27 21:29:47 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 21:29:47 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:29:47 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 27 21:29:47 volumio volumio[30857]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jan 27 21:29:47 volumio volumio-remote-updater[628]: Test mode disabled Jan 27 21:29:47 volumio volumio-remote-updater[628]: Alpha mode disabled Jan 27 21:29:47 volumio volumio-remote-updater[628]: Alpha legacy test mode disabled Jan 27 21:29:47 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Jan 27 21:29:48 volumio volumio[30857]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Jan 27 21:29:48 volumio volumio[30857]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Jan 27 21:29:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:29:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:29:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:29:48 volumio volumio[30857]: info: Getting Spotify volume Jan 27 21:29:48 volumio volumio[30857]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 21:29:48 volumio volumio[30857]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:29:48 volumio volumio[30857]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 27 21:29:48 volumio volumio[30857]: errno: -111, Jan 27 21:29:48 volumio volumio[30857]: code: 'ECONNREFUSED', Jan 27 21:29:48 volumio volumio[30857]: syscall: 'connect', Jan 27 21:29:48 volumio volumio[30857]: address: '127.0.0.1', Jan 27 21:29:48 volumio volumio[30857]: port: 9879, Jan 27 21:29:48 volumio volumio[30857]: response: undefined Jan 27 21:29:48 volumio volumio[30857]: } Jan 27 21:29:48 volumio volumio[30857]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 21:29:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 27 21:29:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:29:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:29:48 volumio go-librespot[31324]: go-librespot daemon starting... Jan 27 21:29:48 volumio go-librespot[31325]: time="2026-01-27T21:29:48+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:29:48 volumio go-librespot[31325]: time="2026-01-27T21:29:48+07:00" level=debug msg="app state loaded" Jan 27 21:29:48 volumio go-librespot[31325]: time="2026-01-27T21:29:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:29:49 volumio go-librespot[31325]: time="2026-01-27T21:29:49+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:29:49 volumio go-librespot[31325]: time="2026-01-27T21:29:49+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 21:29:49 volumio go-librespot[31325]: time="2026-01-27T21:29:49+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 21:29:49 volumio go-librespot[31325]: time="2026-01-27T21:29:49+07:00" level=info msg="zeroconf server listening on port 33037" Jan 27 21:29:49 volumio sudo[31334]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 21:28' Jan 27 21:29:49 volumio sudo[31334]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:29:49 volumio go-librespot[31325]: time="2026-01-27T21:29:49+07:00" level=debug msg="obtained new client token: AAB/SUsHUByY8Yn2b/rzDObwZmc0wIiOJIJIzFAH7vLzzNIBf3AoO3kAh7hpIpiWLtewzq+677Z/g1Uyte3uHYUM2R29+kRle/CSIKrhMTQLk8FlLRSLKluIDU1mewIaa2bNVbb1+a7ikFNwFHWd3Fimi7R+r8l3FWzRyhAUi2GE8DZis5H71bs1xQa2erqVUe4pQMoEly1fteF+UXa35UyAk3TgFWvZ//AAn/iiw5Uld7bchdL8APdQi8E=" Jan 27 21:29:49 volumio go-librespot[31325]: time="2026-01-27T21:29:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:29:49 volumio go-librespot[31325]: time="2026-01-27T21:29:49+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 21:29:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:29:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"