Jan 27 21:03:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:03:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:03:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:03:00 volumio volumio[16295]: info: Initializing connection to go-librespot Websocket Jan 27 21:03:00 volumio volumio[16295]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:03:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:03:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:03:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:03:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 27 21:03:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:03:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:03:02 volumio go-librespot[16623]: go-librespot daemon starting... Jan 27 21:03:02 volumio go-librespot[16624]: time="2026-01-27T21:03:02+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:03:02 volumio go-librespot[16624]: time="2026-01-27T21:03:02+07:00" level=debug msg="app state loaded" Jan 27 21:03:02 volumio go-librespot[16624]: time="2026-01-27T21:03:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:03:03 volumio volumio[16295]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 27 21:03:03 volumio go-librespot[16624]: time="2026-01-27T21:03:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:03:03 volumio go-librespot[16624]: time="2026-01-27T21:03:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 21:03:03 volumio go-librespot[16624]: time="2026-01-27T21:03:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 21:03:03 volumio go-librespot[16624]: time="2026-01-27T21:03:03+07:00" level=info msg="zeroconf server listening on port 34133" Jan 27 21:03:03 volumio go-librespot[16624]: time="2026-01-27T21:03:03+07:00" level=debug msg="obtained new client token: AAACc1bYN+hYnd0UiAUikPBh+ZL6d+G7TW3X0yYqnf36jCRbuGtqPZpoXe6TiiLOcXjgbyLDx/iJOM/RXRV/Sr5ZYrJjfl3aP9kZhpEwfbvnz1t+ZsACjOOqjacLCPBKYRpQhCnFvBGYVNIlLegh3DvFKmAnHFVzsdlcJ+ED3jIOUUti4fuu3HKhGU2LTGVlZw+KPF1gNg8SUz+e9wBB1riCveqaT0a+EsOf+Map7dd61rkFpQIKHQIMmu4=" Jan 27 21:03:03 volumio go-librespot[16624]: time="2026-01-27T21:03:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:03:03 volumio go-librespot[16624]: time="2026-01-27T21:03:03+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:03:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:03:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:03:03 volumio volumio[16295]: info: Initializing connection to go-librespot Websocket Jan 27 21:03:03 volumio volumio[16295]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:03:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:03:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:03:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:03:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:03:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:03:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:03:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 27 21:03:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:03:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:03:06 volumio go-librespot[16631]: go-librespot daemon starting... Jan 27 21:03:06 volumio go-librespot[16632]: time="2026-01-27T21:03:06+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:03:06 volumio go-librespot[16632]: time="2026-01-27T21:03:06+07:00" level=debug msg="app state loaded" Jan 27 21:03:06 volumio go-librespot[16632]: time="2026-01-27T21:03:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:03:06 volumio volumio[16295]: info: Initializing connection to go-librespot Websocket Jan 27 21:03:06 volumio go-librespot[16632]: time="2026-01-27T21:03:06+07:00" level=debug msg="new websocket client" Jan 27 21:03:06 volumio volumio[16295]: info: Connection to go-librespot Websocket established Jan 27 21:03:07 volumio volumio[16295]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 27 21:03:07 volumio volumio[16295]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 27 21:03:07 volumio volumio[16295]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 27 21:03:07 volumio volumio[16295]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 27 21:03:07 volumio volumio[16295]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 27 21:03:07 volumio volumio[16295]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 27 21:03:07 volumio volumio[16295]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 27 21:03:07 volumio volumio[16295]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 27 21:03:07 volumio volumio[16295]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 27 21:03:07 volumio volumio[16295]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 27 21:03:07 volumio volumio[16295]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 27 21:03:07 volumio volumio[16295]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 27 21:03:07 volumio volumio[16295]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 27 21:03:07 volumio volumio[16295]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 27 21:03:07 volumio volumio[16295]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 27 21:03:07 volumio volumio[16295]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 27 21:03:07 volumio volumio[16295]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 27 21:03:07 volumio volumio[16295]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 27 21:03:07 volumio volumio[16295]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 27 21:03:07 volumio volumio[16295]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 27 21:03:07 volumio volumio[16295]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 27 21:03:07 volumio volumio[16295]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 27 21:03:07 volumio volumio[16295]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 27 21:03:07 volumio volumio[16295]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 27 21:03:07 volumio volumio[16295]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 27 21:03:07 volumio volumio[16295]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 27 21:03:07 volumio volumio[16295]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 27 21:03:07 volumio volumio[16295]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 27 21:03:07 volumio volumio[16295]: info: Adding plugin bluetooth to MyMusic Plugins Jan 27 21:03:07 volumio volumio[16295]: info: Adding plugin multiroom to MyMusic Plugins Jan 27 21:03:07 volumio volumio[16295]: info: Adding plugin metavolumio to MyMusic Plugins Jan 27 21:03:07 volumio volumio[16295]: info: Adding plugin cd_controller to MyMusic Plugins Jan 27 21:03:07 volumio volumio[16295]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 27 21:03:07 volumio volumio[16295]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 27 21:03:07 volumio volumio[16295]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 27 21:03:07 volumio volumio[16295]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 27 21:03:07 volumio go-librespot[16632]: time="2026-01-27T21:03:07+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:03:07 volumio go-librespot[16632]: time="2026-01-27T21:03:07+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 21:03:07 volumio go-librespot[16632]: time="2026-01-27T21:03:07+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 21:03:07 volumio go-librespot[16632]: time="2026-01-27T21:03:07+07:00" level=info msg="zeroconf server listening on port 44659" Jan 27 21:03:07 volumio go-librespot[16632]: time="2026-01-27T21:03:07+07:00" level=debug msg="obtained new client token: AADB6OHWtTXqXKJsDnT3rJMCdylvBChgQr26y9D1nPn+Kw4gveSwIORMCUZZGxMnGPfOOz7Bwh4899zvm7HLDpPxVCDH/d5mzk7Qmfga/GRonljoCGtldX5uFE7joVUlG/vyy1G3i8FwuyR2UmSeUv69Um+gXoJvgrLWZJOIqAqafHjN6rYRioDsGh163XMuMIXwTpZdg8OLx8ly94BlvQTi3YiesOOEYe5qm2WV/ntwuTlB3l2RQooIEuM=" Jan 27 21:03:07 volumio go-librespot[16632]: time="2026-01-27T21:03:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:03:07 volumio go-librespot[16632]: time="2026-01-27T21:03:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 21:03:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:03:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:03:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:03:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:03:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:03:09 volumio volumio[16295]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 27 21:03:09 volumio volumio[16295]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 27 21:03:09 volumio volumio[16295]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:03:09 volumio volumio[16295]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:03:09 volumio volumio[16295]: info: Starting MyVolumio Remote Streaming Endpoints Jan 27 21:03:09 volumio volumio[16295]: info: MyVolumio login type: Token Jan 27 21:03:09 volumio volumio[16295]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 27 21:03:09 volumio volumio[16295]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 27 21:03:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:03:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:03:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:03:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 27 21:03:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:03:11 volumio volumio[16295]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 27 21:03:11 volumio volumio[16295]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 27 21:03:11 volumio volumio[16295]: info: Streaming services startup Jan 27 21:03:11 volumio volumio[16295]: info: Starting Streaming Daemon Jan 27 21:03:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:03:11 volumio go-librespot[16655]: go-librespot daemon starting... Jan 27 21:03:11 volumio sudo[16659]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 21:03:11 volumio go-librespot[16658]: time="2026-01-27T21:03:11+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:03:11 volumio go-librespot[16658]: time="2026-01-27T21:03:11+07:00" level=debug msg="app state loaded" Jan 27 21:03:11 volumio sudo[16659]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:03:11 volumio go-librespot[16658]: time="2026-01-27T21:03:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:03:11 volumio volumio[16295]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 27 21:03:11 volumio sudo[16659]: pam_unix(sudo:session): session closed for user root Jan 27 21:03:11 volumio volumio[16295]: info: Getting Spotify volume Jan 27 21:03:11 volumio volumio[16295]: info: Connection to go-librespot Websocket closed Jan 27 21:03:11 volumio volumio[16295]: error: Cannot start Volumio Streaming Daemon Jan 27 21:03:11 volumio volumio[16295]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 21:03:11 volumio volumio[16295]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 21:03:11 volumio volumio[16295]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 27 21:03:11 volumio volumio[16295]: info: CoreCommandRouter::volumioGetState Jan 27 21:03:11 volumio volumio[16295]: info: CorePlayQueue::getTrack 0 Jan 27 21:03:11 volumio go-librespot[16658]: time="2026-01-27T21:03:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:03:11 volumio go-librespot[16658]: time="2026-01-27T21:03:11+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:03:11 volumio go-librespot[16658]: time="2026-01-27T21:03:11+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:03:11 volumio volumio[16295]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 27 21:03:11 volumio volumio[16295]: SPOTIFY: SPOTIFY VOLUME undefined Jan 27 21:03:11 volumio volumio[16295]: SPOTIFY: VOLUMIO VOLUME 100 Jan 27 21:03:11 volumio volumio[16295]: info: Aligning Spotify Volume to Volumio Volume Jan 27 21:03:11 volumio volumio[16295]: info: CoreCommandRouter::volumioGetState Jan 27 21:03:11 volumio volumio[16295]: info: CorePlayQueue::getTrack 0 Jan 27 21:03:11 volumio volumio[16295]: info: Setting Spotify Volume from Volumio: 100 Jan 27 21:03:11 volumio go-librespot[16658]: time="2026-01-27T21:03:11+07:00" level=info msg="zeroconf server listening on port 41959" Jan 27 21:03:11 volumio go-librespot[16658]: time="2026-01-27T21:03:11+07:00" level=debug msg="obtained new client token: AAC9uZkj5I6RZBF8eNkLCUqs4I8P8ixrDCu6cpRkOjoKk113DpB++77s1+/54tLAx4UM2wvw/ow21LCABKxpSMhcvwfJmfxVFJ95FV2hwmrO5Bjb6BHMUq4QyrZZ7hMQcUKEbJErSi+BIeBwUZ/XbaSIHx3H0XwrckOE6nDdkWaRgdzgbyFxcR25zQjD67lCfif5lfDeY+5ADmZKkIneK+LO1Fip5ItBoD7fyGffUi5N+Qa1c0a3XQoRS2w=" Jan 27 21:03:11 volumio go-librespot[16658]: time="2026-01-27T21:03:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:03:11 volumio go-librespot[16658]: time="2026-01-27T21:03:11+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 21:03:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:03:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:03:11 volumio volumio[16295]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 21:03:12 volumio volumio[16295]: Error: socket hang up Jan 27 21:03:12 volumio volumio[16295]: at connResetException (node:internal/errors:720:14) Jan 27 21:03:12 volumio volumio[16295]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 27 21:03:12 volumio volumio[16295]: at Socket.emit (node:events:526:35) Jan 27 21:03:12 volumio volumio[16295]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 27 21:03:12 volumio volumio[16295]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 27 21:03:12 volumio volumio[16295]: code: 'ECONNRESET', Jan 27 21:03:12 volumio volumio[16295]: response: undefined Jan 27 21:03:12 volumio volumio[16295]: } Jan 27 21:03:12 volumio volumio[16295]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 21:03:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:03:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:03:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:03:13 volumio sudo[16685]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 21:02' Jan 27 21:03:13 volumio sudo[16685]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:03:13 volumio sudo[16685]: pam_unix(sudo:session): session closed for user root Jan 27 21:03:13 volumio volumio-remote-updater[628]: [2026-01-27 21:03:13] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 27 21:03:13 volumio volumio-remote-updater[628]: [2026-01-27 21:03:13] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 27 21:03:13 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:03:13 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 27 21:03:13 volumio systemd[1]: volumio.service: Consumed 57.169s CPU time. Jan 27 21:03:13 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 21:03:14 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 21:03:14 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 9133. Jan 27 21:03:14 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 21:03:14 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 27 21:03:14 volumio systemd[1]: volumio.service: Consumed 57.169s CPU time. Jan 27 21:03:14 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 27 21:03:14 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 21:03:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:03:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:03:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:03:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 27 21:03:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:03:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:03:15 volumio go-librespot[16713]: go-librespot daemon starting... Jan 27 21:03:15 volumio go-librespot[16714]: time="2026-01-27T21:03:15+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:03:15 volumio go-librespot[16714]: time="2026-01-27T21:03:15+07:00" level=debug msg="app state loaded" Jan 27 21:03:15 volumio go-librespot[16714]: time="2026-01-27T21:03:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:03:15 volumio go-librespot[16714]: time="2026-01-27T21:03:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:03:15 volumio go-librespot[16714]: time="2026-01-27T21:03:15+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:03:15 volumio go-librespot[16714]: time="2026-01-27T21:03:15+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:03:15 volumio go-librespot[16714]: time="2026-01-27T21:03:15+07:00" level=info msg="zeroconf server listening on port 38605" Jan 27 21:03:16 volumio go-librespot[16714]: time="2026-01-27T21:03:16+07:00" level=debug msg="obtained new client token: AAB4aQkwJKHujOU0X3VmMByEuhvQZtVOO/C4NeNGMKDrv3NOTmPFnhrAw7XuuDWi4m7r9YvZlD0mmaxn7uVAkFhGTaPCEg2wTnalO04fdr5d3cmXjtlq6re9kFr2VmX3ogOHvHUfk7dYOsXtgmHeoDgTtr75cypPyOD8qOs+c6Gsg+/5JOZLq7DrE90SUdPYtM5uYAi53n5fAzYOfHlpP8k11jwKwZUYw7JzHdw2RwRV8zxtUv5pe6Pv" Jan 27 21:03:16 volumio go-librespot[16714]: time="2026-01-27T21:03:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:03:16 volumio go-librespot[16714]: time="2026-01-27T21:03:16+07:00" level=debug msg="completed keyexchange" Jan 27 21:03:16 volumio go-librespot[16714]: time="2026-01-27T21:03:16+07:00" level=debug msg="completed challenge" Jan 27 21:03:16 volumio go-librespot[16714]: time="2026-01-27T21:03:16+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 21:03:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:03:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:03:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:03:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:03:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:03:17 volumio volumio[16698]: info: ------------------------------------------- Jan 27 21:03:17 volumio volumio[16698]: info: ----- Volumio3 ---- Jan 27 21:03:17 volumio volumio[16698]: info: ------------------------------------------- Jan 27 21:03:17 volumio volumio[16698]: info: ----- System startup ---- Jan 27 21:03:17 volumio volumio[16698]: info: ------------------------------------------- Jan 27 21:03:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:03:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:03:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:03:18 volumio volumio-remote-updater[628]: [2026-01-27 21:03:18] [connect] Successful connection Jan 27 21:03:19 volumio volumio[16698]: info: MYVOLUMIO Environment detected Jan 27 21:03:19 volumio volumio[16698]: info: Plugin folders cleanup Jan 27 21:03:19 volumio volumio[16698]: info: Scanning into folder /volumio/app/plugins/ Jan 27 21:03:19 volumio volumio[16698]: info: Scanning category audio_interface Jan 27 21:03:19 volumio volumio[16698]: info: Scanning category miscellanea Jan 27 21:03:19 volumio volumio[16698]: info: Scanning category music_service Jan 27 21:03:19 volumio volumio[16698]: info: Scanning category plugins.json Jan 27 21:03:19 volumio volumio[16698]: info: Scanning category system_controller Jan 27 21:03:19 volumio volumio[16698]: info: Scanning category user_interface Jan 27 21:03:19 volumio volumio[16698]: info: Scanning into folder /data/plugins/ Jan 27 21:03:19 volumio volumio[16698]: info: Scanning category music_service Jan 27 21:03:19 volumio volumio[16698]: info: Plugin folders cleanup completed Jan 27 21:03:19 volumio volumio[16698]: info: ------------------------------------------- Jan 27 21:03:19 volumio volumio[16698]: info: ----- Core plugins startup ---- Jan 27 21:03:19 volumio volumio[16698]: info: ------------------------------------------- Jan 27 21:03:19 volumio volumio[16698]: info: Loading plugins from folder /volumio/app/plugins/ Jan 27 21:03:19 volumio volumio[16698]: info: Adding plugin upnp to MyMusic Plugins Jan 27 21:03:19 volumio volumio[16698]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 27 21:03:19 volumio volumio[16698]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 27 21:03:19 volumio volumio[16698]: info: Loading plugins from folder /data/plugins/ Jan 27 21:03:19 volumio volumio[16698]: info: Loading plugin "system"... Jan 27 21:03:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 27 21:03:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:03:19 volumio volumio[16698]: info: Loading plugin "appearance"... Jan 27 21:03:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:03:19 volumio go-librespot[16730]: go-librespot daemon starting... Jan 27 21:03:19 volumio go-librespot[16734]: time="2026-01-27T21:03:19+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:03:19 volumio go-librespot[16734]: time="2026-01-27T21:03:19+07:00" level=debug msg="app state loaded" Jan 27 21:03:19 volumio go-librespot[16734]: time="2026-01-27T21:03:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:03:20 volumio go-librespot[16734]: time="2026-01-27T21:03:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:03:20 volumio go-librespot[16734]: time="2026-01-27T21:03:20+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 21:03:20 volumio go-librespot[16734]: time="2026-01-27T21:03:20+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 21:03:20 volumio go-librespot[16734]: time="2026-01-27T21:03:20+07:00" level=info msg="zeroconf server listening on port 46681" Jan 27 21:03:20 volumio go-librespot[16734]: time="2026-01-27T21:03:20+07:00" level=debug msg="obtained new client token: AACuFKQXMRL002XYBXFQcnrfBxGiWVSHLpE3CZ4iqBQ4U2YQe+zclrAw1ygRbx+YHmfgt2SXBO63ga/4NQA0FWRlb45sOHeTOoWzr9/uaQlRkyRTMPQjxo9jz1nn3FOEIcKtpmwFDAe7eHntwnnrZglHKqUyHjTkULtGaI5QnWZaBg4j9HHCyofkmJOhPvmAdkeIviaIPSf2fxlUuko5Ie7rChoTfl+J2DB8aPKVxmHx+Qar+KId7W9LSGc=" Jan 27 21:03:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:03:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:03:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:03:20 volumio go-librespot[16734]: time="2026-01-27T21:03:20+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:03:20 volumio go-librespot[16734]: time="2026-01-27T21:03:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 21:03:20 volumio go-librespot[16734]: time="2026-01-27T21:03:20+07:00" level=debug msg="completed keyexchange" Jan 27 21:03:20 volumio go-librespot[16734]: time="2026-01-27T21:03:20+07:00" level=debug msg="completed challenge" Jan 27 21:03:20 volumio go-librespot[16734]: time="2026-01-27T21:03: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:03:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:03:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:03:21 volumio volumio[16698]: info: Loading plugin "network"... Jan 27 21:03:21 volumio volumio[16698]: info: Refreshing Cached IP Addresses Jan 27 21:03:21 volumio sudo[16743]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 21:03:21 volumio sudo[16743]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:03:21 volumio sudo[16745]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 21:03:21 volumio volumio[16698]: info: Loading plugin "services"... Jan 27 21:03:21 volumio sudo[16745]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:03:21 volumio volumio[16698]: info: Loading plugin "alsa_controller"... Jan 27 21:03:21 volumio sudo[16743]: pam_unix(sudo:session): session closed for user root Jan 27 21:03:21 volumio sudo[16745]: pam_unix(sudo:session): session closed for user root Jan 27 21:03:21 volumio sudo[16753]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 27 21:03:21 volumio sudo[16753]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:03:21 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 21:03:21 volumio volumio[16698]: info: Loading plugin "wizard"... Jan 27 21:03:21 volumio volumio[16698]: info: Loading plugin "networkfs"... Jan 27 21:03:21 volumio volumio[16698]: info: Starting Udev Watcher for removable devices Jan 27 21:03:21 volumio volumio[16698]: info: Ignoring mount for partition: boot Jan 27 21:03:21 volumio volumio[16698]: info: Ignoring mount for partition: volumio Jan 27 21:03:21 volumio volumio[16698]: info: Ignoring mount for partition: volumio_data Jan 27 21:03:21 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 21:03:21 volumio volumio[16698]: info: Loading plugin "volumio_command_line_client"... Jan 27 21:03:21 volumio volumio[16698]: info: Loading plugin "upnp"... Jan 27 21:03:21 volumio volumio[16698]: info: [1769522601896] Starting Upmpd Daemon Jan 27 21:03:21 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 21:03:21 volumio volumio[16698]: info: Loading plugin "my_music"... Jan 27 21:03:21 volumio volumio[16698]: info: Loading plugin "mpd"... Jan 27 21:03:22 volumio volumio[16698]: info: Loading plugin "upnp_browser"... Jan 27 21:03:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:03:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:03:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:03:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 27 21:03:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:03:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:03:24 volumio go-librespot[16776]: go-librespot daemon starting... Jan 27 21:03:24 volumio go-librespot[16777]: time="2026-01-27T21:03:24+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:03:24 volumio go-librespot[16777]: time="2026-01-27T21:03:24+07:00" level=debug msg="app state loaded" Jan 27 21:03:24 volumio go-librespot[16777]: time="2026-01-27T21:03:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:03:24 volumio sudo[16753]: pam_unix(sudo:session): session closed for user root Jan 27 21:03:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:03:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:03:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:03:24 volumio go-librespot[16777]: time="2026-01-27T21:03:24+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:03:24 volumio go-librespot[16777]: time="2026-01-27T21:03:24+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:03:24 volumio go-librespot[16777]: time="2026-01-27T21:03:24+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:03:24 volumio go-librespot[16777]: time="2026-01-27T21:03:24+07:00" level=info msg="zeroconf server listening on port 41743" Jan 27 21:03:24 volumio go-librespot[16777]: time="2026-01-27T21:03:24+07:00" level=debug msg="obtained new client token: AAD7z5px220vDR3ETXZf7M6ETXtbtFTtbbA2H1SN8Msyaj3imp3CLrPQXlafNJmpX7bFJ8HUpNBggQEe47rf/9LfdPqdrhfdLdnt0PxTlgPnVPF+R26Rz7pgnJESXUXlmVqHVuhTDUlGYGGSrmGqYga4HM6Us7JkCtadcVkFjt8He5iRXf/omBCZxt3CSBBxKDntCLzrSfiALXLa3UX2oCM0Yf6uvq/C7WQ/oPe621PgoP7/ImlHPDYjpeI=" Jan 27 21:03:24 volumio go-librespot[16777]: time="2026-01-27T21:03:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:03:25 volumio go-librespot[16777]: time="2026-01-27T21:03:25+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 21:03:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:03:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:03:25 volumio volumio[16698]: info: Starting UPNP Browser Jan 27 21:03:25 volumio volumio[16698]: info: Loading plugin "alarm-clock"... Jan 27 21:03:25 volumio volumio[16698]: info: Loading plugin "airplay_emulation"... Jan 27 21:03:25 volumio volumio[16698]: info: Starting Shairport Sync Jan 27 21:03:25 volumio volumio[16698]: info: Loading plugin "last_100"... Jan 27 21:03:25 volumio volumio[16698]: info: Loading plugin "webradio"... Jan 27 21:03:26 volumio volumio[16698]: info: Loading plugin "i2s_dacs"... Jan 27 21:03:26 volumio volumio[16698]: info: Loading plugin "volumiodiscovery"... Jan 27 21:03:26 volumio volumio[16698]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 21:03:26 volumio volumio[16698]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 21:03:26 volumio node[16698]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 21:03:26 volumio volumio[16698]: *** WARNING *** For more information see Jan 27 21:03:26 volumio volumio[16698]: *** 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:03:26 volumio volumio[16698]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 21:03:26 volumio volumio[16698]: *** WARNING *** For more information see Jan 27 21:03:26 volumio node[16698]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 21:03:26 volumio node[16698]: *** WARNING *** For more information see Jan 27 21:03:26 volumio node[16698]: *** 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:03:26 volumio node[16698]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 21:03:26 volumio node[16698]: *** WARNING *** For more information see Jan 27 21:03:26 volumio volumio[16698]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 27 21:03:26 volumio volumio[16698]: info: Discovery: Started advertising with name: Volumio Jan 27 21:03:26 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 21:03:26 volumio volumio[16698]: info: Loading plugin "spop"... Jan 27 21:03:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:03:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:03:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:03:28 volumio volumio[16698]: info: Loading plugin "ytcr"... Jan 27 21:03:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 27 21:03:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:03:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:03:28 volumio go-librespot[16787]: go-librespot daemon starting... Jan 27 21:03:28 volumio go-librespot[16788]: time="2026-01-27T21:03:28+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:03:28 volumio go-librespot[16788]: time="2026-01-27T21:03:28+07:00" level=debug msg="app state loaded" Jan 27 21:03:28 volumio go-librespot[16788]: time="2026-01-27T21:03:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:03:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:03:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:03:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:03:28 volumio go-librespot[16788]: time="2026-01-27T21:03: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:03:28 volumio go-librespot[16788]: time="2026-01-27T21:03: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:03:28 volumio go-librespot[16788]: time="2026-01-27T21:03: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:03:28 volumio go-librespot[16788]: time="2026-01-27T21:03:28+07:00" level=info msg="zeroconf server listening on port 37419" Jan 27 21:03:29 volumio go-librespot[16788]: time="2026-01-27T21:03:29+07:00" level=debug msg="obtained new client token: AACEHVuJRlFIgQIrnJNuoHH1hf6isAPS+TWq1HpS9CznoT8IP8zq2oYRB9+FWLwotIbEKLykhLNjJipX4yq0rotklRl6tEbz5vurevod5hFzOYSpU23r3/tPseNEwQwWSH6l0CLApU8CXyzMVkhsIwW+JJ7duoMM/qR5A1xNtQ2I6c4Xu/j77GPoznD9g6+7+uFTNZkgCl7EJ2ysM0rP/xS8/0T2X5j8Pr2RRuyXV3ec+3/1f1b8wci3" Jan 27 21:03:29 volumio go-librespot[16788]: time="2026-01-27T21:03:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:03:29 volumio go-librespot[16788]: time="2026-01-27T21:03:29+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 21:03:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:03:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:03:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:03:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:03:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:03:30 volumio volumio[16698]: info: Loading plugin "ytmusic"... Jan 27 21:03:31 volumio volumio-remote-updater[628]: [2026-01-27 21:03:31] [connect] Successful connection Jan 27 21:03:31 volumio volumio[16698]: info: Loading plugin "outputs"... Jan 27 21:03:31 volumio volumio[16698]: info: Loading plugin "albumart"... Jan 27 21:03:31 volumio volumio[16698]: info: Plugin example_plugin is not enabled Jan 27 21:03:31 volumio volumio[16698]: info: Loading plugin "inputs"... Jan 27 21:03:31 volumio volumio[16698]: info: Loading plugin "updater_comm"... Jan 27 21:03:32 volumio volumio[16698]: info: Plugin mpdemulation is not enabled Jan 27 21:03:32 volumio volumio[16698]: info: Loading plugin "rest_api"... Jan 27 21:03:32 volumio volumio[16698]: info: Loading plugin "websocket"... Jan 27 21:03:32 volumio volumio[16698]: info: Starting Socket.io Server version 1.7.4 Jan 27 21:03:32 volumio volumio[16698]: info: Loading plugin "RoonBridge"... Jan 27 21:03:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 27 21:03:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:03:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:03:32 volumio go-librespot[16819]: go-librespot daemon starting... Jan 27 21:03:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:03:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:03:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:03:32 volumio go-librespot[16820]: time="2026-01-27T21:03:32+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:03:32 volumio go-librespot[16820]: time="2026-01-27T21:03:32+07:00" level=debug msg="app state loaded" Jan 27 21:03:32 volumio go-librespot[16820]: time="2026-01-27T21:03:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:03:32 volumio volumio[16698]: info: Applying required configuration parameters for plugin RoonBridge Jan 27 21:03:32 volumio volumio[16698]: info: Loading i18n strings for locale en Jan 27 21:03:32 volumio volumio[16698]: Updating browse sources language Jan 27 21:03:32 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:03:32 volumio volumio[16809]: Forking 3 albumart workers Jan 27 21:03:33 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 21:03:33 volumio volumio[16698]: info: CoreCommandRouter::initPlayerControls Jan 27 21:03:33 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:03:33 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:03:33 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:03:33 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:03:33 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:03:33 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:03:33 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:03:33 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:03:33 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 21:03:33 volumio volumio[16698]: Express server listening on port 3000 Jan 27 21:03:33 volumio volumio[16698]: [Metrics] WebUI: 16s 99.67ms Jan 27 21:03:33 volumio volumio[16698]: info: CoreStateMachine::resetVolumioState Jan 27 21:03:33 volumio volumio[16698]: info: CoreStateMachine::getcurrentVolume Jan 27 21:03:33 volumio volumio[16698]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 21:03:33 volumio go-librespot[16820]: time="2026-01-27T21:03: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-gew1.spotify.com:80]" Jan 27 21:03:33 volumio go-librespot[16820]: time="2026-01-27T21:03:33+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:03:33 volumio go-librespot[16820]: time="2026-01-27T21:03:33+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:03:33 volumio go-librespot[16820]: time="2026-01-27T21:03:33+07:00" level=info msg="zeroconf server listening on port 33639" Jan 27 21:03:33 volumio sudo[16863]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 21:03:33 volumio sudo[16863]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:03:33 volumio sudo[16863]: pam_unix(sudo:session): session closed for user root Jan 27 21:03:33 volumio sudo[16865]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 21:03:33 volumio sudo[16865]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:03:33 volumio sudo[16865]: pam_unix(sudo:session): session closed for user root Jan 27 21:03:33 volumio volumio[16698]: info: Volumio Network Manager: Network status updated: 1 Jan 27 21:03:33 volumio go-librespot[16820]: time="2026-01-27T21:03:33+07:00" level=debug msg="obtained new client token: AACf4HQlYDCI77Yp6yULd2GuPz+squdvX5tlexz/Z4y8oFCOkJE5hqzJaRY+HDgr9HCTf1hzhS0OrlTb7fg7X50XIlqsF+N/jqOPqQSBC5sVVsD9+gfE2+RiVwSUOTjrXVWf/iDPfGt/ll+/BU+YVjfjbcbMGgId+qlDyRTuy9QqcqkyIOmtn4j+mmGvshvY6apiuI9Y62VfARrTFVbqEJW24qAX2uXzKuYMzniT1A53fo/3406jAEIixRw=" Jan 27 21:03:33 volumio go-librespot[16820]: time="2026-01-27T21:03:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:03:33 volumio volumio[16698]: info: VolumeController:: Volume=100 Mute =false Jan 27 21:03:33 volumio volumio[16698]: info: CoreStateMachine::pushState Jan 27 21:03:33 volumio volumio[16698]: info: CorePlayQueue::getTrack 0 Jan 27 21:03:33 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 21:03:33 volumio volumio[16698]: info: CoreCommandRouter::volumioPushState Jan 27 21:03:33 volumio volumio[16698]: info: CoreStateMachine::updateTrackBlock Jan 27 21:03:33 volumio volumio[16698]: info: CorePlayQueue::getTrackBlock Jan 27 21:03:33 volumio volumio[16698]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 21:03:33 volumio go-librespot[16820]: time="2026-01-27T21:03:33+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:03:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:03:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:03:33 volumio volumio-remote-updater[628]: [2026-01-27 21:03:33] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769522611 101 Jan 27 21:03:33 volumio volumio[16698]: 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:03:34 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:03:34 volumio volumio[16698]: info: Reloading queue from file Jan 27 21:03:34 volumio volumio[16698]: info: CoreStateMachine::setRepeat null single undefined Jan 27 21:03:34 volumio volumio[16698]: info: CoreStateMachine::pushState Jan 27 21:03:34 volumio volumio[16698]: info: CorePlayQueue::getTrack 0 Jan 27 21:03:34 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 21:03:34 volumio volumio[16698]: info: CoreCommandRouter::volumioPushState Jan 27 21:03:34 volumio volumio[16698]: info: CoreStateMachine::setRandom null Jan 27 21:03:34 volumio volumio[16698]: info: CoreStateMachine::pushState Jan 27 21:03:34 volumio volumio[16698]: info: CorePlayQueue::getTrack 0 Jan 27 21:03:34 volumio volumio[16698]: info: CoreCommandRouter::volumioPushState Jan 27 21:03:34 volumio volumio[16698]: info: Setting Device type: Raspberry PI Jan 27 21:03:34 volumio volumio[16698]: info: Completed loading Core Plugins Jan 27 21:03:34 volumio volumio[16698]: info: Preparing to generate the ALSA configuration file Jan 27 21:03:34 volumio volumio[16698]: info: VolumeController:: Volume=100 Mute =false Jan 27 21:03:34 volumio volumio[16698]: info: CoreStateMachine::pushState Jan 27 21:03:34 volumio volumio[16698]: info: CorePlayQueue::getTrack 0 Jan 27 21:03:34 volumio volumio[16698]: info: CoreCommandRouter::volumioPushState Jan 27 21:03:34 volumio volumio[16698]: info: Asound.conf file unchanged, so no further update is needed Jan 27 21:03:34 volumio volumio[16698]: info: Output device has changed, restarting MPD Jan 27 21:03:34 volumio volumio[16698]: info: Output device has changed, restarting Shairport Sync Jan 27 21:03:34 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:03:34 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:03:34 volumio sudo[16879]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 27 21:03:34 volumio sudo[16879]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:03:34 volumio volumio[16698]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 21:03:34 volumio sudo[16881]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 21:03:34 volumio volumio[16698]: info: ___________ START PLUGINS ___________ Jan 27 21:03:34 volumio sudo[16881]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:03:34 volumio sudo[16881]: pam_unix(sudo:session): session closed for user root Jan 27 21:03:34 volumio sudo[16883]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 21:03:34 volumio volumio[16698]: info: ControllerMpd::onStart: Initializing MPD Jan 27 21:03:34 volumio sudo[16883]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:03:34 volumio volumio[16698]: info: Creating MPD Configuration file Jan 27 21:03:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:03:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:03:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:03:34 volumio sudo[16879]: pam_unix(sudo:session): session closed for user root Jan 27 21:03:34 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 21:03:34 volumio volumio[16698]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 21:03:34 volumio volumio[16698]: info: [1769522614629] CoreMusicLibrary::Adding element Media Servers Jan 27 21:03:34 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:03:34 volumio volumio[16698]: info: UPNP Browser: Client initialized successfully Jan 27 21:03:34 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 27 21:03:34 volumio sudo[16892]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 21:03:34 volumio sudo[16892]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:03:34 volumio sudo[16894]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 21:03:34 volumio sudo[16894]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:03:34 volumio sudo[16892]: pam_unix(sudo:session): session closed for user root Jan 27 21:03:34 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:03:34 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:03:34 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 21:03:34 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 21:03:34 volumio systemd[1]: mpd.service: Consumed 7.336s CPU time. Jan 27 21:03:34 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 21:03:34 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 21:03:34 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 21:03:34 volumio volumio[16698]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 21:03:34 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:03:34 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:03:34 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 21:03:34 volumio volumio[16698]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 21:03:34 volumio volumio[16698]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 21:03:34 volumio volumio[16698]: info: [1769522614960] CoreMusicLibrary::Adding element Last_100 Jan 27 21:03:34 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:03:34 volumio volumio[16698]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 21:03:34 volumio volumio[16698]: info: [1769522614970] CoreMusicLibrary::Adding element Webradio Jan 27 21:03:34 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:03:34 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 21:03:34 volumio volumio[16698]: info: Initializing BBC Radios Jan 27 21:03:35 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 21:03:35 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 21:03:35 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:03:35 volumio volumio[16698]: info: Creating Spotify config file Jan 27 21:03:35 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:03:35 volumio sudo[16906]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 27 21:03:35 volumio sudo[16906]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 27 21:03:35 volumio sudo[16906]: pam_unix(sudo:session): session closed for user root Jan 27 21:03:36 volumio volumio[16830]: Starting albumart workers Jan 27 21:03:36 volumio volumio[16829]: Starting albumart workers Jan 27 21:03:36 volumio volumio[16828]: Starting albumart workers Jan 27 21:03:36 volumio volumio[16698]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 21:03:36 volumio volumio[16698]: info: [1769522616488] CoreMusicLibrary::Adding element YouTube Music Jan 27 21:03:36 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:03:36 volumio volumio[16698]: Cannot find translation for source YouTube Music Jan 27 21:03:36 volumio volumio[16698]: info: Volumio Calling Home Jan 27 21:03:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:03:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:03:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:03:36 volumio sudo[16923]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 27 21:03:36 volumio sudo[16923]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:03:36 volumio sudo[16923]: pam_unix(sudo:session): session closed for user root Jan 27 21:03:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 27 21:03:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:03:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:03:37 volumio go-librespot[16928]: go-librespot daemon starting... Jan 27 21:03:37 volumio go-librespot[16929]: time="2026-01-27T21:03:37+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:03:37 volumio volumio[16698]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 21:03:37 volumio volumio[16698]: info: Discovery: Found device Volumio Jan 27 21:03:37 volumio volumio[16698]: info: CoreCommandRouter::volumioGetState Jan 27 21:03:37 volumio volumio[16698]: info: CorePlayQueue::getTrack 0 Jan 27 21:03:37 volumio volumio[16698]: info: MPD Permissions set Jan 27 21:03:37 volumio volumio[16698]: info: MPD Permissions set Jan 27 21:03:37 volumio volumio[16698]: info: Upmpdcli Daemon Started Jan 27 21:03:37 volumio volumio[16698]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 21:03:37 volumio volumio[16698]: info: Discovery: Found device Volumio Jan 27 21:03:37 volumio volumio[16698]: info: CoreCommandRouter::volumioGetState Jan 27 21:03:37 volumio volumio[16698]: info: CorePlayQueue::getTrack 0 Jan 27 21:03:37 volumio volumio[16698]: info: Volumio called home Jan 27 21:03:37 volumio volumio[16698]: info: Spotify config file written Jan 27 21:03:37 volumio go-librespot[16929]: time="2026-01-27T21:03:37+07:00" level=info msg="zeroconf server listening on port 42935" Jan 27 21:03:37 volumio sudo[16937]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 21:03:37 volumio sudo[16937]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:03:38 volumio volumio[16698]: 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:03:38 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:03:38 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:03:38 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:03:38 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:03:38 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:03:38 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:03:38 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:03:38 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:03:38 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 27 21:03:38 volumio systemd[1]: go-librespot-daemon.service: Killing process 16934 (go-librespot) with signal SIGKILL. Jan 27 21:03:38 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 27 21:03:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:03:38 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:03:38 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:03:38 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:03:38 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:03:38 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:03:38 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:03:38 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:03:38 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:03:38 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:03:38 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:03:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:03:38 volumio go-librespot[16944]: go-librespot daemon starting... Jan 27 21:03:38 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:03:38 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:03:38 volumio volumio[16698]: info: No need to fix Spotify hosts Jan 27 21:03:38 volumio go-librespot[16951]: time="2026-01-27T21:03:38+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:03:38 volumio go-librespot[16951]: time="2026-01-27T21:03:38+07:00" level=debug msg="app state loaded" Jan 27 21:03:38 volumio go-librespot[16951]: time="2026-01-27T21:03:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:03:38 volumio sudo[16937]: pam_unix(sudo:session): session closed for user root Jan 27 21:03:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:03:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:03:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:03:38 volumio go-librespot[16951]: time="2026-01-27T21:03: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:03:38 volumio go-librespot[16951]: time="2026-01-27T21:03: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:03:38 volumio go-librespot[16951]: time="2026-01-27T21:03: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:03:38 volumio go-librespot[16951]: time="2026-01-27T21:03:38+07:00" level=info msg="zeroconf server listening on port 43051" Jan 27 21:03:39 volumio go-librespot[16951]: time="2026-01-27T21:03:39+07:00" level=debug msg="obtained new client token: AACIRMJr47YXbxIk7I7VsfbaDZ4cZCHFUm+0Jtn0choX7rfe4tAWtBEhVIprTy6KOpaMo+vA7yAXtfy5ShaIyilFs4rwDsGNQpvoH4nJJ2rXzyV63FxCosphkKie1uyhPVu555QYWp/YumcpcXpkF3O+qk425NH6sZY0haO2cgTedFKL4TLLjYzc8R28vJUVd+2s89Yu9V/wW5dxkD4NBSPCKRo5JLw0WNa1LOxshrjSOLwqhAR+g3rV" Jan 27 21:03:39 volumio go-librespot[16951]: time="2026-01-27T21:03:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:03:39 volumio go-librespot[16951]: time="2026-01-27T21:03:39+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:03:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:03:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:03:39 volumio volumio[16698]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 21:03:39 volumio volumio[16698]: SPOTIFY: BQBSa8B3bEyfxJYIGx-8w6_tD-DotGpu4u5eR8kD0Z65dtDt8ny4YF3WohEgjPf_m50Xo-yNxEscnHgN-Zi_NdWjger86rXR5NUhGLc2g6FBmDsFmHMmKiw9ULRBK3XXvG28aX3DzTwh_30ylb3JvaCB4QuiJXnIWruWSfPDW43oFJL6EKfnZIUNhFNsNc-BwBHPP_v5KDNpcu74GKpOIwKkzQjKxrI9KGXFXwG0NbldFpYBAMtShMFslX4sFHgV3zzXsWcuEF_8PyB5hBQaFme057_dv_3FL7AoO6Rc_rEr3HA8-yO7u2JL Jan 27 21:03:39 volumio volumio[16698]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 21:03:39 volumio volumio[16698]: info: New Spotify access token = BQBSa8B3bEyfxJYIGx-8w6_tD-DotGpu4u5eR8kD0Z65dtDt8ny4YF3WohEgjPf_m50Xo-yNxEscnHgN-Zi_NdWjger86rXR5NUhGLc2g6FBmDsFmHMmKiw9ULRBK3XXvG28aX3DzTwh_30ylb3JvaCB4QuiJXnIWruWSfPDW43oFJL6EKfnZIUNhFNsNc-BwBHPP_v5KDNpcu74GKpOIwKkzQjKxrI9KGXFXwG0NbldFpYBAMtShMFslX4sFHgV3zzXsWcuEF_8PyB5hBQaFme057_dv_3FL7AoO6Rc_rEr3HA8-yO7u2JL Jan 27 21:03:39 volumio volumio[16698]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 27 21:03:39 volumio volumio[16698]: info: Starting Shairport Sync Jan 27 21:03:39 volumio volumio[16698]: info: Starting Shairport Sync Jan 27 21:03:39 volumio volumio[16698]: info: Starting Shairport Sync Jan 27 21:03:39 volumio sudo[16977]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 21:03:39 volumio sudo[16977]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:03:39 volumio sudo[16979]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 21:03:39 volumio sudo[16979]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:03:39 volumio sudo[16981]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 21:03:39 volumio sudo[16981]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:03:39 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 21:03:39 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 21:03:39 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 21:03:39 volumio systemd[1]: shairport-sync.service: Consumed 2.293s CPU time. Jan 27 21:03:39 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 21:03:39 volumio sudo[16981]: pam_unix(sudo:session): session closed for user root Jan 27 21:03:39 volumio sudo[16977]: pam_unix(sudo:session): session closed for user root Jan 27 21:03:39 volumio sudo[16979]: pam_unix(sudo:session): session closed for user root Jan 27 21:03:39 volumio volumio[16698]: info: CoreCommandRouter::volumioGetState Jan 27 21:03:39 volumio volumio[16698]: info: CorePlayQueue::getTrack 0 Jan 27 21:03:39 volumio volumio[16698]: info: Shairport-Sync Started Jan 27 21:03:39 volumio volumio[16698]: Error adding Membership: Error: addMembership EINVAL Jan 27 21:03:39 volumio volumio[16698]: info: Shairport-Sync Started Jan 27 21:03:40 volumio volumio[16698]: info: Shairport-Sync Started Jan 27 21:03:40 volumio volumio[16698]: 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:03:40 volumio volumio[16698]: info: Spotify Successfully logged in Jan 27 21:03:40 volumio volumio[16698]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 21:03:40 volumio volumio[16698]: info: [1769522620081] CoreMusicLibrary::Adding element Spotify Jan 27 21:03:40 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:03:40 volumio volumio[16698]: Cannot find translation for source YouTube Music Jan 27 21:03:40 volumio volumio[16698]: Cannot find translation for source Spotify Jan 27 21:03:40 volumio volumio[16698]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 27 21:03:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:03:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:03:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:03:40 volumio volumio[16698]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 21:03:40 volumio volumio[16698]: info: VolumeController:: Volume=100 Mute =false Jan 27 21:03:40 volumio volumio[16698]: info: CoreCommandRouter::volumioGetState Jan 27 21:03:40 volumio volumio[16698]: info: CorePlayQueue::getTrack 0 Jan 27 21:03:40 volumio volumio[16698]: info: CoreStateMachine::pushState Jan 27 21:03:40 volumio volumio[16698]: info: CorePlayQueue::getTrack 0 Jan 27 21:03:40 volumio volumio[16698]: info: CoreCommandRouter::volumioPushState Jan 27 21:03:42 volumio volumio[16698]: info: go-librespot daemon successfully initialized Jan 27 21:03:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 27 21:03:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:03:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:03:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:03:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:03:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:03:42 volumio go-librespot[17016]: go-librespot daemon starting... Jan 27 21:03:42 volumio go-librespot[17017]: time="2026-01-27T21:03:42+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:03:42 volumio go-librespot[17017]: time="2026-01-27T21:03:42+07:00" level=debug msg="app state loaded" Jan 27 21:03:42 volumio go-librespot[17017]: time="2026-01-27T21:03:42+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:03:42 volumio mpd[16921]: 2026-01-27T21:03:42 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 27 21:03:42 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 27 21:03:42 volumio sudo[16883]: pam_unix(sudo:session): session closed for user root Jan 27 21:03:42 volumio sudo[16894]: pam_unix(sudo:session): session closed for user root Jan 27 21:03:42 volumio volumio[16698]: error: MPD error: The expression evaluated to a falsy value: Jan 27 21:03:42 volumio volumio[16698]: assert.ok(self.idling) Jan 27 21:03:42 volumio volumio[16698]: error: The expression evaluated to a falsy value: Jan 27 21:03:42 volumio volumio[16698]: assert.ok(self.idling) Jan 27 21:03:42 volumio volumio[16698]: info: MPD running with PID16921 Jan 27 21:03:42 volumio volumio[16698]: ,establishing connection Jan 27 21:03:42 volumio volumio[16698]: error: updateQueue error: null Jan 27 21:03:43 volumio volumio[16698]: info: Completed starting Core Plugins Jan 27 21:03:43 volumio volumio[16698]: info: ------------------------------------------- Jan 27 21:03:43 volumio volumio[16698]: info: ----- MyVolumio plugins startup ---- Jan 27 21:03:43 volumio volumio[16698]: info: ------------------------------------------- Jan 27 21:03:43 volumio volumio[16698]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 27 21:03:43 volumio volumio[16698]: error: updateQueue error: null Jan 27 21:03:43 volumio go-librespot[17017]: time="2026-01-27T21:03:43+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:03:43 volumio go-librespot[17017]: time="2026-01-27T21:03:43+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:03:43 volumio go-librespot[17017]: time="2026-01-27T21:03:43+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:03:43 volumio go-librespot[17017]: time="2026-01-27T21:03:43+07:00" level=info msg="zeroconf server listening on port 39591" Jan 27 21:03:43 volumio go-librespot[17017]: time="2026-01-27T21:03:43+07:00" level=debug msg="obtained new client token: AAByo0dObmxMYLDhUnTm0vs2uK2hM2bLlcPBhz3DHoE+LgJhlv9TRT0MoIbzsJra/KIVka1Ko3mokU5bAVao/UuBVnuIsNQuLCftemv4tgdtm+cDGD+lfEl14F1IqZFA587Y/fBLNXdnPugMvC+e8lXZp18RBmD2HWlm7BF9J9uRiMwhoyipWu7RXVuij8/fLb9U6rpAX4IRSoh8mVm1gd11jMnfp9/kAjKg5bVpfwC0IAbGNPTBAOoIeQ0=" Jan 27 21:03:43 volumio go-librespot[17017]: time="2026-01-27T21:03:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:03:43 volumio go-librespot[17017]: time="2026-01-27T21:03:43+07:00" level=debug msg="completed keyexchange" Jan 27 21:03:43 volumio go-librespot[17017]: time="2026-01-27T21:03:43+07:00" level=debug msg="completed challenge" Jan 27 21:03:43 volumio go-librespot[17017]: time="2026-01-27T21:03:43+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:03:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:03:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:03:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:03:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:03:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:03:45 volumio volumio[16698]: info: Initializing connection to go-librespot Websocket Jan 27 21:03:45 volumio volumio[16698]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:03:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:03:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:03:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:03:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 27 21:03:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:03:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:03:46 volumio go-librespot[17028]: go-librespot daemon starting... Jan 27 21:03:46 volumio go-librespot[17029]: time="2026-01-27T21:03:46+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:03:46 volumio go-librespot[17029]: time="2026-01-27T21:03:46+07:00" level=debug msg="app state loaded" Jan 27 21:03:46 volumio go-librespot[17029]: time="2026-01-27T21:03:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:03:47 volumio go-librespot[17029]: time="2026-01-27T21:03:47+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:03:47 volumio go-librespot[17029]: time="2026-01-27T21:03:47+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:03:47 volumio go-librespot[17029]: time="2026-01-27T21:03:47+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:03:47 volumio go-librespot[17029]: time="2026-01-27T21:03:47+07:00" level=info msg="zeroconf server listening on port 41563" Jan 27 21:03:47 volumio go-librespot[17029]: time="2026-01-27T21:03:47+07:00" level=debug msg="obtained new client token: AADQVmXAUlOLNXBJuYxovUb5tHoD2pwUT/EWVl+d6MyAOwhRR2UYImMOumxMNzJRIudbwRYcA1cW0tjq2AYWMNwbxAWVoWPTqKz0qjISSU2E8E8MfgX86L8LpPySeg6BPujI3sDkcQfEL5tCHb0F6Im1t2xBdmj1pl3S4S+ANezcf6ROoK3U9mLqUu1z1x+CCyISTVt+kQf3blTl09mK7ajKHC0Gq1BCV/Ds+cnDc7bLtKMak1G4VKCrpQw=" Jan 27 21:03:47 volumio go-librespot[17029]: time="2026-01-27T21:03:47+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:03:47 volumio go-librespot[17029]: time="2026-01-27T21:03:47+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:03:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:03:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:03:47 volumio volumio[16698]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 27 21:03:48 volumio volumio[16698]: info: Initializing connection to go-librespot Websocket Jan 27 21:03:48 volumio volumio[16698]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:03:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:03:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:03:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:03:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:03:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:03:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:03:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 27 21:03:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:03:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:03:51 volumio go-librespot[17039]: go-librespot daemon starting... Jan 27 21:03:51 volumio go-librespot[17040]: time="2026-01-27T21:03:51+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:03:51 volumio go-librespot[17040]: time="2026-01-27T21:03:51+07:00" level=debug msg="app state loaded" Jan 27 21:03:51 volumio go-librespot[17040]: time="2026-01-27T21:03:51+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:03:51 volumio volumio[16698]: info: Initializing connection to go-librespot Websocket Jan 27 21:03:51 volumio go-librespot[17040]: time="2026-01-27T21:03:51+07:00" level=debug msg="new websocket client" Jan 27 21:03:51 volumio volumio[16698]: info: Connection to go-librespot Websocket established Jan 27 21:03:51 volumio go-librespot[17040]: time="2026-01-27T21:03:51+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 21:03:51 volumio go-librespot[17040]: time="2026-01-27T21:03:51+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:03:51 volumio go-librespot[17040]: time="2026-01-27T21:03:51+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:03:51 volumio go-librespot[17040]: time="2026-01-27T21:03:51+07:00" level=info msg="zeroconf server listening on port 40427" Jan 27 21:03:51 volumio go-librespot[17040]: time="2026-01-27T21:03:51+07:00" level=debug msg="obtained new client token: AAA4/RpAxMbtL7O5Z32D/jLjT/iHY24+ljPWiJpeChyRFLfwfp8RPjyTQRrGl/uXpUCaJzGUXBmqktT2DUk/+XAQPXP7w50Bps3AR24h5kopwQ2Q2Kyi+1Gs87UToD+fJMmrA2csG36gJYlIYM3GeH8/nFCTMdDSztmM/aRwQuFN5LoXjkQ0+MLRRpuA22+enopw9tgTx5HyL8OXT1tDJ+LUPvt2XdHAxtH/Oo9z9D2SR6UjssLGUkNZJDc=" Jan 27 21:03:51 volumio go-librespot[17040]: time="2026-01-27T21:03:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:03:51 volumio go-librespot[17040]: time="2026-01-27T21:03:51+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 21:03:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:03:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:03:51 volumio volumio[16698]: info: Connection to go-librespot Websocket closed Jan 27 21:03:52 volumio volumio[16698]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 27 21:03:52 volumio volumio[16698]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 27 21:03:52 volumio volumio[16698]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 27 21:03:52 volumio volumio[16698]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 27 21:03:52 volumio volumio[16698]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 27 21:03:52 volumio volumio[16698]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 27 21:03:52 volumio volumio[16698]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 27 21:03:52 volumio volumio[16698]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 27 21:03:52 volumio volumio[16698]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 27 21:03:52 volumio volumio[16698]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 27 21:03:52 volumio volumio[16698]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 27 21:03:52 volumio volumio[16698]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 27 21:03:52 volumio volumio[16698]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 27 21:03:52 volumio volumio[16698]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 27 21:03:52 volumio volumio[16698]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 27 21:03:52 volumio volumio[16698]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 27 21:03:52 volumio volumio[16698]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 27 21:03:52 volumio volumio[16698]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 27 21:03:52 volumio volumio[16698]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 27 21:03:52 volumio volumio[16698]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 27 21:03:52 volumio volumio[16698]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 27 21:03:52 volumio volumio[16698]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 27 21:03:52 volumio volumio[16698]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 27 21:03:52 volumio volumio[16698]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 27 21:03:52 volumio volumio[16698]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 27 21:03:52 volumio volumio[16698]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 27 21:03:52 volumio volumio[16698]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 27 21:03:52 volumio volumio[16698]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 27 21:03:52 volumio volumio[16698]: info: Adding plugin bluetooth to MyMusic Plugins Jan 27 21:03:52 volumio volumio[16698]: info: Adding plugin multiroom to MyMusic Plugins Jan 27 21:03:52 volumio volumio[16698]: info: Adding plugin metavolumio to MyMusic Plugins Jan 27 21:03:52 volumio volumio[16698]: info: Adding plugin cd_controller to MyMusic Plugins Jan 27 21:03:52 volumio volumio[16698]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 27 21:03:52 volumio volumio[16698]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 27 21:03:52 volumio volumio[16698]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 27 21:03:52 volumio volumio[16698]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 27 21:03:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:03:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:03:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:03:53 volumio volumio[16698]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 27 21:03:53 volumio volumio[16698]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 27 21:03:53 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:03:53 volumio volumio[16698]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:03:53 volumio volumio[16698]: info: Starting MyVolumio Remote Streaming Endpoints Jan 27 21:03:53 volumio volumio[16698]: info: MyVolumio login type: Token Jan 27 21:03:54 volumio volumio[16698]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 27 21:03:54 volumio volumio[16698]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 27 21:03:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:03:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:03:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:03:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 27 21:03:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:03:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:03:55 volumio go-librespot[17061]: go-librespot daemon starting... Jan 27 21:03:55 volumio go-librespot[17062]: time="2026-01-27T21:03:55+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:03:55 volumio go-librespot[17062]: time="2026-01-27T21:03:55+07:00" level=debug msg="app state loaded" Jan 27 21:03:55 volumio go-librespot[17062]: time="2026-01-27T21:03:55+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:03:55 volumio volumio[16698]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 27 21:03:55 volumio volumio[16698]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 27 21:03:55 volumio volumio[16698]: info: Streaming services startup Jan 27 21:03:55 volumio volumio[16698]: info: Starting Streaming Daemon Jan 27 21:03:55 volumio sudo[17071]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 21:03:55 volumio sudo[17071]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:03:55 volumio volumio[16698]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 27 21:03:55 volumio sudo[17071]: pam_unix(sudo:session): session closed for user root Jan 27 21:03:55 volumio go-librespot[17062]: time="2026-01-27T21:03: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:03:55 volumio go-librespot[17062]: time="2026-01-27T21:03:55+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:03:55 volumio go-librespot[17062]: time="2026-01-27T21:03:55+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:03:55 volumio volumio[16698]: info: Getting Spotify volume Jan 27 21:03:55 volumio go-librespot[17062]: time="2026-01-27T21:03:55+07:00" level=info msg="zeroconf server listening on port 43653" Jan 27 21:03:55 volumio volumio[16698]: info: Initializing connection to go-librespot Websocket Jan 27 21:03:56 volumio volumio[16698]: error: Cannot start Volumio Streaming Daemon Jan 27 21:03:56 volumio volumio[16698]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 21:03:56 volumio volumio[16698]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 21:03:56 volumio go-librespot[17062]: time="2026-01-27T21:03:56+07:00" level=debug msg="new websocket client" Jan 27 21:03:56 volumio volumio[16698]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 27 21:03:56 volumio volumio[16698]: info: Connection to go-librespot Websocket established Jan 27 21:03:56 volumio go-librespot[17062]: time="2026-01-27T21:03:56+07:00" level=debug msg="obtained new client token: AADolGDtQUEiwfRxbE/zwJPZ8Ujewkm3+8o6w/pWemIskeCqfa4d8vKQQg3VBESaZzPnqhlc6JUIv8NsxAkV1UW/qD2JvU81kD1boHNGRa7cCy1HjDNagj/WklxspMtpVxg75FaCF3ytOjrSXI4gZk7heb0dBGMopidZIPQiim85fwwILR9d4HUTPFSiqzSjsE6NlFenLS8S8fvC0PRlZuo0s0D4dv8VgfX2mJ1wHHzy6OHPekyDvfwU" Jan 27 21:03:56 volumio volumio[16698]: info: CoreCommandRouter::volumioGetState Jan 27 21:03:56 volumio volumio[16698]: info: CorePlayQueue::getTrack 0 Jan 27 21:03:56 volumio go-librespot[17062]: time="2026-01-27T21:03:56+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:03:56 volumio volumio[16698]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 27 21:03:56 volumio volumio[16698]: SPOTIFY: SPOTIFY VOLUME undefined Jan 27 21:03:56 volumio volumio[16698]: SPOTIFY: VOLUMIO VOLUME 100 Jan 27 21:03:56 volumio volumio[16698]: info: Aligning Spotify Volume to Volumio Volume Jan 27 21:03:56 volumio volumio[16698]: info: CoreCommandRouter::volumioGetState Jan 27 21:03:56 volumio volumio[16698]: info: CorePlayQueue::getTrack 0 Jan 27 21:03:56 volumio volumio[16698]: info: Setting Spotify Volume from Volumio: 100 Jan 27 21:03:56 volumio go-librespot[17062]: time="2026-01-27T21:03:56+07:00" level=debug msg="completed keyexchange" Jan 27 21:03:56 volumio go-librespot[17062]: time="2026-01-27T21:03:56+07:00" level=debug msg="completed challenge" Jan 27 21:03:56 volumio go-librespot[17062]: time="2026-01-27T21:03:56+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:03:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:03:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:03:56 volumio volumio[16698]: info: Connection to go-librespot Websocket closed Jan 27 21:03:56 volumio volumio[16698]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 21:03:56 volumio volumio[16698]: Error: socket hang up Jan 27 21:03:56 volumio volumio[16698]: at connResetException (node:internal/errors:720:14) Jan 27 21:03:56 volumio volumio[16698]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 27 21:03:56 volumio volumio[16698]: at Socket.emit (node:events:526:35) Jan 27 21:03:56 volumio volumio[16698]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 27 21:03:56 volumio volumio[16698]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 27 21:03:56 volumio volumio[16698]: code: 'ECONNRESET', Jan 27 21:03:56 volumio volumio[16698]: response: undefined Jan 27 21:03:56 volumio volumio[16698]: } Jan 27 21:03:56 volumio volumio[16698]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 21:03:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:03:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:03:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:03:57 volumio sudo[17092]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 21:02' Jan 27 21:03:57 volumio sudo[17092]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:03:58 volumio sudo[17092]: pam_unix(sudo:session): session closed for user root Jan 27 21:03:58 volumio volumio-remote-updater[628]: [2026-01-27 21:03:58] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 27 21:03:58 volumio volumio-remote-updater[628]: [2026-01-27 21:03:58] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 27 21:03:58 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:03:58 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 27 21:03:58 volumio systemd[1]: volumio.service: Consumed 57.462s CPU time. Jan 27 21:03:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:03:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:03:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:03:58 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 21:03:58 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 21:03:58 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 9134. Jan 27 21:03:58 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 21:03:58 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 27 21:03:58 volumio systemd[1]: volumio.service: Consumed 57.462s CPU time. Jan 27 21:03:58 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 27 21:03:58 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 21:03:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 27 21:03:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:03:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:03:59 volumio go-librespot[17119]: go-librespot daemon starting... Jan 27 21:03:59 volumio go-librespot[17120]: time="2026-01-27T21:03:59+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:03:59 volumio go-librespot[17120]: time="2026-01-27T21:03:59+07:00" level=debug msg="app state loaded" Jan 27 21:03:59 volumio go-librespot[17120]: time="2026-01-27T21:03:59+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:04:00 volumio go-librespot[17120]: time="2026-01-27T21:04:00+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:04:00 volumio go-librespot[17120]: time="2026-01-27T21:04:00+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:04:00 volumio go-librespot[17120]: time="2026-01-27T21:04:00+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:04:00 volumio go-librespot[17120]: time="2026-01-27T21:04:00+07:00" level=info msg="zeroconf server listening on port 39809" Jan 27 21:04:00 volumio go-librespot[17120]: time="2026-01-27T21:04:00+07:00" level=debug msg="obtained new client token: AADglWyfQ8U5+U5tCYyP7csD/KjJ/Q4NvOhCOcSAmHGRR7mlFIMRx5IUVDGYIEUNka3oX+LkGA3ykqg7PZ+uJA+Sl0YPzyW5qaVouMyGKJEcAhopN9KfMQ+m379LzRxpyOPjEEcYvrV85phHgJO5YHPMoegk0D6FCMxbMkoE6V6k4oC6zdUVchcoBKmPdSZz+o6vPwGElATola38MjyoDnPnjSekbw9Mk/O/xFZ/Zk32psza7xGh2W0lJzk=" Jan 27 21:04:00 volumio go-librespot[17120]: time="2026-01-27T21:04:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:04:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:04:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:04:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:04:01 volumio go-librespot[17120]: time="2026-01-27T21:04:01+07:00" level=debug msg="completed keyexchange" Jan 27 21:04:01 volumio go-librespot[17120]: time="2026-01-27T21:04:01+07:00" level=debug msg="completed challenge" Jan 27 21:04:01 volumio go-librespot[17120]: time="2026-01-27T21:04:01+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:04:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:04:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:04:02 volumio volumio[17104]: info: ------------------------------------------- Jan 27 21:04:02 volumio volumio[17104]: info: ----- Volumio3 ---- Jan 27 21:04:02 volumio volumio[17104]: info: ------------------------------------------- Jan 27 21:04:02 volumio volumio[17104]: info: ----- System startup ---- Jan 27 21:04:02 volumio volumio[17104]: info: ------------------------------------------- Jan 27 21:04:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:04:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:04:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:04:03 volumio volumio-remote-updater[628]: [2026-01-27 21:04:03] [connect] Successful connection Jan 27 21:04:03 volumio volumio[17104]: info: MYVOLUMIO Environment detected Jan 27 21:04:03 volumio volumio[17104]: info: Plugin folders cleanup Jan 27 21:04:03 volumio volumio[17104]: info: Scanning into folder /volumio/app/plugins/ Jan 27 21:04:03 volumio volumio[17104]: info: Scanning category audio_interface Jan 27 21:04:03 volumio volumio[17104]: info: Scanning category miscellanea Jan 27 21:04:03 volumio volumio[17104]: info: Scanning category music_service Jan 27 21:04:03 volumio volumio[17104]: info: Scanning category plugins.json Jan 27 21:04:03 volumio volumio[17104]: info: Scanning category system_controller Jan 27 21:04:03 volumio volumio[17104]: info: Scanning category user_interface Jan 27 21:04:03 volumio volumio[17104]: info: Scanning into folder /data/plugins/ Jan 27 21:04:03 volumio volumio[17104]: info: Scanning category music_service Jan 27 21:04:03 volumio volumio[17104]: info: Plugin folders cleanup completed Jan 27 21:04:03 volumio volumio[17104]: info: ------------------------------------------- Jan 27 21:04:03 volumio volumio[17104]: info: ----- Core plugins startup ---- Jan 27 21:04:03 volumio volumio[17104]: info: ------------------------------------------- Jan 27 21:04:03 volumio volumio[17104]: info: Loading plugins from folder /volumio/app/plugins/ Jan 27 21:04:03 volumio volumio[17104]: info: Adding plugin upnp to MyMusic Plugins Jan 27 21:04:03 volumio volumio[17104]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 27 21:04:03 volumio volumio[17104]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 27 21:04:03 volumio volumio[17104]: info: Loading plugins from folder /data/plugins/ Jan 27 21:04:03 volumio volumio[17104]: info: Loading plugin "system"... Jan 27 21:04:03 volumio volumio[17104]: info: Loading plugin "appearance"... Jan 27 21:04:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:04:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:04:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:04:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 27 21:04:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:04:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:04:05 volumio go-librespot[17140]: go-librespot daemon starting... Jan 27 21:04:05 volumio go-librespot[17141]: time="2026-01-27T21:04:05+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:04:05 volumio go-librespot[17141]: time="2026-01-27T21:04:05+07:00" level=debug msg="app state loaded" Jan 27 21:04:05 volumio go-librespot[17141]: time="2026-01-27T21:04:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:04:05 volumio go-librespot[17141]: time="2026-01-27T21:04:05+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:04:05 volumio go-librespot[17141]: time="2026-01-27T21:04:05+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:04:05 volumio go-librespot[17141]: time="2026-01-27T21:04:05+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:04:05 volumio go-librespot[17141]: time="2026-01-27T21:04:05+07:00" level=info msg="zeroconf server listening on port 36971" Jan 27 21:04:05 volumio volumio[17104]: info: Loading plugin "network"... Jan 27 21:04:05 volumio volumio[17104]: info: Refreshing Cached IP Addresses Jan 27 21:04:05 volumio sudo[17149]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 21:04:05 volumio sudo[17149]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:04:05 volumio sudo[17151]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 21:04:05 volumio sudo[17151]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:04:05 volumio sudo[17149]: pam_unix(sudo:session): session closed for user root Jan 27 21:04:05 volumio sudo[17151]: pam_unix(sudo:session): session closed for user root Jan 27 21:04:05 volumio volumio[17104]: info: Loading plugin "services"... Jan 27 21:04:05 volumio volumio[17104]: info: Loading plugin "alsa_controller"... Jan 27 21:04:05 volumio sudo[17159]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 27 21:04:05 volumio sudo[17159]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:04:06 volumio go-librespot[17141]: time="2026-01-27T21:04:06+07:00" level=debug msg="obtained new client token: AAC+hJA2uWPk3+WN7NpBdm3Szg88OMin/xDnguQ1caPa3aSWBvQZVW4IzfaFZ8l/xJqSfI108jAK427D94kwMimyOnnGv5HG05Xv0xztvElC6ONVEN53JzHBofkdoJm5xISpkcddZ85m38nc0eZS8hY5aFA12Qxx9BKG7xIirfIf2IN3MYugq9nVOoaXMmwsEwuin9W/v3iER0CKylRzMhCsgk9y8YasyhQWl+gXRGfReFOCXhg56grQbPs=" Jan 27 21:04:06 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 21:04:06 volumio volumio[17104]: info: Loading plugin "wizard"... Jan 27 21:04:06 volumio go-librespot[17141]: time="2026-01-27T21:04:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:04:06 volumio volumio[17104]: info: Loading plugin "networkfs"... Jan 27 21:04:06 volumio volumio[17104]: info: Starting Udev Watcher for removable devices Jan 27 21:04:06 volumio go-librespot[17141]: time="2026-01-27T21:04:06+07:00" level=debug msg="completed keyexchange" Jan 27 21:04:06 volumio go-librespot[17141]: time="2026-01-27T21:04:06+07:00" level=debug msg="completed challenge" Jan 27 21:04:06 volumio volumio[17104]: info: Ignoring mount for partition: boot Jan 27 21:04:06 volumio volumio[17104]: info: Ignoring mount for partition: volumio Jan 27 21:04:06 volumio volumio[17104]: info: Ignoring mount for partition: volumio_data Jan 27 21:04:06 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 21:04:06 volumio volumio[17104]: info: Loading plugin "volumio_command_line_client"... Jan 27 21:04:06 volumio volumio[17104]: info: Loading plugin "upnp"... Jan 27 21:04:06 volumio volumio[17104]: info: [1769522646255] Starting Upmpd Daemon Jan 27 21:04:06 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 21:04:06 volumio volumio[17104]: info: Loading plugin "my_music"... Jan 27 21:04:06 volumio volumio[17104]: info: Loading plugin "mpd"... Jan 27 21:04:06 volumio go-librespot[17141]: time="2026-01-27T21:04:06+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:04:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:04:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:04:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:04:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:04:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:04:06 volumio volumio[17104]: info: Loading plugin "upnp_browser"... Jan 27 21:04:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:04:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:04:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:04:08 volumio sudo[17159]: pam_unix(sudo:session): session closed for user root Jan 27 21:04:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 27 21:04:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:04:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:04:09 volumio go-librespot[17183]: go-librespot daemon starting... Jan 27 21:04:09 volumio go-librespot[17184]: time="2026-01-27T21:04:09+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:04:09 volumio go-librespot[17184]: time="2026-01-27T21:04:09+07:00" level=debug msg="app state loaded" Jan 27 21:04:09 volumio go-librespot[17184]: time="2026-01-27T21:04:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:04:09 volumio volumio[17104]: info: Starting UPNP Browser Jan 27 21:04:09 volumio volumio[17104]: info: Loading plugin "alarm-clock"... Jan 27 21:04:10 volumio go-librespot[17184]: time="2026-01-27T21:04:10+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:04:10 volumio go-librespot[17184]: time="2026-01-27T21:04:10+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:04:10 volumio go-librespot[17184]: time="2026-01-27T21:04:10+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:04:10 volumio go-librespot[17184]: time="2026-01-27T21:04:10+07:00" level=info msg="zeroconf server listening on port 34989" Jan 27 21:04:10 volumio volumio[17104]: info: Loading plugin "airplay_emulation"... Jan 27 21:04:10 volumio volumio[17104]: info: Starting Shairport Sync Jan 27 21:04:10 volumio volumio[17104]: info: Loading plugin "last_100"... Jan 27 21:04:10 volumio volumio[17104]: info: Loading plugin "webradio"... Jan 27 21:04:10 volumio go-librespot[17184]: time="2026-01-27T21:04:10+07:00" level=debug msg="obtained new client token: AACbJB1Jlmhis7ij6m4hjFX6XDvv2H/H0PxwGzcv8rbApEKzVOm7Icew8rM7a/ITy2tZzdwJkGaMj1ytNceZuViUx9LoO7iVKXUnCOaT+eOCTZV5/I5vkzQG5G+x16QAFTupbPX2+vkHoo3G0905Iv9O8mOzyHFdFf2HUe8X5ne4LVtch0JxMVy/a1TZSQNN+nlHQ91ka3Jetnh9X0L1xPZ5FmlSxxejWaaOaBVDU8tT/n+U3znAxRTSLlE=" Jan 27 21:04:10 volumio volumio[17104]: info: Loading plugin "i2s_dacs"... Jan 27 21:04:10 volumio go-librespot[17184]: time="2026-01-27T21:04:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:04:10 volumio volumio[17104]: info: Loading plugin "volumiodiscovery"... Jan 27 21:04:10 volumio go-librespot[17184]: time="2026-01-27T21:04:10+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:04:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:04:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:04:10 volumio volumio[17104]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 21:04:10 volumio volumio[17104]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 21:04:10 volumio volumio[17104]: *** WARNING *** For more information see Jan 27 21:04:10 volumio volumio[17104]: *** 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:04:10 volumio volumio[17104]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 21:04:10 volumio volumio[17104]: *** WARNING *** For more information see Jan 27 21:04:10 volumio node[17104]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 21:04:10 volumio node[17104]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 21:04:10 volumio node[17104]: *** WARNING *** For more information see Jan 27 21:04:10 volumio node[17104]: *** 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:04:10 volumio node[17104]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 21:04:10 volumio node[17104]: *** WARNING *** For more information see Jan 27 21:04:10 volumio volumio[17104]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 27 21:04:10 volumio volumio[17104]: info: Discovery: Started advertising with name: Volumio Jan 27 21:04:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:04:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:04:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:04:10 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 21:04:10 volumio volumio[17104]: info: Loading plugin "spop"... Jan 27 21:04:12 volumio volumio[17104]: info: Loading plugin "ytcr"... Jan 27 21:04:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:04:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:04:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:04:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 27 21:04:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:04:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:04:13 volumio go-librespot[17195]: go-librespot daemon starting... Jan 27 21:04:13 volumio go-librespot[17196]: time="2026-01-27T21:04:13+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:04:13 volumio go-librespot[17196]: time="2026-01-27T21:04:13+07:00" level=debug msg="app state loaded" Jan 27 21:04:13 volumio go-librespot[17196]: time="2026-01-27T21:04:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:04:14 volumio go-librespot[17196]: time="2026-01-27T21:04:14+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:04:14 volumio go-librespot[17196]: time="2026-01-27T21:04:14+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:04:14 volumio go-librespot[17196]: time="2026-01-27T21:04:14+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:04:14 volumio go-librespot[17196]: time="2026-01-27T21:04:14+07:00" level=info msg="zeroconf server listening on port 46817" Jan 27 21:04:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:04:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:04:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:04:14 volumio go-librespot[17196]: time="2026-01-27T21:04:14+07:00" level=debug msg="obtained new client token: AACTzHm4fSn4m7rpiLWWw9JGJ8DzZiDC2J+KtTmqPkFlU1TjFPKVhBatXEWcShwE7IHYMNWDREJiWmDa/EQvUpdhXAmg2lnVjbXJ8bUJByEgbfutOTs4xaJGBjxj8AiJx/x0O0SGEaHKzzDzcx1oZjvnoeyWTY7ZXV9tMLPW9tf7ePDPRT4PMVc4sjnD+XIODdSKTNESQyyVHYTSHjPp1nF81aJ3Lcz8mtlVYAgupIuUk0RD7PPy580qrYM=" Jan 27 21:04:14 volumio go-librespot[17196]: time="2026-01-27T21:04:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:04:14 volumio go-librespot[17196]: time="2026-01-27T21:04:14+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:04:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:04:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:04:15 volumio volumio[17104]: info: Loading plugin "ytmusic"... Jan 27 21:04:15 volumio volumio-remote-updater[628]: [2026-01-27 21:04:15] [connect] Successful connection Jan 27 21:04:16 volumio volumio[17104]: info: Loading plugin "outputs"... Jan 27 21:04:16 volumio volumio[17104]: info: Loading plugin "albumart"... Jan 27 21:04:16 volumio volumio[17104]: info: Plugin example_plugin is not enabled Jan 27 21:04:16 volumio volumio[17104]: info: Loading plugin "inputs"... Jan 27 21:04:16 volumio volumio[17104]: info: Loading plugin "updater_comm"... Jan 27 21:04:16 volumio volumio[17104]: info: Plugin mpdemulation is not enabled Jan 27 21:04:16 volumio volumio[17104]: info: Loading plugin "rest_api"... Jan 27 21:04:16 volumio volumio[17104]: info: Loading plugin "websocket"... Jan 27 21:04:16 volumio volumio[17104]: info: Starting Socket.io Server version 1.7.4 Jan 27 21:04:16 volumio volumio[17104]: info: Loading plugin "RoonBridge"... Jan 27 21:04:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:04:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:04:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:04:16 volumio volumio[17104]: info: Applying required configuration parameters for plugin RoonBridge Jan 27 21:04:17 volumio volumio[17104]: info: Loading i18n strings for locale en Jan 27 21:04:17 volumio volumio[17104]: Updating browse sources language Jan 27 21:04:17 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:04:17 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 21:04:17 volumio volumio[17104]: info: CoreCommandRouter::initPlayerControls Jan 27 21:04:17 volumio volumio[17217]: Forking 3 albumart workers Jan 27 21:04:17 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:04:17 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:04:17 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:04:17 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:04:17 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:04:17 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:04:17 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:04:17 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:04:17 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 21:04:17 volumio volumio[17104]: Express server listening on port 3000 Jan 27 21:04:17 volumio volumio[17104]: [Metrics] WebUI: 15s 983.16ms Jan 27 21:04:17 volumio volumio[17104]: info: CoreStateMachine::resetVolumioState Jan 27 21:04:17 volumio volumio[17104]: info: CoreStateMachine::getcurrentVolume Jan 27 21:04:17 volumio volumio[17104]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 21:04:17 volumio sudo[17259]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 21:04:17 volumio sudo[17259]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:04:17 volumio sudo[17259]: pam_unix(sudo:session): session closed for user root Jan 27 21:04:17 volumio sudo[17261]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 21:04:17 volumio sudo[17261]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:04:17 volumio volumio[17104]: info: Volumio Network Manager: Network status updated: 1 Jan 27 21:04:17 volumio sudo[17261]: pam_unix(sudo:session): session closed for user root Jan 27 21:04:17 volumio volumio[17104]: info: VolumeController:: Volume=100 Mute =false Jan 27 21:04:17 volumio volumio[17104]: info: CoreStateMachine::pushState Jan 27 21:04:17 volumio volumio[17104]: info: CorePlayQueue::getTrack 0 Jan 27 21:04:17 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 21:04:17 volumio volumio[17104]: info: CoreCommandRouter::volumioPushState Jan 27 21:04:17 volumio volumio[17104]: info: CoreStateMachine::updateTrackBlock Jan 27 21:04:17 volumio volumio[17104]: info: CorePlayQueue::getTrackBlock Jan 27 21:04:17 volumio volumio[17104]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 21:04:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 27 21:04:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:04:18 volumio volumio-remote-updater[628]: [2026-01-27 21:04:18] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769522655 101 Jan 27 21:04:18 volumio volumio[17104]: 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:04:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:04:18 volumio go-librespot[17269]: go-librespot daemon starting... Jan 27 21:04:18 volumio go-librespot[17271]: time="2026-01-27T21:04:18+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:04:18 volumio go-librespot[17271]: time="2026-01-27T21:04:18+07:00" level=debug msg="app state loaded" Jan 27 21:04:18 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:04:18 volumio volumio[17104]: info: Reloading queue from file Jan 27 21:04:18 volumio go-librespot[17271]: time="2026-01-27T21:04:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:04:18 volumio volumio[17104]: info: CoreStateMachine::setRepeat null single undefined Jan 27 21:04:18 volumio volumio[17104]: info: CoreStateMachine::pushState Jan 27 21:04:18 volumio volumio[17104]: info: CorePlayQueue::getTrack 0 Jan 27 21:04:18 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 21:04:18 volumio volumio[17104]: info: CoreCommandRouter::volumioPushState Jan 27 21:04:18 volumio volumio[17104]: info: CoreStateMachine::setRandom null Jan 27 21:04:18 volumio volumio[17104]: info: CoreStateMachine::pushState Jan 27 21:04:18 volumio volumio[17104]: info: CorePlayQueue::getTrack 0 Jan 27 21:04:18 volumio volumio[17104]: info: CoreCommandRouter::volumioPushState Jan 27 21:04:18 volumio volumio[17104]: info: Setting Device type: Raspberry PI Jan 27 21:04:18 volumio volumio[17104]: info: Completed loading Core Plugins Jan 27 21:04:18 volumio volumio[17104]: info: Preparing to generate the ALSA configuration file Jan 27 21:04:18 volumio volumio[17104]: info: VolumeController:: Volume=100 Mute =false Jan 27 21:04:18 volumio volumio[17104]: info: CoreStateMachine::pushState Jan 27 21:04:18 volumio volumio[17104]: info: CorePlayQueue::getTrack 0 Jan 27 21:04:18 volumio volumio[17104]: info: CoreCommandRouter::volumioPushState Jan 27 21:04:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:04:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:04:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:04:18 volumio volumio[17104]: info: Asound.conf file unchanged, so no further update is needed Jan 27 21:04:18 volumio volumio[17104]: info: Output device has changed, restarting MPD Jan 27 21:04:18 volumio volumio[17104]: info: Output device has changed, restarting Shairport Sync Jan 27 21:04:18 volumio sudo[17287]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 21:04:18 volumio sudo[17287]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:04:18 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:04:18 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:04:18 volumio sudo[17285]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 27 21:04:18 volumio sudo[17285]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:04:18 volumio sudo[17287]: pam_unix(sudo:session): session closed for user root Jan 27 21:04:18 volumio sudo[17289]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 21:04:18 volumio sudo[17289]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:04:18 volumio go-librespot[17271]: time="2026-01-27T21:04:18+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:04:18 volumio go-librespot[17271]: time="2026-01-27T21:04:18+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:04:18 volumio go-librespot[17271]: time="2026-01-27T21:04:18+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:04:18 volumio volumio[17104]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 21:04:18 volumio sudo[17285]: pam_unix(sudo:session): session closed for user root Jan 27 21:04:18 volumio volumio[17104]: info: ___________ START PLUGINS ___________ Jan 27 21:04:18 volumio go-librespot[17271]: time="2026-01-27T21:04:18+07:00" level=info msg="zeroconf server listening on port 34875" Jan 27 21:04:18 volumio volumio[17104]: info: ControllerMpd::onStart: Initializing MPD Jan 27 21:04:18 volumio volumio[17104]: info: Creating MPD Configuration file Jan 27 21:04:18 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 27 21:04:18 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 21:04:18 volumio volumio[17104]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 21:04:19 volumio volumio[17104]: info: [1769522659000] CoreMusicLibrary::Adding element Media Servers Jan 27 21:04:19 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:04:19 volumio sudo[17300]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 21:04:19 volumio sudo[17299]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 21:04:19 volumio sudo[17299]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:04:19 volumio sudo[17300]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:04:19 volumio sudo[17300]: pam_unix(sudo:session): session closed for user root Jan 27 21:04:19 volumio volumio[17104]: info: UPNP Browser: Client initialized successfully Jan 27 21:04:19 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 21:04:19 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 21:04:19 volumio systemd[1]: mpd.service: Consumed 7.300s CPU time. Jan 27 21:04:19 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 21:04:19 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 21:04:19 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 21:04:19 volumio go-librespot[17271]: time="2026-01-27T21:04:19+07:00" level=debug msg="obtained new client token: AACfaW+kh3l3n7g3khDykTJ/vmE8zePU0X8S357UGoO6QS1zG5ANswT6G9SA8fRqSBBpO/dOKAevp+F4baFiMZg1RX10oi9/KoaBO59F1U/2m+sIgRdj/P9xHW5KBlvY5efh2zsCZPuwxzRbBtZ0NBA/ODlMmLXe3KD/EtpZAr48XV2aRooxBbtiAlc50RlHGMQB4/KagYsWkeU+oZqVNWt7VhK6hByXQGs4MiEpcE+nd6LBN8ukB69T" Jan 27 21:04:19 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:04:19 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:04:19 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 21:04:19 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 21:04:19 volumio go-librespot[17271]: time="2026-01-27T21:04:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:04:19 volumio volumio[17104]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 21:04:19 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:04:19 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:04:19 volumio go-librespot[17271]: time="2026-01-27T21:04:19+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:04:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:04:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:04:19 volumio volumio[17104]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 21:04:19 volumio volumio[17104]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 21:04:19 volumio volumio[17104]: info: [1769522659458] CoreMusicLibrary::Adding element Last_100 Jan 27 21:04:19 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:04:19 volumio volumio[17104]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 21:04:19 volumio volumio[17104]: info: [1769522659478] CoreMusicLibrary::Adding element Webradio Jan 27 21:04:19 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:04:19 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 21:04:19 volumio volumio[17104]: info: Initializing BBC Radios Jan 27 21:04:19 volumio sudo[17308]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 27 21:04:19 volumio sudo[17308]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 27 21:04:19 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 21:04:19 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:04:19 volumio sudo[17308]: pam_unix(sudo:session): session closed for user root Jan 27 21:04:19 volumio volumio[17104]: info: Creating Spotify config file Jan 27 21:04:19 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:04:20 volumio volumio[17228]: Starting albumart workers Jan 27 21:04:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:04:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:04:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:04:20 volumio volumio[17227]: Starting albumart workers Jan 27 21:04:20 volumio volumio[17229]: Starting albumart workers Jan 27 21:04:21 volumio volumio[17104]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 21:04:21 volumio volumio[17104]: info: [1769522661106] CoreMusicLibrary::Adding element YouTube Music Jan 27 21:04:21 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:04:21 volumio volumio[17104]: Cannot find translation for source YouTube Music Jan 27 21:04:21 volumio volumio[17104]: info: Volumio Calling Home Jan 27 21:04:21 volumio sudo[17329]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 27 21:04:21 volumio sudo[17329]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:04:21 volumio sudo[17329]: pam_unix(sudo:session): session closed for user root Jan 27 21:04:22 volumio volumio[17104]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 21:04:22 volumio volumio[17104]: info: Discovery: Found device Volumio Jan 27 21:04:22 volumio volumio[17104]: info: CoreCommandRouter::volumioGetState Jan 27 21:04:22 volumio volumio[17104]: info: CorePlayQueue::getTrack 0 Jan 27 21:04:22 volumio volumio[17104]: info: MPD Permissions set Jan 27 21:04:22 volumio volumio[17104]: info: MPD Permissions set Jan 27 21:04:22 volumio volumio[17104]: info: Upmpdcli Daemon Started Jan 27 21:04:22 volumio volumio[17104]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 21:04:22 volumio volumio[17104]: info: Discovery: Found device Volumio Jan 27 21:04:22 volumio volumio[17104]: info: CoreCommandRouter::volumioGetState Jan 27 21:04:22 volumio volumio[17104]: info: CorePlayQueue::getTrack 0 Jan 27 21:04:22 volumio volumio[17104]: info: Volumio called home Jan 27 21:04:22 volumio volumio[17104]: info: Spotify config file written Jan 27 21:04:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 27 21:04:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:04:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:04:22 volumio go-librespot[17348]: go-librespot daemon starting... Jan 27 21:04:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:04:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:04:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:04:22 volumio volumio[17104]: 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:04:22 volumio sudo[17344]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 21:04:22 volumio sudo[17344]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:04:22 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:04:22 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:04:22 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:04:22 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:04:22 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:04:22 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:04:22 volumio go-librespot[17349]: time="2026-01-27T21:04:22+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:04:22 volumio go-librespot[17349]: time="2026-01-27T21:04:22+07:00" level=debug msg="app state loaded" Jan 27 21:04:22 volumio go-librespot[17349]: time="2026-01-27T21:04:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:04:22 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:04:22 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:04:22 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:04:22 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:04:22 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:04:22 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:04:22 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:04:22 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:04:22 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:04:22 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:04:22 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:04:22 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:04:22 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 27 21:04:22 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 27 21:04:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:04:22 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:04:22 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 21:04:22 volumio volumio[17104]: info: No need to fix Spotify hosts Jan 27 21:04:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:04:22 volumio go-librespot[17372]: go-librespot daemon starting... Jan 27 21:04:22 volumio sudo[17344]: pam_unix(sudo:session): session closed for user root Jan 27 21:04:22 volumio go-librespot[17373]: time="2026-01-27T21:04:22+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:04:22 volumio go-librespot[17373]: time="2026-01-27T21:04:22+07:00" level=debug msg="app state loaded" Jan 27 21:04:22 volumio go-librespot[17373]: time="2026-01-27T21:04:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:04:23 volumio go-librespot[17373]: time="2026-01-27T21:04: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:04:23 volumio go-librespot[17373]: time="2026-01-27T21:04:23+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:04:23 volumio go-librespot[17373]: time="2026-01-27T21:04:23+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:04:23 volumio go-librespot[17373]: time="2026-01-27T21:04:23+07:00" level=info msg="zeroconf server listening on port 46381" Jan 27 21:04:23 volumio volumio[17104]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 21:04:23 volumio volumio[17104]: SPOTIFY: BQCg2ImEpwBog-EzgNzd4e7vmT4yZBV7-c1AfRp5CCEsiYrYsgVrNyBrf0uW8jov0yRobC2FmP_4wioslDM6XTXTB3zda-RBa4xfKZNEAkyh5QAcdtudpWrdnSuenEiZcgc7oMZ_9BKsRQH2wZyYCDhRJyDUZZtSg3s_-0ejh0d-GWGYZ0P_nPRyXqW4tF8HDqcG3RNCXD36_W-EsgcfT1l9pn9VhjqxXrJjezvU6F9YhJfXWOMSlOSCN2yA63AZkNy4hI9O47UByYqPyEXqfyLbiNScXT5zL5zCbjskpXAX-BJq7KdCEcg5 Jan 27 21:04:23 volumio volumio[17104]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 21:04:23 volumio volumio[17104]: info: New Spotify access token = BQCg2ImEpwBog-EzgNzd4e7vmT4yZBV7-c1AfRp5CCEsiYrYsgVrNyBrf0uW8jov0yRobC2FmP_4wioslDM6XTXTB3zda-RBa4xfKZNEAkyh5QAcdtudpWrdnSuenEiZcgc7oMZ_9BKsRQH2wZyYCDhRJyDUZZtSg3s_-0ejh0d-GWGYZ0P_nPRyXqW4tF8HDqcG3RNCXD36_W-EsgcfT1l9pn9VhjqxXrJjezvU6F9YhJfXWOMSlOSCN2yA63AZkNy4hI9O47UByYqPyEXqfyLbiNScXT5zL5zCbjskpXAX-BJq7KdCEcg5 Jan 27 21:04:23 volumio volumio[17104]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 27 21:04:23 volumio volumio[17104]: info: Starting Shairport Sync Jan 27 21:04:23 volumio volumio[17104]: info: Starting Shairport Sync Jan 27 21:04:23 volumio volumio[17104]: info: Starting Shairport Sync Jan 27 21:04:23 volumio go-librespot[17373]: time="2026-01-27T21:04:23+07:00" level=debug msg="obtained new client token: AAC+mSDHKkQ7edf1YvM3A35+vwD1NATm7Mu+Wf5h92NW5UC3P3pi9TOCwM0DdR8F6LoePQR3bHoneaq1/y8zRvy2pBjsMXKIvvWgJakaDMscM7Vagot/8uYRS55bUWJ+IQ5oHHmOCYoFwj33M+zUPpfbvE6usKpsXbL88NP6oxprKKe4NbF8ITi18zZL1wFg1mOK5oAAueZ4l1/zVEgXhqlFri8l+AukAeT2iSX3u1GTRA9ndKWX/WaJgDQ=" Jan 27 21:04:23 volumio sudo[17382]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 21:04:23 volumio sudo[17382]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:04:23 volumio sudo[17386]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 21:04:23 volumio sudo[17386]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:04:23 volumio sudo[17384]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 21:04:23 volumio sudo[17384]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:04:23 volumio go-librespot[17373]: time="2026-01-27T21:04:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:04:23 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 21:04:23 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 21:04:23 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 21:04:23 volumio systemd[1]: shairport-sync.service: Consumed 2.304s CPU time. Jan 27 21:04:24 volumio go-librespot[17373]: time="2026-01-27T21:04: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:04:24 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 21:04:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:04:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:04:24 volumio sudo[17382]: pam_unix(sudo:session): session closed for user root Jan 27 21:04:24 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 21:04:24 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 21:04:24 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 21:04:24 volumio volumio[17104]: info: Shairport-Sync Started Jan 27 21:04:24 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 21:04:24 volumio volumio[17104]: Error adding Membership: Error: addMembership EINVAL Jan 27 21:04:24 volumio sudo[17384]: pam_unix(sudo:session): session closed for user root Jan 27 21:04:24 volumio sudo[17386]: pam_unix(sudo:session): session closed for user root Jan 27 21:04:24 volumio volumio[17104]: info: Shairport-Sync Started Jan 27 21:04:24 volumio volumio[17104]: info: Shairport-Sync Started Jan 27 21:04:24 volumio volumio[17104]: info: CoreCommandRouter::volumioGetState Jan 27 21:04:24 volumio volumio[17104]: info: CorePlayQueue::getTrack 0 Jan 27 21:04:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:04:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:04:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:04:24 volumio volumio[17104]: 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:04:24 volumio volumio[17104]: info: Spotify Successfully logged in Jan 27 21:04:24 volumio volumio[17104]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 21:04:24 volumio volumio[17104]: info: [1769522664703] CoreMusicLibrary::Adding element Spotify Jan 27 21:04:24 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 21:04:24 volumio volumio[17104]: Cannot find translation for source YouTube Music Jan 27 21:04:24 volumio volumio[17104]: Cannot find translation for source Spotify Jan 27 21:04:25 volumio volumio[17104]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 27 21:04:25 volumio volumio[17104]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 21:04:25 volumio volumio[17104]: info: VolumeController:: Volume=100 Mute =false Jan 27 21:04:25 volumio volumio[17104]: info: CoreCommandRouter::volumioGetState Jan 27 21:04:25 volumio volumio[17104]: info: CorePlayQueue::getTrack 0 Jan 27 21:04:25 volumio volumio[17104]: info: CoreStateMachine::pushState Jan 27 21:04:25 volumio volumio[17104]: info: CorePlayQueue::getTrack 0 Jan 27 21:04:25 volumio volumio[17104]: info: CoreCommandRouter::volumioPushState Jan 27 21:04:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:04:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:04:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:04:26 volumio volumio[17104]: info: go-librespot daemon successfully initialized Jan 27 21:04:26 volumio mpd[17327]: 2026-01-27T21:04:26 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 27 21:04:26 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 27 21:04:26 volumio sudo[17289]: pam_unix(sudo:session): session closed for user root Jan 27 21:04:26 volumio sudo[17299]: pam_unix(sudo:session): session closed for user root Jan 27 21:04:27 volumio volumio[17104]: error: MPD error: The expression evaluated to a falsy value: Jan 27 21:04:27 volumio volumio[17104]: assert.ok(self.idling) Jan 27 21:04:27 volumio volumio[17104]: error: The expression evaluated to a falsy value: Jan 27 21:04:27 volumio volumio[17104]: assert.ok(self.idling) Jan 27 21:04:27 volumio volumio[17104]: error: updateQueue error: null Jan 27 21:04:27 volumio volumio[17104]: info: MPD running with PID17327 Jan 27 21:04:27 volumio volumio[17104]: ,establishing connection Jan 27 21:04:27 volumio volumio[17104]: info: Completed starting Core Plugins Jan 27 21:04:27 volumio volumio[17104]: info: ------------------------------------------- Jan 27 21:04:27 volumio volumio[17104]: info: ----- MyVolumio plugins startup ---- Jan 27 21:04:27 volumio volumio[17104]: info: ------------------------------------------- Jan 27 21:04:27 volumio volumio[17104]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 27 21:04:27 volumio volumio[17104]: error: updateQueue error: null Jan 27 21:04:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 27 21:04:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:04:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:04:27 volumio go-librespot[17430]: go-librespot daemon starting... Jan 27 21:04:27 volumio go-librespot[17431]: time="2026-01-27T21:04:27+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:04:27 volumio go-librespot[17431]: time="2026-01-27T21:04:27+07:00" level=debug msg="app state loaded" Jan 27 21:04:27 volumio go-librespot[17431]: time="2026-01-27T21:04:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:04:27 volumio go-librespot[17431]: time="2026-01-27T21:04:27+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:04:27 volumio go-librespot[17431]: time="2026-01-27T21:04:27+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:04:27 volumio go-librespot[17431]: time="2026-01-27T21:04:27+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:04:27 volumio go-librespot[17431]: time="2026-01-27T21:04:27+07:00" level=info msg="zeroconf server listening on port 44023" Jan 27 21:04:28 volumio go-librespot[17431]: time="2026-01-27T21:04:28+07:00" level=debug msg="obtained new client token: AADjWy2YQ0Z4fQlUpxRSR1optR9MSHDR+xz89XHZQPxFYeNwIx+z/MNxNRkWX2s3i4ZTZOmunMHeNIIMfC8DEBPqkDepVRwG5dXzuEiT/2sXfd/iRJ3hCenOVGtveAuwBIjZs2MmZK6WgiVpIABS4lw84TJrBJhxVvHSAnhq8IZnY8jAWU6lZas/iOBB5Qk1z59rilN4a7nlddl6xXl26nvU51zqg7dPeMEHl22V7pvmpa/4OOJH/S4Y" Jan 27 21:04:28 volumio go-librespot[17431]: time="2026-01-27T21:04:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:04:28 volumio go-librespot[17431]: time="2026-01-27T21:04:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 21:04:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:04:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:04:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:04:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:04:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:04:29 volumio volumio[17104]: info: Initializing connection to go-librespot Websocket Jan 27 21:04:29 volumio volumio[17104]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:04:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:04:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:04:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:04:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 27 21:04:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:04:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:04:31 volumio go-librespot[17439]: go-librespot daemon starting... Jan 27 21:04:31 volumio go-librespot[17440]: time="2026-01-27T21:04:31+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:04:31 volumio go-librespot[17440]: time="2026-01-27T21:04:31+07:00" level=debug msg="app state loaded" Jan 27 21:04:31 volumio go-librespot[17440]: time="2026-01-27T21:04:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:04:31 volumio volumio[17104]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 27 21:04:32 volumio go-librespot[17440]: time="2026-01-27T21:04:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:04:32 volumio go-librespot[17440]: time="2026-01-27T21:04:32+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 21:04:32 volumio go-librespot[17440]: time="2026-01-27T21:04:32+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 21:04:32 volumio go-librespot[17440]: time="2026-01-27T21:04:32+07:00" level=info msg="zeroconf server listening on port 45723" Jan 27 21:04:32 volumio go-librespot[17440]: time="2026-01-27T21:04:32+07:00" level=debug msg="obtained new client token: AABVcWGYP7ujOSmQDen4NO0pkzKeRg05EK5ISlIOzAgWMWjuM/LEBvnaD7bk2iM6lhrdSmOEgLMmezPJIgjdcA+3VQQrfkmJGpQJ/Jl8vkUAFDhnXgyAA/Qzvpa4itJUxoiSBbIA/dA5YDtOVQxFJeagKQbuGGKApj3X9pBMc57ycQXtEtrl+CfExPnpsWC0SLKbeHa09aS46mrYCRiIPAl58gBuNKgDygss37Hoi1bjr3CLAEIWcRLFatE=" Jan 27 21:04:32 volumio go-librespot[17440]: time="2026-01-27T21:04:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:04:32 volumio go-librespot[17440]: time="2026-01-27T21:04: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:04:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:04:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:04:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:04:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:04:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:04:32 volumio volumio[17104]: info: Initializing connection to go-librespot Websocket Jan 27 21:04:32 volumio volumio[17104]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:04:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:04:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:04:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:04:35 volumio volumio[17104]: info: Initializing connection to go-librespot Websocket Jan 27 21:04:35 volumio volumio[17104]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:04:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 27 21:04:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:04:35 volumio volumio[17104]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 27 21:04:35 volumio volumio[17104]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 27 21:04:35 volumio volumio[17104]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 27 21:04:35 volumio volumio[17104]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 27 21:04:35 volumio volumio[17104]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 27 21:04:35 volumio volumio[17104]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 27 21:04:35 volumio volumio[17104]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 27 21:04:35 volumio volumio[17104]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 27 21:04:35 volumio volumio[17104]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 27 21:04:35 volumio volumio[17104]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 27 21:04:35 volumio volumio[17104]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 27 21:04:35 volumio volumio[17104]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 27 21:04:35 volumio volumio[17104]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 27 21:04:35 volumio volumio[17104]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 27 21:04:35 volumio volumio[17104]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 27 21:04:35 volumio volumio[17104]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 27 21:04:35 volumio volumio[17104]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 27 21:04:35 volumio volumio[17104]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 27 21:04:35 volumio volumio[17104]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 27 21:04:35 volumio volumio[17104]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 27 21:04:35 volumio volumio[17104]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 27 21:04:35 volumio volumio[17104]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 27 21:04:35 volumio volumio[17104]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 27 21:04:35 volumio volumio[17104]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 27 21:04:35 volumio volumio[17104]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 27 21:04:35 volumio volumio[17104]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 27 21:04:35 volumio volumio[17104]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 27 21:04:35 volumio volumio[17104]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 27 21:04:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:04:35 volumio go-librespot[17447]: go-librespot daemon starting... Jan 27 21:04:35 volumio volumio[17104]: info: Adding plugin bluetooth to MyMusic Plugins Jan 27 21:04:35 volumio volumio[17104]: info: Adding plugin multiroom to MyMusic Plugins Jan 27 21:04:35 volumio volumio[17104]: info: Adding plugin metavolumio to MyMusic Plugins Jan 27 21:04:35 volumio volumio[17104]: info: Adding plugin cd_controller to MyMusic Plugins Jan 27 21:04:35 volumio volumio[17104]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 27 21:04:35 volumio volumio[17104]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 27 21:04:35 volumio volumio[17104]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 27 21:04:35 volumio volumio[17104]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 27 21:04:35 volumio go-librespot[17448]: time="2026-01-27T21:04:35+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:04:35 volumio go-librespot[17448]: time="2026-01-27T21:04:35+07:00" level=debug msg="app state loaded" Jan 27 21:04:35 volumio go-librespot[17448]: time="2026-01-27T21:04:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:04:36 volumio go-librespot[17448]: time="2026-01-27T21:04: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:04:36 volumio go-librespot[17448]: time="2026-01-27T21:04: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:04:36 volumio go-librespot[17448]: time="2026-01-27T21:04: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:04:36 volumio go-librespot[17448]: time="2026-01-27T21:04:36+07:00" level=info msg="zeroconf server listening on port 42001" Jan 27 21:04:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:04:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:04:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:04:36 volumio go-librespot[17448]: time="2026-01-27T21:04:36+07:00" level=debug msg="obtained new client token: AAC3b/wmY/gPhbfAxX8oAkLfK88XMqpRESOEM0tr1nT7ZsTs70Q+SxpIAv9WEkChOIlJJxNtcpfjMm09TtjZhuhJP1SBEq2Hk3xqP7flXdEg4GFLhJyeiYfc5649m5cdJ95zFwRQajAi/f+4WfpxSJgd15a2/IXvbgST1qFi49Gn2DWC0Zyq/Fq+AwxnK87FvK2DDBPUJ1zJeQJ+MRw+4i4H4plHlOPDTRywFXvotT8VEPT8vSw+TCF5ZeA=" Jan 27 21:04:36 volumio go-librespot[17448]: time="2026-01-27T21:04:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:04:36 volumio go-librespot[17448]: time="2026-01-27T21:04:36+07:00" level=debug msg="completed keyexchange" Jan 27 21:04:36 volumio go-librespot[17448]: time="2026-01-27T21:04:36+07:00" level=debug msg="completed challenge" Jan 27 21:04:36 volumio go-librespot[17448]: time="2026-01-27T21:04:36+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:04:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:04:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:04:37 volumio volumio[17104]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 27 21:04:37 volumio volumio[17104]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 27 21:04:37 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:04:37 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:04:37 volumio volumio[17104]: info: Starting MyVolumio Remote Streaming Endpoints Jan 27 21:04:37 volumio volumio[17104]: info: MyVolumio login type: Token Jan 27 21:04:37 volumio volumio[17104]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 27 21:04:37 volumio volumio[17104]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 27 21:04:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:04:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:04:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:04:39 volumio volumio[17104]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 27 21:04:39 volumio volumio[17104]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 27 21:04:39 volumio volumio[17104]: info: Streaming services startup Jan 27 21:04:39 volumio volumio[17104]: info: Starting Streaming Daemon Jan 27 21:04:39 volumio sudo[17473]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 21:04:39 volumio sudo[17473]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:04:39 volumio volumio[17104]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 27 21:04:39 volumio sudo[17473]: pam_unix(sudo:session): session closed for user root Jan 27 21:04:39 volumio volumio[17104]: info: Initializing connection to go-librespot Websocket Jan 27 21:04:39 volumio volumio[17104]: error: Cannot start Volumio Streaming Daemon Jan 27 21:04:39 volumio volumio[17104]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 21:04:39 volumio volumio[17104]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 21:04:39 volumio volumio[17104]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:04:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 27 21:04:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:04:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:04:40 volumio go-librespot[17479]: go-librespot daemon starting... Jan 27 21:04:40 volumio go-librespot[17480]: time="2026-01-27T21:04:40+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:04:40 volumio go-librespot[17480]: time="2026-01-27T21:04:40+07:00" level=debug msg="app state loaded" Jan 27 21:04:40 volumio go-librespot[17480]: time="2026-01-27T21:04:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:04:40 volumio go-librespot[17480]: time="2026-01-27T21:04: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:04:40 volumio go-librespot[17480]: time="2026-01-27T21:04: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:04:40 volumio go-librespot[17480]: time="2026-01-27T21:04: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:04:40 volumio go-librespot[17480]: time="2026-01-27T21:04:40+07:00" level=info msg="zeroconf server listening on port 41775" Jan 27 21:04:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:04:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:04:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:04:40 volumio volumio[17104]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 27 21:04:40 volumio go-librespot[17480]: time="2026-01-27T21:04:40+07:00" level=debug msg="obtained new client token: AAC/cWeVsTfZyE1hGIqTDAxF46TNR8BbQk+F7dZ1bhwTxsfhELmDcY8kGYGjKf6p/YXjN1A2tI4mpzAvIEi8cVA2R83OT3fqtBZDPFQ2p6t87AZRIcu0uP/Pmdg7zO0t945+u1inwmvrQ5qln1NR86NdfU7uGzZA/ydESCdJENzUZF+/YLpOvF0r1n6h1aK4UOtwShvRJrtB6r6IPFTmNcatF5U63Z6ciwWz7/6RDs/VOXVa0Igv0LGooBQ=" Jan 27 21:04:40 volumio go-librespot[17480]: time="2026-01-27T21:04:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:04:40 volumio go-librespot[17480]: time="2026-01-27T21:04:40+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:04:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:04:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:04:41 volumio volumio[17104]: info: MyVolumio token set successfully Jan 27 21:04:41 volumio volumio[17104]: info: MYVOLUMIO: Adding device Jan 27 21:04:41 volumio volumio[17104]: info: MYVOLUMIO: Evaluating Server Jan 27 21:04:42 volumio volumio[17104]: info: MyVolumio status changed Jan 27 21:04:42 volumio volumio[17104]: info: Streaming services startup Jan 27 21:04:42 volumio volumio[17104]: info: Starting Streaming Daemon Jan 27 21:04:42 volumio volumio[17104]: info: Removing browser output: myVolumio user plan is not superstar Jan 27 21:04:42 volumio volumio[17104]: info: Removing audio output: Jan 27 21:04:42 volumio volumio[17104]: info: Stoppping Tunnel 1 Jan 27 21:04:42 volumio sudo[17509]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 21:04:42 volumio sudo[17509]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:04:42 volumio sudo[17509]: pam_unix(sudo:session): session closed for user root Jan 27 21:04:42 volumio sudo[17512]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 27 21:04:42 volumio volumio[17104]: error: Cannot start Volumio Streaming Daemon Jan 27 21:04:42 volumio sudo[17512]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:04:42 volumio volumio[17104]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 21:04:42 volumio volumio[17104]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 21:04:42 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:04:42 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:04:42 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:04:42 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:04:42 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:04:42 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:04:42 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:04:42 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:04:42 volumio sudo[17512]: pam_unix(sudo:session): session closed for user root Jan 27 21:04:42 volumio volumio[17104]: info: Remote SSH Stopped Jan 27 21:04:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:04:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:04:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:04:42 volumio volumio[17104]: info: Initializing connection to go-librespot Websocket Jan 27 21:04:42 volumio volumio[17104]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:04:42 volumio volumio[17104]: info: Setting Geolocation for MyVolumio to as1 Jan 27 21:04:42 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:04:42 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:04:42 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:04:43 volumio volumio[17104]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 27 21:04:43 volumio volumio[17104]: info: Updating MyVolumio device info Jan 27 21:04:43 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:04:43 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:04:43 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:04:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 27 21:04:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:04:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:04:44 volumio go-librespot[17514]: go-librespot daemon starting... Jan 27 21:04:44 volumio go-librespot[17515]: time="2026-01-27T21:04:44+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:04:44 volumio go-librespot[17515]: time="2026-01-27T21:04:44+07:00" level=debug msg="app state loaded" Jan 27 21:04:44 volumio go-librespot[17515]: time="2026-01-27T21:04:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:04:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:04:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:04:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:04:44 volumio go-librespot[17515]: time="2026-01-27T21:04:44+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:04:44 volumio go-librespot[17515]: time="2026-01-27T21:04:44+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:04:44 volumio go-librespot[17515]: time="2026-01-27T21:04:44+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:04:44 volumio go-librespot[17515]: time="2026-01-27T21:04:44+07:00" level=info msg="zeroconf server listening on port 41863" Jan 27 21:04:45 volumio go-librespot[17515]: time="2026-01-27T21:04:45+07:00" level=debug msg="obtained new client token: AAB0iCwy2WMVEGQP5Xwkq8RjwOwosTgv9HfEk2vWpysK0tBImoUrueql3/zl/ZKaFkVw8EQQD2LF+BUM2Q378PPUAl/Ijrl2frMP/DbeUrcD2dn1wlxZM2vF+xzoTtqMYzG7Rc9yPkU5nFvZxkpJAhHZ7BrItRTJkxsBJDGqUuZbcSggX3FRRlKAwTjce2PaQI7NWapLf9xtzL/J5HFTT0aXDI8MGyuoYawLafXgfP2BVqB+iL0mJ7bW" Jan 27 21:04:45 volumio go-librespot[17515]: time="2026-01-27T21:04:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:04:45 volumio go-librespot[17515]: time="2026-01-27T21:04: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:04:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:04:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:04:45 volumio volumio[17104]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jan 27 21:04:45 volumio volumio[17104]: info: Initializing connection to go-librespot Websocket Jan 27 21:04:45 volumio volumio[17104]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:04:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:04:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:04:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:04:47 volumio volumio[17104]: info: MYVOLUMIO: Adding device Jan 27 21:04:47 volumio volumio[17104]: info: MYVOLUMIO: Evaluating Server Jan 27 21:04:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 27 21:04:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:04:48 volumio volumio[17104]: info: Setting Geolocation for MyVolumio to as1 Jan 27 21:04:48 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:04:48 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:04:48 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:04:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:04:48 volumio go-librespot[17555]: go-librespot daemon starting... Jan 27 21:04:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:04:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:04:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:04:48 volumio go-librespot[17556]: time="2026-01-27T21:04:48+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:04:48 volumio go-librespot[17556]: time="2026-01-27T21:04:48+07:00" level=debug msg="app state loaded" Jan 27 21:04:48 volumio go-librespot[17556]: time="2026-01-27T21:04:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:04:48 volumio volumio[17104]: info: Initializing connection to go-librespot Websocket Jan 27 21:04:48 volumio go-librespot[17556]: time="2026-01-27T21:04:48+07:00" level=debug msg="new websocket client" Jan 27 21:04:48 volumio volumio[17104]: info: Connection to go-librespot Websocket established Jan 27 21:04:49 volumio go-librespot[17556]: time="2026-01-27T21:04: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 21:04:49 volumio go-librespot[17556]: time="2026-01-27T21:04:49+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:04:49 volumio go-librespot[17556]: time="2026-01-27T21:04:49+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:04:49 volumio go-librespot[17556]: time="2026-01-27T21:04:49+07:00" level=info msg="zeroconf server listening on port 33817" Jan 27 21:04:49 volumio go-librespot[17556]: time="2026-01-27T21:04:49+07:00" level=debug msg="obtained new client token: AACQWAgLPGa6SeHx8FurRGYPCREvl8NwufB+u/yhB+0PzK+MrDBpXwZmmgxBUM09Cl5BTbKuzc/scawt9CpnUrcYHmloyodjJs7wMpxF+zzqC6xeJdJJpjiZKjmNjbkFhOu25hqGjSKHulMYk0YRV3A8A+wHNWaPzceU8QllCij/zEiwOHPS/CaW03GZvsjj+a770eISWSxoqhqodRUWFKVx4nL1iTVJj5rUAG6joZjooQhvWnEtZbfefC0=" Jan 27 21:04:49 volumio go-librespot[17556]: time="2026-01-27T21:04:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 21:04:49 volumio volumio[17104]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 27 21:04:49 volumio volumio[17104]: info: Updating MyVolumio device info Jan 27 21:04:49 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:04:49 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:04:49 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:04:49 volumio go-librespot[17556]: time="2026-01-27T21:04: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:04:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 21:04:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 21:04:49 volumio volumio[17104]: info: Connection to go-librespot Websocket closed Jan 27 21:04:49 volumio volumio[17104]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jan 27 21:04:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:04:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:04:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:04:51 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 21:04:51 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 21:04:51 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 27 21:04:51 volumio volumio-remote-updater[628]: Test mode disabled Jan 27 21:04:51 volumio volumio-remote-updater[628]: Alpha mode disabled Jan 27 21:04:51 volumio volumio-remote-updater[628]: Alpha legacy test mode disabled Jan 27 21:04:51 volumio volumio[17104]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Jan 27 21:04:51 volumio volumio[17104]: info: Getting Spotify volume Jan 27 21:04:51 volumio volumio[17104]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 21:04:51 volumio volumio[17104]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 21:04:51 volumio volumio[17104]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 27 21:04:51 volumio volumio[17104]: errno: -111, Jan 27 21:04:51 volumio volumio[17104]: code: 'ECONNREFUSED', Jan 27 21:04:51 volumio volumio[17104]: syscall: 'connect', Jan 27 21:04:51 volumio volumio[17104]: address: '127.0.0.1', Jan 27 21:04:51 volumio volumio[17104]: port: 9879, Jan 27 21:04:51 volumio volumio[17104]: response: undefined Jan 27 21:04:51 volumio volumio[17104]: } Jan 27 21:04:51 volumio volumio[17104]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 21:04:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 21:04:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 21:04:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 21:04:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 27 21:04:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:04:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 21:04:52 volumio go-librespot[17580]: go-librespot daemon starting... Jan 27 21:04:52 volumio go-librespot[17581]: time="2026-01-27T21:04:52+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 21:04:52 volumio go-librespot[17581]: time="2026-01-27T21:04:52+07:00" level=debug msg="app state loaded" Jan 27 21:04:52 volumio go-librespot[17581]: time="2026-01-27T21:04:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 21:04:53 volumio sudo[17590]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 21:03' Jan 27 21:04:53 volumio sudo[17590]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 21:04:53 volumio go-librespot[17581]: time="2026-01-27T21:04:53+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:04:53 volumio go-librespot[17581]: time="2026-01-27T21:04:53+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:04:53 volumio go-librespot[17581]: time="2026-01-27T21:04:53+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:04:53 volumio go-librespot[17581]: time="2026-01-27T21:04:53+07:00" level=info msg="zeroconf server listening on port 34665" Jan 27 21:04:53 volumio go-librespot[17581]: time="2026-01-27T21:04:53+07:00" level=debug msg="obtained new client token: AAAGgEpvdjvB2YFuilKLP2nB82Ur81aqdYL+ZeH9x+nmTlrnd/7gDYN64kKnvzzKcLh+7QBo6zIaqO0PdEJDDfZ/zrIv/TUUQ0NcBRjIF3tBzYmNOHK7ycaEVvSZyoAPLucr1lPXuune+4KdLJG6Rfbpmgl9fe5o0pvC9K554FT3kcx7kAF2kLJWUVbY6VtoqrAU7PYJCp+BAUh8rqPIDqiFekpYZR7pnvP61J+1oxgK5HMgVx3FgVAG//E=" Jan 27 21:04:53 volumio go-librespot[17581]: time="2026-01-27T21:04:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" 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"