Jan 28 14:51:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:51:00 volumio go-librespot[13495]: go-librespot daemon starting... Jan 28 14:51:00 volumio go-librespot[13496]: time="2026-01-28T14:51:00+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:51:00 volumio go-librespot[13496]: time="2026-01-28T14:51:00+07:00" level=debug msg="app state loaded" Jan 28 14:51:00 volumio go-librespot[13496]: time="2026-01-28T14:51:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:51:00 volumio volumio[13151]: info: Initializing connection to go-librespot Websocket Jan 28 14:51:00 volumio go-librespot[13496]: time="2026-01-28T14:51:00+07:00" level=debug msg="new websocket client" Jan 28 14:51:00 volumio volumio[13151]: info: Connection to go-librespot Websocket established Jan 28 14:51:00 volumio go-librespot[13496]: time="2026-01-28T14:51: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 14:51:00 volumio go-librespot[13496]: time="2026-01-28T14:51:00+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 14:51:00 volumio go-librespot[13496]: time="2026-01-28T14:51:00+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 14:51:00 volumio go-librespot[13496]: time="2026-01-28T14:51:00+07:00" level=info msg="zeroconf server listening on port 33567" Jan 28 14:51:00 volumio go-librespot[13496]: time="2026-01-28T14:51:00+07:00" level=debug msg="obtained new client token: AAA0LL+qiS2Ml6cua1SfZH6s+c/j9coVXCuDGcBLorfukXYyyEhQjMtD/uVzdmEkcHx8qATkr0T5d2rvZyqZrQnyRbdHitxmqhedjkGg5B/MEy0RpIZrPdxqkCa54ToEkgq94DixOYe000ZMByLTEP3Jy5ewcqfqa8yp1vnOVdJIpvwRXFBF+tAm4IU4ZEPwwl5OU0/lzZ/aKBiKoUy7qjwrEKtCcFdIshvFiQ9xrZOGxBc5ysseywBzN0w=" Jan 28 14:51:00 volumio go-librespot[13496]: time="2026-01-28T14:51:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:51:01 volumio go-librespot[13496]: time="2026-01-28T14:51:01+07:00" level=debug msg="completed keyexchange" Jan 28 14:51:01 volumio go-librespot[13496]: time="2026-01-28T14:51:01+07:00" level=debug msg="completed challenge" Jan 28 14:51:01 volumio volumio[13151]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 14:51:01 volumio volumio[13151]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 14:51:01 volumio volumio[13151]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 14:51:01 volumio volumio[13151]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 14:51:01 volumio volumio[13151]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 14:51:01 volumio volumio[13151]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 14:51:01 volumio volumio[13151]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 14:51:01 volumio volumio[13151]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 14:51:01 volumio volumio[13151]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 14:51:01 volumio volumio[13151]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 14:51:01 volumio volumio[13151]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 14:51:01 volumio volumio[13151]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 14:51:01 volumio volumio[13151]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 14:51:01 volumio volumio[13151]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 14:51:01 volumio volumio[13151]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 14:51:01 volumio volumio[13151]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 14:51:01 volumio volumio[13151]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 14:51:01 volumio volumio[13151]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 14:51:01 volumio volumio[13151]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 14:51:01 volumio volumio[13151]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 14:51:01 volumio volumio[13151]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 14:51:01 volumio volumio[13151]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 14:51:01 volumio volumio[13151]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 14:51:01 volumio volumio[13151]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 14:51:01 volumio volumio[13151]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 14:51:01 volumio volumio[13151]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 14:51:01 volumio volumio[13151]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 14:51:01 volumio volumio[13151]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 14:51:01 volumio volumio[13151]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 14:51:01 volumio volumio[13151]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 14:51:01 volumio volumio[13151]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 14:51:01 volumio volumio[13151]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 14:51:01 volumio volumio[13151]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 14:51:01 volumio volumio[13151]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 14:51:01 volumio volumio[13151]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 14:51:01 volumio volumio[13151]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 14:51:01 volumio go-librespot[13496]: time="2026-01-28T14:51: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 28 14:51:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:51:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:51:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:51:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:51:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:51:03 volumio volumio[13151]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 14:51:03 volumio volumio[13151]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 14:51:03 volumio volumio[13151]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:51:03 volumio volumio[13151]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:51:03 volumio volumio[13151]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 14:51:03 volumio volumio[13151]: info: MyVolumio login type: Token Jan 28 14:51:03 volumio volumio[13151]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 14:51:03 volumio volumio[13151]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 14:51:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:51:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:51:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:51:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 28 14:51:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:51:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:51:04 volumio go-librespot[13517]: go-librespot daemon starting... Jan 28 14:51:04 volumio go-librespot[13518]: time="2026-01-28T14:51:04+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:51:04 volumio go-librespot[13518]: time="2026-01-28T14:51:04+07:00" level=debug msg="app state loaded" Jan 28 14:51:04 volumio go-librespot[13518]: time="2026-01-28T14:51:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:51:04 volumio volumio[13151]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 14:51:04 volumio volumio[13151]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 14:51:04 volumio volumio[13151]: info: Streaming services startup Jan 28 14:51:04 volumio volumio[13151]: info: Starting Streaming Daemon Jan 28 14:51:04 volumio sudo[13527]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 14:51:04 volumio sudo[13527]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:51:04 volumio volumio[13151]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 14:51:04 volumio go-librespot[13518]: time="2026-01-28T14:51:04+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 14:51:04 volumio go-librespot[13518]: time="2026-01-28T14:51:04+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 14:51:04 volumio go-librespot[13518]: time="2026-01-28T14:51:04+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 14:51:04 volumio go-librespot[13518]: time="2026-01-28T14:51:04+07:00" level=info msg="zeroconf server listening on port 44405" Jan 28 14:51:04 volumio sudo[13527]: pam_unix(sudo:session): session closed for user root Jan 28 14:51:04 volumio volumio[13151]: info: Getting Spotify volume Jan 28 14:51:05 volumio volumio[13151]: info: Connection to go-librespot Websocket closed Jan 28 14:51:05 volumio volumio[13151]: error: Cannot start Volumio Streaming Daemon Jan 28 14:51:05 volumio volumio[13151]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 14:51:05 volumio volumio[13151]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 14:51:05 volumio volumio[13151]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 28 14:51:05 volumio go-librespot[13518]: time="2026-01-28T14:51:05+07:00" level=debug msg="obtained new client token: AACl3rcwoGA84oTfhILFbLPe2YjatrogO0eUN7GV/KYovRpY2hTBV+eY9niDABHMby34IMkHFwa0DFuQryi8iE3f/Q1+euZ5REZ5SLmF/8zZyQH4P6w9OGGCCHBVkV+8Zy7VlAT6uHdWHolT/XjC9c/4FBrIkVcfVQ32wmgW8/Jq2lQK2RvPe2Kop+NsGLJGQC6fUsGWM/P9f1Ho/cfyfGdZeDy6WLjXa9f3Nr9BEQvv2sLH2zKpoTPg" Jan 28 14:51:05 volumio go-librespot[13518]: time="2026-01-28T14:51:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:51:05 volumio volumio[13151]: info: CoreCommandRouter::volumioGetState Jan 28 14:51:05 volumio volumio[13151]: info: CorePlayQueue::getTrack 0 Jan 28 14:51:05 volumio volumio[13151]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 28 14:51:05 volumio volumio[13151]: SPOTIFY: SPOTIFY VOLUME undefined Jan 28 14:51:05 volumio volumio[13151]: SPOTIFY: VOLUMIO VOLUME 100 Jan 28 14:51:05 volumio volumio[13151]: info: Aligning Spotify Volume to Volumio Volume Jan 28 14:51:05 volumio volumio[13151]: info: CoreCommandRouter::volumioGetState Jan 28 14:51:05 volumio volumio[13151]: info: CorePlayQueue::getTrack 0 Jan 28 14:51:05 volumio volumio[13151]: info: Setting Spotify Volume from Volumio: 100 Jan 28 14:51:05 volumio go-librespot[13518]: time="2026-01-28T14:51:05+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 14:51:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:51:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:51:05 volumio volumio[13151]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 14:51:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:51:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:51:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:51:05 volumio volumio[13151]: Error: socket hang up Jan 28 14:51:05 volumio volumio[13151]: at connResetException (node:internal/errors:720:14) Jan 28 14:51:05 volumio volumio[13151]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 14:51:05 volumio volumio[13151]: at Socket.emit (node:events:526:35) Jan 28 14:51:05 volumio volumio[13151]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 14:51:05 volumio volumio[13151]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 14:51:05 volumio volumio[13151]: code: 'ECONNRESET', Jan 28 14:51:05 volumio volumio[13151]: response: undefined Jan 28 14:51:05 volumio volumio[13151]: } Jan 28 14:51:05 volumio volumio[13151]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 14:51:06 volumio sudo[13547]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 14:50' Jan 28 14:51:06 volumio sudo[13547]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:51:07 volumio sudo[13547]: pam_unix(sudo:session): session closed for user root Jan 28 14:51:07 volumio volumio-remote-updater[628]: [2026-01-28 14:51:07] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 28 14:51:07 volumio volumio-remote-updater[628]: [2026-01-28 14:51:07] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 28 14:51:07 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:51:07 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 14:51:07 volumio systemd[1]: volumio.service: Consumed 58.862s CPU time. Jan 28 14:51:07 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 14:51:07 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 14:51:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:51:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:51:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:51:07 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10284. Jan 28 14:51:07 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 14:51:07 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 14:51:07 volumio systemd[1]: volumio.service: Consumed 58.862s CPU time. Jan 28 14:51:07 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 14:51:07 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 14:51:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 28 14:51:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:51:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:51:08 volumio go-librespot[13578]: go-librespot daemon starting... Jan 28 14:51:08 volumio go-librespot[13579]: time="2026-01-28T14:51:08+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:51:08 volumio go-librespot[13579]: time="2026-01-28T14:51:08+07:00" level=debug msg="app state loaded" Jan 28 14:51:08 volumio go-librespot[13579]: time="2026-01-28T14:51:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:51:09 volumio go-librespot[13579]: time="2026-01-28T14:51:09+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 14:51:09 volumio go-librespot[13579]: time="2026-01-28T14:51:09+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 14:51:09 volumio go-librespot[13579]: time="2026-01-28T14:51:09+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 14:51:09 volumio go-librespot[13579]: time="2026-01-28T14:51:09+07:00" level=info msg="zeroconf server listening on port 36393" Jan 28 14:51:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:51:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:51:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:51:09 volumio go-librespot[13579]: time="2026-01-28T14:51:09+07:00" level=debug msg="obtained new client token: AADAgKSxF+HFqZVDKCVH90Ku62v3uKgV4kU7NBmFgguJDNmVKBrbm+BhvXBGef5reCA5Bhwk2uvnZOcltrkXnPHdBmnxq4nEw3Pwe2c7ZMUqBO+pmMsJ/NWkp+lS/ylCvSv9a6CUMrYZ/XpU2oo8yoO6rp7hJy0RIHhspRvOlQlg44PB25+fce5hSy4mmzAVNCfHoL3j61bN7Io1Y7H49k4HaY4gppEw0WydzRsCgOtQgcNu3bVM3KOqcho=" Jan 28 14:51:09 volumio go-librespot[13579]: time="2026-01-28T14:51:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:51:09 volumio go-librespot[13579]: time="2026-01-28T14:51:09+07:00" level=debug msg="completed keyexchange" Jan 28 14:51:09 volumio go-librespot[13579]: time="2026-01-28T14:51:09+07:00" level=debug msg="completed challenge" Jan 28 14:51:09 volumio go-librespot[13579]: time="2026-01-28T14:51:09+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 14:51:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:51:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:51:11 volumio volumio[13563]: info: ------------------------------------------- Jan 28 14:51:11 volumio volumio[13563]: info: ----- Volumio3 ---- Jan 28 14:51:11 volumio volumio[13563]: info: ------------------------------------------- Jan 28 14:51:11 volumio volumio[13563]: info: ----- System startup ---- Jan 28 14:51:11 volumio volumio[13563]: info: ------------------------------------------- Jan 28 14:51:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:51:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:51:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:51:12 volumio volumio-remote-updater[628]: [2026-01-28 14:51:12] [connect] Successful connection Jan 28 14:51:12 volumio volumio[13563]: info: MYVOLUMIO Environment detected Jan 28 14:51:12 volumio volumio[13563]: info: Plugin folders cleanup Jan 28 14:51:12 volumio volumio[13563]: info: Scanning into folder /volumio/app/plugins/ Jan 28 14:51:12 volumio volumio[13563]: info: Scanning category audio_interface Jan 28 14:51:12 volumio volumio[13563]: info: Scanning category miscellanea Jan 28 14:51:12 volumio volumio[13563]: info: Scanning category music_service Jan 28 14:51:12 volumio volumio[13563]: info: Scanning category plugins.json Jan 28 14:51:12 volumio volumio[13563]: info: Scanning category system_controller Jan 28 14:51:12 volumio volumio[13563]: info: Scanning category user_interface Jan 28 14:51:12 volumio volumio[13563]: info: Scanning into folder /data/plugins/ Jan 28 14:51:12 volumio volumio[13563]: info: Scanning category music_service Jan 28 14:51:12 volumio volumio[13563]: info: Plugin folders cleanup completed Jan 28 14:51:12 volumio volumio[13563]: info: ------------------------------------------- Jan 28 14:51:12 volumio volumio[13563]: info: ----- Core plugins startup ---- Jan 28 14:51:12 volumio volumio[13563]: info: ------------------------------------------- Jan 28 14:51:12 volumio volumio[13563]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 14:51:12 volumio volumio[13563]: info: Adding plugin upnp to MyMusic Plugins Jan 28 14:51:12 volumio volumio[13563]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 14:51:12 volumio volumio[13563]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 14:51:12 volumio volumio[13563]: info: Loading plugins from folder /data/plugins/ Jan 28 14:51:12 volumio volumio[13563]: info: Loading plugin "system"... Jan 28 14:51:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 28 14:51:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:51:12 volumio volumio[13563]: info: Loading plugin "appearance"... Jan 28 14:51:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:51:12 volumio go-librespot[13596]: go-librespot daemon starting... Jan 28 14:51:12 volumio go-librespot[13600]: time="2026-01-28T14:51:12+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:51:12 volumio go-librespot[13600]: time="2026-01-28T14:51:12+07:00" level=debug msg="app state loaded" Jan 28 14:51:12 volumio go-librespot[13600]: time="2026-01-28T14:51:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:51:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:51:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:51:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:51:13 volumio go-librespot[13600]: time="2026-01-28T14:51:13+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 14:51:13 volumio go-librespot[13600]: time="2026-01-28T14:51:13+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 14:51:13 volumio go-librespot[13600]: time="2026-01-28T14:51:13+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 14:51:13 volumio go-librespot[13600]: time="2026-01-28T14:51:13+07:00" level=info msg="zeroconf server listening on port 40187" Jan 28 14:51:13 volumio go-librespot[13600]: time="2026-01-28T14:51:13+07:00" level=debug msg="obtained new client token: AAAj6Si42QrekAWzSWjrE2LBGTXt10hoTeAlorPLTzkbW1u5BrdIqEzPIXmQboHK9VCxZhEqf4yf0waXWHc8jhxrJnXpR+APmUW7h1txjZsPKiYR6ApJLPAgKK7taqM6KMkrHo24tgWs27ABm8/VcgvfyAkbBxCKHxrl9hd364mQ5Ckyx7Sdpb3yq2t4UsY6Nd3OipwsuDiBrEmK5WfzxS78eXiCCQAlh3Su0KLixKzI5t/EK58XtWQZXLY=" Jan 28 14:51:13 volumio go-librespot[13600]: time="2026-01-28T14:51:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:51:13 volumio go-librespot[13600]: time="2026-01-28T14:51:13+07:00" level=debug msg="completed keyexchange" Jan 28 14:51:13 volumio go-librespot[13600]: time="2026-01-28T14:51:13+07:00" level=debug msg="completed challenge" Jan 28 14:51:13 volumio go-librespot[13600]: time="2026-01-28T14:51:13+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 14:51:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:51:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:51:14 volumio volumio[13563]: info: Loading plugin "network"... Jan 28 14:51:14 volumio volumio[13563]: info: Refreshing Cached IP Addresses Jan 28 14:51:14 volumio sudo[13608]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 14:51:14 volumio sudo[13608]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:51:14 volumio sudo[13608]: pam_unix(sudo:session): session closed for user root Jan 28 14:51:14 volumio sudo[13610]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 14:51:14 volumio sudo[13610]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:51:14 volumio volumio[13563]: info: Loading plugin "services"... Jan 28 14:51:14 volumio volumio[13563]: info: Loading plugin "alsa_controller"... Jan 28 14:51:14 volumio sudo[13610]: pam_unix(sudo:session): session closed for user root Jan 28 14:51:14 volumio sudo[13618]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 14:51:14 volumio sudo[13618]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:51:14 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 14:51:14 volumio volumio[13563]: info: Loading plugin "wizard"... Jan 28 14:51:14 volumio volumio[13563]: info: Loading plugin "networkfs"... Jan 28 14:51:15 volumio volumio[13563]: info: Starting Udev Watcher for removable devices Jan 28 14:51:15 volumio volumio[13563]: info: Ignoring mount for partition: boot Jan 28 14:51:15 volumio volumio[13563]: info: Ignoring mount for partition: volumio Jan 28 14:51:15 volumio volumio[13563]: info: Ignoring mount for partition: volumio_data Jan 28 14:51:15 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 14:51:15 volumio volumio[13563]: info: Loading plugin "volumio_command_line_client"... Jan 28 14:51:15 volumio volumio[13563]: info: Loading plugin "upnp"... Jan 28 14:51:15 volumio volumio[13563]: info: [1769586675129] Starting Upmpd Daemon Jan 28 14:51:15 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 14:51:15 volumio volumio[13563]: info: Loading plugin "my_music"... Jan 28 14:51:15 volumio volumio[13563]: info: Loading plugin "mpd"... Jan 28 14:51:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:51:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:51:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:51:15 volumio volumio[13563]: info: Loading plugin "upnp_browser"... Jan 28 14:51:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 28 14:51:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:51:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:51:17 volumio go-librespot[13641]: go-librespot daemon starting... Jan 28 14:51:17 volumio go-librespot[13642]: time="2026-01-28T14:51:17+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:51:17 volumio go-librespot[13642]: time="2026-01-28T14:51:17+07:00" level=debug msg="app state loaded" Jan 28 14:51:17 volumio go-librespot[13642]: time="2026-01-28T14:51:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:51:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:51:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:51:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:51:17 volumio go-librespot[13642]: time="2026-01-28T14:51:17+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 14:51:17 volumio go-librespot[13642]: time="2026-01-28T14:51:17+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 14:51:17 volumio go-librespot[13642]: time="2026-01-28T14:51:17+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 14:51:17 volumio go-librespot[13642]: time="2026-01-28T14:51:17+07:00" level=info msg="zeroconf server listening on port 41757" Jan 28 14:51:17 volumio sudo[13618]: pam_unix(sudo:session): session closed for user root Jan 28 14:51:17 volumio go-librespot[13642]: time="2026-01-28T14:51:17+07:00" level=debug msg="obtained new client token: AAA0LVJyohbitHS/BgiyY6Ek8DoVNcG4p/ufMpfe0xouwJudKEQvvqzZogRglnyjHeT3rvQ8vkWGkGSHkhY7303NeDAuTu/z0HFj5ak/jMHkLDogRFjt7YYXDyi2eyA1dvqPZ5w3PK0b6CVqfYojq7J86aukDioiRaFIoumomskta77EN5gfYlEaA2s+Bbez/YxyQCGzIm9JtyoMXa13ywHVSNVliPzj0xvPyZFhteTCMV3z7nJqkDCHUW8=" Jan 28 14:51:17 volumio go-librespot[13642]: time="2026-01-28T14:51:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:51:17 volumio go-librespot[13642]: time="2026-01-28T14:51:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 14:51:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:51:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:51:18 volumio volumio[13563]: info: Starting UPNP Browser Jan 28 14:51:18 volumio volumio[13563]: info: Loading plugin "alarm-clock"... Jan 28 14:51:19 volumio volumio[13563]: info: Loading plugin "airplay_emulation"... Jan 28 14:51:19 volumio volumio[13563]: info: Starting Shairport Sync Jan 28 14:51:19 volumio volumio[13563]: info: Loading plugin "last_100"... Jan 28 14:51:19 volumio volumio[13563]: info: Loading plugin "webradio"... Jan 28 14:51:19 volumio volumio[13563]: info: Loading plugin "i2s_dacs"... Jan 28 14:51:19 volumio volumio[13563]: info: Loading plugin "volumiodiscovery"... Jan 28 14:51:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:51:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:51:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:51:19 volumio volumio[13563]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 14:51:19 volumio volumio[13563]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 14:51:19 volumio volumio[13563]: *** WARNING *** For more information see Jan 28 14:51:19 volumio volumio[13563]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 14:51:19 volumio volumio[13563]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 14:51:19 volumio volumio[13563]: *** WARNING *** For more information see Jan 28 14:51:19 volumio node[13563]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 14:51:19 volumio node[13563]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 14:51:19 volumio node[13563]: *** WARNING *** For more information see Jan 28 14:51:19 volumio node[13563]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 14:51:19 volumio node[13563]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 14:51:19 volumio node[13563]: *** WARNING *** For more information see Jan 28 14:51:19 volumio volumio[13563]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 14:51:19 volumio volumio[13563]: info: Discovery: Started advertising with name: Volumio Jan 28 14:51:19 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 14:51:19 volumio volumio[13563]: info: Loading plugin "spop"... Jan 28 14:51:21 volumio volumio[13563]: info: Loading plugin "ytcr"... Jan 28 14:51:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 28 14:51:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:51:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:51:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:51:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:51:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:51:21 volumio go-librespot[13651]: go-librespot daemon starting... Jan 28 14:51:21 volumio go-librespot[13652]: time="2026-01-28T14:51:21+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:51:21 volumio go-librespot[13652]: time="2026-01-28T14:51:21+07:00" level=debug msg="app state loaded" Jan 28 14:51:21 volumio go-librespot[13652]: time="2026-01-28T14:51:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:51:21 volumio go-librespot[13652]: time="2026-01-28T14:51:21+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 14:51:21 volumio go-librespot[13652]: time="2026-01-28T14:51:21+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 14:51:21 volumio go-librespot[13652]: time="2026-01-28T14:51:21+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 14:51:21 volumio go-librespot[13652]: time="2026-01-28T14:51:21+07:00" level=info msg="zeroconf server listening on port 42477" Jan 28 14:51:22 volumio go-librespot[13652]: time="2026-01-28T14:51:22+07:00" level=debug msg="obtained new client token: AADe26yJsmGpy/ZAbCm5LSt65AVb82LZLEeoyPKW2JTPeuK5uKL2fJAF51pmDEtOQN4bv4p/BZVXRaQsGN3dC/zQEOYt6IjpPLAN6K65lt4LjZRdii2hZsOv2eAEc2H4Gy1Emtp7kS3hGx+ixAtdU2EjfUqTuJ3nVpofsPpCF1Unk+/wWOI2tgRzae7kyDgbZ8m71I8RZfbTVFu2ZcpK141aIZR3M+tkOJjR/n5/wVfw6F/vzdOB1EEJ" Jan 28 14:51:22 volumio go-librespot[13652]: time="2026-01-28T14:51:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:51:22 volumio go-librespot[13652]: time="2026-01-28T14:51:22+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 14:51:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:51:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:51:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:51:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:51:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:51:23 volumio volumio[13563]: info: Loading plugin "ytmusic"... Jan 28 14:51:24 volumio volumio-remote-updater[628]: [2026-01-28 14:51:24] [connect] Successful connection Jan 28 14:51:24 volumio volumio[13563]: info: Loading plugin "outputs"... Jan 28 14:51:24 volumio volumio[13563]: info: Loading plugin "albumart"... Jan 28 14:51:24 volumio volumio[13563]: info: Plugin example_plugin is not enabled Jan 28 14:51:24 volumio volumio[13563]: info: Loading plugin "inputs"... Jan 28 14:51:24 volumio volumio[13563]: info: Loading plugin "updater_comm"... Jan 28 14:51:25 volumio volumio[13563]: info: Plugin mpdemulation is not enabled Jan 28 14:51:25 volumio volumio[13563]: info: Loading plugin "rest_api"... Jan 28 14:51:25 volumio volumio[13563]: info: Loading plugin "websocket"... Jan 28 14:51:25 volumio volumio[13563]: info: Starting Socket.io Server version 1.7.4 Jan 28 14:51:25 volumio volumio[13563]: info: Loading plugin "RoonBridge"... Jan 28 14:51:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:51:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:51:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:51:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 28 14:51:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:51:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:51:25 volumio go-librespot[13683]: go-librespot daemon starting... Jan 28 14:51:25 volumio go-librespot[13684]: time="2026-01-28T14:51:25+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:51:25 volumio go-librespot[13684]: time="2026-01-28T14:51:25+07:00" level=debug msg="app state loaded" Jan 28 14:51:25 volumio go-librespot[13684]: time="2026-01-28T14:51:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:51:25 volumio volumio[13563]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 14:51:25 volumio volumio[13563]: info: Loading i18n strings for locale en Jan 28 14:51:25 volumio volumio[13563]: Updating browse sources language Jan 28 14:51:25 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 14:51:26 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 14:51:26 volumio volumio[13563]: info: CoreCommandRouter::initPlayerControls Jan 28 14:51:26 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:51:26 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:51:26 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:51:26 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:51:26 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:51:26 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:51:26 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:51:26 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:51:26 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 14:51:26 volumio volumio[13563]: Express server listening on port 3000 Jan 28 14:51:26 volumio volumio[13672]: Forking 3 albumart workers Jan 28 14:51:26 volumio volumio[13563]: [Metrics] WebUI: 15s 882.94ms Jan 28 14:51:26 volumio go-librespot[13684]: time="2026-01-28T14:51:26+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 14:51:26 volumio go-librespot[13684]: time="2026-01-28T14:51:26+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 14:51:26 volumio go-librespot[13684]: time="2026-01-28T14:51:26+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 14:51:26 volumio volumio[13563]: info: CoreStateMachine::resetVolumioState Jan 28 14:51:26 volumio volumio[13563]: info: CoreStateMachine::getcurrentVolume Jan 28 14:51:26 volumio volumio[13563]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 14:51:26 volumio go-librespot[13684]: time="2026-01-28T14:51:26+07:00" level=info msg="zeroconf server listening on port 35163" Jan 28 14:51:26 volumio sudo[13715]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 14:51:26 volumio sudo[13715]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:51:26 volumio sudo[13715]: pam_unix(sudo:session): session closed for user root Jan 28 14:51:26 volumio sudo[13717]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 14:51:26 volumio go-librespot[13684]: time="2026-01-28T14:51:26+07:00" level=debug msg="obtained new client token: AAAOYQdTnoYf8ppUtkpMrq1/guAcsHM7hirOAIfeoPShZzs+8Dt33xbRPVKCuKoIh1u4idg8slag/+F0RO6b/7ape7LVDeaN9iJzS1NQwIzDi6y6w/mnLqcXzpueR2fMKhTf3bZFraEVO/AlIbohI1ZK2jSxz52eiRgcCj76F+dcLwqeKEq5yAJvB3qRh9PPGJBkXNfYrVRLIoJhgi9S2MFLhUKsL4xhuFow9nsZNCyXM1gocSRDiGJiP54=" Jan 28 14:51:26 volumio sudo[13717]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:51:26 volumio sudo[13717]: pam_unix(sudo:session): session closed for user root Jan 28 14:51:26 volumio volumio[13563]: info: Volumio Network Manager: Network status updated: 1 Jan 28 14:51:26 volumio go-librespot[13684]: time="2026-01-28T14:51:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:51:26 volumio go-librespot[13684]: time="2026-01-28T14:51:26+07:00" level=debug msg="completed keyexchange" Jan 28 14:51:26 volumio go-librespot[13684]: time="2026-01-28T14:51:26+07:00" level=debug msg="completed challenge" Jan 28 14:51:26 volumio volumio[13563]: info: VolumeController:: Volume=100 Mute =false Jan 28 14:51:26 volumio volumio[13563]: info: CoreStateMachine::pushState Jan 28 14:51:26 volumio volumio[13563]: info: CorePlayQueue::getTrack 0 Jan 28 14:51:26 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 14:51:26 volumio volumio[13563]: info: CoreCommandRouter::volumioPushState Jan 28 14:51:26 volumio go-librespot[13684]: time="2026-01-28T14:51:26+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 14:51:26 volumio volumio[13563]: info: CoreStateMachine::updateTrackBlock Jan 28 14:51:26 volumio volumio[13563]: info: CorePlayQueue::getTrackBlock Jan 28 14:51:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:51:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:51:26 volumio volumio[13563]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 14:51:26 volumio volumio-remote-updater[628]: [2026-01-28 14:51:26] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769586684 101 Jan 28 14:51:26 volumio volumio[13563]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 28 14:51:26 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:51:26 volumio volumio[13563]: info: Reloading queue from file Jan 28 14:51:27 volumio volumio[13563]: info: CoreStateMachine::setRepeat null single undefined Jan 28 14:51:27 volumio volumio[13563]: info: CoreStateMachine::pushState Jan 28 14:51:27 volumio volumio[13563]: info: CorePlayQueue::getTrack 0 Jan 28 14:51:27 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 14:51:27 volumio volumio[13563]: info: CoreCommandRouter::volumioPushState Jan 28 14:51:27 volumio volumio[13563]: info: CoreStateMachine::setRandom null Jan 28 14:51:27 volumio volumio[13563]: info: CoreStateMachine::pushState Jan 28 14:51:27 volumio volumio[13563]: info: CorePlayQueue::getTrack 0 Jan 28 14:51:27 volumio volumio[13563]: info: CoreCommandRouter::volumioPushState Jan 28 14:51:27 volumio volumio[13563]: info: Setting Device type: Raspberry PI Jan 28 14:51:27 volumio volumio[13563]: info: Completed loading Core Plugins Jan 28 14:51:27 volumio volumio[13563]: info: Preparing to generate the ALSA configuration file Jan 28 14:51:27 volumio volumio[13563]: info: VolumeController:: Volume=100 Mute =false Jan 28 14:51:27 volumio volumio[13563]: info: CoreStateMachine::pushState Jan 28 14:51:27 volumio volumio[13563]: info: CorePlayQueue::getTrack 0 Jan 28 14:51:27 volumio volumio[13563]: info: CoreCommandRouter::volumioPushState Jan 28 14:51:27 volumio volumio[13563]: info: Asound.conf file unchanged, so no further update is needed Jan 28 14:51:27 volumio volumio[13563]: info: Output device has changed, restarting MPD Jan 28 14:51:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:51:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:51:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:51:27 volumio volumio[13563]: info: Output device has changed, restarting Shairport Sync Jan 28 14:51:27 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:51:27 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:51:27 volumio sudo[13742]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 14:51:27 volumio sudo[13742]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:51:27 volumio sudo[13744]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 14:51:27 volumio sudo[13744]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:51:27 volumio sudo[13744]: pam_unix(sudo:session): session closed for user root Jan 28 14:51:27 volumio volumio[13563]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 14:51:27 volumio sudo[13746]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 14:51:27 volumio sudo[13746]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:51:27 volumio volumio[13563]: info: ___________ START PLUGINS ___________ Jan 28 14:51:27 volumio volumio[13563]: info: ControllerMpd::onStart: Initializing MPD Jan 28 14:51:27 volumio volumio[13563]: info: Creating MPD Configuration file Jan 28 14:51:27 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 14:51:27 volumio volumio[13563]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 14:51:27 volumio volumio[13563]: info: [1769586687526] CoreMusicLibrary::Adding element Media Servers Jan 28 14:51:27 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 14:51:27 volumio sudo[13742]: pam_unix(sudo:session): session closed for user root Jan 28 14:51:27 volumio sudo[13756]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 14:51:27 volumio sudo[13756]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:51:27 volumio volumio[13563]: info: UPNP Browser: Client initialized successfully Jan 28 14:51:27 volumio sudo[13756]: pam_unix(sudo:session): session closed for user root Jan 28 14:51:27 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 14:51:27 volumio sudo[13757]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 14:51:27 volumio sudo[13757]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:51:27 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:51:27 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:51:27 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 14:51:27 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 14:51:27 volumio systemd[1]: mpd.service: Consumed 7.424s CPU time. Jan 28 14:51:27 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 14:51:27 volumio volumio[13563]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 14:51:27 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 14:51:27 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 14:51:27 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:51:27 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:51:27 volumio volumio[13563]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 14:51:27 volumio volumio[13563]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 14:51:27 volumio volumio[13563]: info: [1769586687877] CoreMusicLibrary::Adding element Last_100 Jan 28 14:51:27 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 14:51:27 volumio volumio[13563]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 14:51:27 volumio volumio[13563]: info: [1769586687897] CoreMusicLibrary::Adding element Webradio Jan 28 14:51:27 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 14:51:27 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 14:51:27 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 14:51:27 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 14:51:27 volumio volumio[13563]: info: Initializing BBC Radios Jan 28 14:51:27 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 14:51:27 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 14:51:27 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 14:51:27 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 14:51:27 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 14:51:28 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 14:51:28 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 14:51:28 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 14:51:28 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:51:28 volumio volumio[13563]: info: Creating Spotify config file Jan 28 14:51:28 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:51:28 volumio sudo[13773]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 14:51:28 volumio sudo[13773]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 14:51:28 volumio sudo[13773]: pam_unix(sudo:session): session closed for user root Jan 28 14:51:29 volumio volumio[13563]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 14:51:29 volumio volumio[13563]: info: [1769586689123] CoreMusicLibrary::Adding element YouTube Music Jan 28 14:51:29 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 14:51:29 volumio volumio[13563]: Cannot find translation for source YouTube Music Jan 28 14:51:29 volumio volumio[13692]: Starting albumart workers Jan 28 14:51:29 volumio volumio[13563]: info: Volumio Calling Home Jan 28 14:51:29 volumio sudo[13788]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 14:51:29 volumio sudo[13788]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:51:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:51:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:51:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:51:29 volumio sudo[13788]: pam_unix(sudo:session): session closed for user root Jan 28 14:51:29 volumio volumio[13695]: Starting albumart workers Jan 28 14:51:29 volumio volumio[13697]: Starting albumart workers Jan 28 14:51:29 volumio volumio[13563]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 14:51:29 volumio volumio[13563]: info: Discovery: Found device Volumio Jan 28 14:51:29 volumio volumio[13563]: info: CoreCommandRouter::volumioGetState Jan 28 14:51:29 volumio volumio[13563]: info: CorePlayQueue::getTrack 0 Jan 28 14:51:29 volumio volumio[13563]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 14:51:29 volumio volumio[13563]: info: Discovery: Found device Volumio Jan 28 14:51:29 volumio volumio[13563]: info: CoreCommandRouter::volumioGetState Jan 28 14:51:29 volumio volumio[13563]: info: CorePlayQueue::getTrack 0 Jan 28 14:51:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 28 14:51:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:51:30 volumio volumio[13563]: info: MPD Permissions set Jan 28 14:51:30 volumio volumio[13563]: info: MPD Permissions set Jan 28 14:51:30 volumio volumio[13563]: info: Upmpdcli Daemon Started Jan 28 14:51:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:51:30 volumio go-librespot[13793]: go-librespot daemon starting... Jan 28 14:51:30 volumio volumio[13563]: info: Spotify config file written Jan 28 14:51:30 volumio go-librespot[13794]: time="2026-01-28T14:51:30+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:51:30 volumio go-librespot[13794]: time="2026-01-28T14:51:30+07:00" level=debug msg="app state loaded" Jan 28 14:51:30 volumio go-librespot[13794]: time="2026-01-28T14:51:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:51:30 volumio sudo[13802]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 14:51:30 volumio sudo[13802]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:51:30 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 14:51:30 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 14:51:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:51:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:51:30 volumio go-librespot[13804]: go-librespot daemon starting... Jan 28 14:51:30 volumio sudo[13802]: pam_unix(sudo:session): session closed for user root Jan 28 14:51:30 volumio go-librespot[13805]: time="2026-01-28T14:51:30+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:51:30 volumio go-librespot[13805]: time="2026-01-28T14:51:30+07:00" level=debug msg="app state loaded" Jan 28 14:51:30 volumio go-librespot[13805]: time="2026-01-28T14:51:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:51:31 volumio volumio[13563]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 14:51:31 volumio go-librespot[13805]: time="2026-01-28T14:51:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 14:51:31 volumio go-librespot[13805]: time="2026-01-28T14:51:31+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 14:51:31 volumio go-librespot[13805]: time="2026-01-28T14:51:31+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 14:51:31 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:51:31 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:51:31 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:51:31 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:51:31 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:51:31 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:51:31 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:51:31 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:51:31 volumio go-librespot[13805]: time="2026-01-28T14:51:31+07:00" level=info msg="zeroconf server listening on port 41127" Jan 28 14:51:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:51:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:51:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:51:31 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:51:31 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:51:31 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:51:31 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:51:31 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:51:31 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:51:31 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:51:31 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:51:31 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:51:31 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:51:31 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:51:31 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:51:31 volumio volumio[13563]: info: No need to fix Spotify hosts Jan 28 14:51:31 volumio go-librespot[13805]: time="2026-01-28T14:51:31+07:00" level=debug msg="obtained new client token: AAATbuRyeZzKdp1nuKp/LAE9dAI6qd9o/alcUT2okNI4kcIOlSjg6VHM06cACnoGAQSjBrved9uYM3+0DEcp8lnnmr1nW8vBiTKUQiHv0+mRbLq4kzw9IYX+GQTN6uQIpJlRa/bzzQ27y7cf4whSA0/np48+LbgkBc5bQBVJ9Id+dXKiQ7a2F9h8cEiYx6jiEPUbkqU+BMaiMeF4ioRPN3Tr8sJaQDhJG46vI9rzAX5i7V7qq/Qc6flIgXs=" Jan 28 14:51:31 volumio go-librespot[13805]: time="2026-01-28T14:51:31+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 28 14:51:31 volumio go-librespot[13805]: time="2026-01-28T14:51:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 14:51:31 volumio go-librespot[13805]: time="2026-01-28T14:51:31+07:00" level=debug msg="completed keyexchange" Jan 28 14:51:31 volumio go-librespot[13805]: time="2026-01-28T14:51:31+07:00" level=debug msg="completed challenge" Jan 28 14:51:31 volumio go-librespot[13805]: time="2026-01-28T14:51:31+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 14:51:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:51:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:51:32 volumio volumio[13563]: info: Volumio called home Jan 28 14:51:32 volumio volumio[13563]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 14:51:32 volumio volumio[13563]: SPOTIFY: BQC9BgRieEAC3aEuCffvnr7lYeUULX94XFdei6U08Ca720eOtm9yEm6CKFBZtpEPZrMviOftRox3UvncxOVv0gsam3EO5laWtU9AAj-gfCcnqj0ol3UqERdUEltdiaw4Jgzj3iziDIq59FccpLmjvdaaFoVCYhfjDJSFYxlRap05bsJOaVvSBdrjLE6u_Ms679YyvLkRP62UmlCstm4a8khNTh9Xo5Y3YBvnMx5QFt_6tgrBnmDGDstGv1OmItJ9oR2eGGzLBpeoy9jp0OTbLqw45dxhbGtCi2JFgtsqmVDligWtsDv7MDts Jan 28 14:51:32 volumio volumio[13563]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 14:51:32 volumio volumio[13563]: info: New Spotify access token = BQC9BgRieEAC3aEuCffvnr7lYeUULX94XFdei6U08Ca720eOtm9yEm6CKFBZtpEPZrMviOftRox3UvncxOVv0gsam3EO5laWtU9AAj-gfCcnqj0ol3UqERdUEltdiaw4Jgzj3iziDIq59FccpLmjvdaaFoVCYhfjDJSFYxlRap05bsJOaVvSBdrjLE6u_Ms679YyvLkRP62UmlCstm4a8khNTh9Xo5Y3YBvnMx5QFt_6tgrBnmDGDstGv1OmItJ9oR2eGGzLBpeoy9jp0OTbLqw45dxhbGtCi2JFgtsqmVDligWtsDv7MDts Jan 28 14:51:32 volumio volumio[13563]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 14:51:32 volumio volumio[13563]: info: Starting Shairport Sync Jan 28 14:51:32 volumio volumio[13563]: info: Starting Shairport Sync Jan 28 14:51:32 volumio volumio[13563]: info: Starting Shairport Sync Jan 28 14:51:32 volumio sudo[13844]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 14:51:32 volumio sudo[13844]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:51:32 volumio sudo[13848]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 14:51:32 volumio sudo[13848]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:51:32 volumio sudo[13846]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 14:51:32 volumio sudo[13846]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:51:32 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 14:51:32 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 14:51:32 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 14:51:32 volumio systemd[1]: shairport-sync.service: Consumed 2.319s CPU time. Jan 28 14:51:32 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 14:51:32 volumio volumio[13563]: info: CoreCommandRouter::volumioGetState Jan 28 14:51:32 volumio volumio[13563]: info: CorePlayQueue::getTrack 0 Jan 28 14:51:32 volumio sudo[13844]: pam_unix(sudo:session): session closed for user root Jan 28 14:51:32 volumio sudo[13846]: pam_unix(sudo:session): session closed for user root Jan 28 14:51:32 volumio sudo[13848]: pam_unix(sudo:session): session closed for user root Jan 28 14:51:32 volumio volumio[13563]: info: Shairport-Sync Started Jan 28 14:51:32 volumio volumio[13563]: Error adding Membership: Error: addMembership EINVAL Jan 28 14:51:32 volumio volumio[13563]: info: Shairport-Sync Started Jan 28 14:51:32 volumio volumio[13563]: info: Shairport-Sync Started Jan 28 14:51:33 volumio volumio[13563]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Jan 28 14:51:33 volumio volumio[13563]: info: Spotify Successfully logged in Jan 28 14:51:33 volumio volumio[13563]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 14:51:33 volumio volumio[13563]: info: [1769586693059] CoreMusicLibrary::Adding element Spotify Jan 28 14:51:33 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 14:51:33 volumio volumio[13563]: Cannot find translation for source YouTube Music Jan 28 14:51:33 volumio volumio[13563]: Cannot find translation for source Spotify Jan 28 14:51:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:51:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:51:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:51:33 volumio volumio[13563]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 14:51:33 volumio volumio[13563]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 14:51:33 volumio volumio[13563]: info: VolumeController:: Volume=100 Mute =false Jan 28 14:51:34 volumio volumio[13563]: info: CoreCommandRouter::volumioGetState Jan 28 14:51:34 volumio volumio[13563]: info: CorePlayQueue::getTrack 0 Jan 28 14:51:34 volumio volumio[13563]: info: CoreStateMachine::pushState Jan 28 14:51:34 volumio volumio[13563]: info: CorePlayQueue::getTrack 0 Jan 28 14:51:34 volumio volumio[13563]: info: CoreCommandRouter::volumioPushState Jan 28 14:51:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 14:51:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:51:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:51:35 volumio go-librespot[13874]: go-librespot daemon starting... Jan 28 14:51:35 volumio volumio[13563]: info: go-librespot daemon successfully initialized Jan 28 14:51:35 volumio go-librespot[13879]: time="2026-01-28T14:51:35+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:51:35 volumio go-librespot[13879]: time="2026-01-28T14:51:35+07:00" level=debug msg="app state loaded" Jan 28 14:51:35 volumio go-librespot[13879]: time="2026-01-28T14:51:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:51:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:51:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:51:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:51:35 volumio mpd[13786]: 2026-01-28T14:51:35 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 14:51:35 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 14:51:35 volumio sudo[13746]: pam_unix(sudo:session): session closed for user root Jan 28 14:51:35 volumio sudo[13757]: pam_unix(sudo:session): session closed for user root Jan 28 14:51:35 volumio go-librespot[13879]: time="2026-01-28T14:51:35+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 14:51:35 volumio go-librespot[13879]: time="2026-01-28T14:51:35+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 14:51:35 volumio go-librespot[13879]: time="2026-01-28T14:51:35+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 14:51:35 volumio go-librespot[13879]: time="2026-01-28T14:51:35+07:00" level=info msg="zeroconf server listening on port 34411" Jan 28 14:51:36 volumio volumio[13563]: error: MPD error: The expression evaluated to a falsy value: Jan 28 14:51:36 volumio volumio[13563]: assert.ok(self.idling) Jan 28 14:51:36 volumio volumio[13563]: error: The expression evaluated to a falsy value: Jan 28 14:51:36 volumio volumio[13563]: assert.ok(self.idling) Jan 28 14:51:36 volumio volumio[13563]: error: updateQueue error: null Jan 28 14:51:36 volumio volumio[13563]: info: MPD running with PID13786 Jan 28 14:51:36 volumio volumio[13563]: ,establishing connection Jan 28 14:51:36 volumio go-librespot[13879]: time="2026-01-28T14:51:36+07:00" level=debug msg="obtained new client token: AAB/km6ymdLOztOFk8EsmGynjK+hcSPKATMzV6pElWWZRh5hBsg0Xu6dP/OgaJwYg4TYIEopNU8mTHVnXdudbRoIktLzpaHx9VxiE83l60C8w8Qc86DmttxVY2+uQ+t59QPWB0GCnDK8E8ogIAn/O32WKHVbfltc6wr6CF/ZV3W7tqcYYKPp+8m3nP6vCfb6+AT0RBc7EiVepb2saIdn233/5W6Udu+/QNxJHL+v5yFd7b1OGf8d2fms" Jan 28 14:51:36 volumio volumio[13563]: info: Completed starting Core Plugins Jan 28 14:51:36 volumio volumio[13563]: info: ------------------------------------------- Jan 28 14:51:36 volumio volumio[13563]: info: ----- MyVolumio plugins startup ---- Jan 28 14:51:36 volumio volumio[13563]: info: ------------------------------------------- Jan 28 14:51:36 volumio volumio[13563]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 14:51:36 volumio volumio[13563]: error: updateQueue error: null Jan 28 14:51:36 volumio go-librespot[13879]: time="2026-01-28T14:51:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:51:36 volumio go-librespot[13879]: time="2026-01-28T14:51:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 14:51:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:51:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:51:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:51:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:51:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:51:38 volumio volumio[13563]: info: Initializing connection to go-librespot Websocket Jan 28 14:51:38 volumio volumio[13563]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 14:51:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:51:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:51:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:51:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 14:51:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:51:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:51:39 volumio go-librespot[13897]: go-librespot daemon starting... Jan 28 14:51:39 volumio go-librespot[13898]: time="2026-01-28T14:51:39+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:51:39 volumio go-librespot[13898]: time="2026-01-28T14:51:39+07:00" level=debug msg="app state loaded" Jan 28 14:51:39 volumio go-librespot[13898]: time="2026-01-28T14:51:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:51:40 volumio go-librespot[13898]: time="2026-01-28T14:51: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 14:51:40 volumio go-librespot[13898]: time="2026-01-28T14:51:40+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 14:51:40 volumio go-librespot[13898]: time="2026-01-28T14:51:40+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 14:51:40 volumio go-librespot[13898]: time="2026-01-28T14:51:40+07:00" level=info msg="zeroconf server listening on port 32843" Jan 28 14:51:40 volumio go-librespot[13898]: time="2026-01-28T14:51:40+07:00" level=debug msg="obtained new client token: AAB47bISVijqlaTIpT1Xsyq6fzKxuqiyNpIb7+f4jdgI1ZVCA30DVjD/eWmiSMJddViw6dKw8iV94vOlliw+qZDJIuQ8i3A4zay18jyVHSKu7AkZxsxe5xqD+GO7M9uBprGbhTMUAxFL/IUSLSvlMkJiPf15AG0M45oN67ZctS0bPc3bzzPkEXBsvqoZXP3pEwdSS8uka+CUhlCj8v58IejWjGw4Tuub+vzmGcE/SWaug2UFpgZLNnznpws=" Jan 28 14:51:40 volumio go-librespot[13898]: time="2026-01-28T14:51:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:51:40 volumio go-librespot[13898]: time="2026-01-28T14:51:40+07:00" level=debug msg="completed keyexchange" Jan 28 14:51:40 volumio go-librespot[13898]: time="2026-01-28T14:51:40+07:00" level=debug msg="completed challenge" Jan 28 14:51:40 volumio go-librespot[13898]: time="2026-01-28T14:51:40+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 14:51:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:51:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:51:40 volumio volumio[13563]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 14:51:41 volumio volumio[13563]: info: Initializing connection to go-librespot Websocket Jan 28 14:51:41 volumio volumio[13563]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 14:51:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:51:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:51:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:51:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:51:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:51:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:51:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 14:51:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:51:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:51:43 volumio go-librespot[13906]: go-librespot daemon starting... Jan 28 14:51:43 volumio go-librespot[13907]: time="2026-01-28T14:51:43+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:51:43 volumio go-librespot[13907]: time="2026-01-28T14:51:43+07:00" level=debug msg="app state loaded" Jan 28 14:51:43 volumio go-librespot[13907]: time="2026-01-28T14:51:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:51:44 volumio volumio[13563]: info: Initializing connection to go-librespot Websocket Jan 28 14:51:44 volumio go-librespot[13907]: time="2026-01-28T14:51:44+07:00" level=debug msg="new websocket client" Jan 28 14:51:44 volumio volumio[13563]: info: Connection to go-librespot Websocket established Jan 28 14:51:44 volumio go-librespot[13907]: time="2026-01-28T14:51: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 28 14:51:44 volumio go-librespot[13907]: time="2026-01-28T14:51: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 28 14:51:44 volumio go-librespot[13907]: time="2026-01-28T14:51: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 28 14:51:44 volumio go-librespot[13907]: time="2026-01-28T14:51:44+07:00" level=info msg="zeroconf server listening on port 33199" Jan 28 14:51:44 volumio go-librespot[13907]: time="2026-01-28T14:51:44+07:00" level=debug msg="obtained new client token: AACpcZCFaKyzPU7qIofShbfxFjIpQpYxyvhI3zFO61V5IYp/TZP4cCVzWNiHADD648bQVp/ilN8p/3OK+6xofQuMDuOEMBXatD2pcgmKOndINJrUCj4oCpydu/3S65W/MhaXIvMyhNBcg6ejgZJgwcYEGnz3TIsW99vG3RvfqgPsyRQj1fHGTVHNYkIG/mLfU78tVYlKKOyegh0Cocn9Igi0r9cZTh/NXHyQflRbBDsv9f86TJDqL3VE1ow=" Jan 28 14:51:44 volumio go-librespot[13907]: time="2026-01-28T14:51:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:51:44 volumio go-librespot[13907]: time="2026-01-28T14:51:44+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 14:51:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:51:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:51:44 volumio volumio[13563]: info: Connection to go-librespot Websocket closed Jan 28 14:51:44 volumio volumio[13563]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 14:51:44 volumio volumio[13563]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 14:51:44 volumio volumio[13563]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 14:51:44 volumio volumio[13563]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 14:51:44 volumio volumio[13563]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 14:51:44 volumio volumio[13563]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 14:51:44 volumio volumio[13563]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 14:51:44 volumio volumio[13563]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 14:51:44 volumio volumio[13563]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 14:51:44 volumio volumio[13563]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 14:51:44 volumio volumio[13563]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 14:51:44 volumio volumio[13563]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 14:51:44 volumio volumio[13563]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 14:51:44 volumio volumio[13563]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 14:51:44 volumio volumio[13563]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 14:51:44 volumio volumio[13563]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 14:51:44 volumio volumio[13563]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 14:51:44 volumio volumio[13563]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 14:51:44 volumio volumio[13563]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 14:51:44 volumio volumio[13563]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 14:51:44 volumio volumio[13563]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 14:51:44 volumio volumio[13563]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 14:51:44 volumio volumio[13563]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 14:51:44 volumio volumio[13563]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 14:51:44 volumio volumio[13563]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 14:51:44 volumio volumio[13563]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 14:51:44 volumio volumio[13563]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 14:51:44 volumio volumio[13563]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 14:51:44 volumio volumio[13563]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 14:51:44 volumio volumio[13563]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 14:51:44 volumio volumio[13563]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 14:51:44 volumio volumio[13563]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 14:51:44 volumio volumio[13563]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 14:51:44 volumio volumio[13563]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 14:51:44 volumio volumio[13563]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 14:51:44 volumio volumio[13563]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 14:51:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:51:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:51:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:51:46 volumio volumio[13563]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 14:51:46 volumio volumio[13563]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 14:51:46 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:51:46 volumio volumio[13563]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:51:46 volumio volumio[13563]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 14:51:46 volumio volumio[13563]: info: MyVolumio login type: Token Jan 28 14:51:46 volumio volumio[13563]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 14:51:46 volumio volumio[13563]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 14:51:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:51:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:51:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:51:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 28 14:51:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:51:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:51:48 volumio go-librespot[13928]: go-librespot daemon starting... Jan 28 14:51:48 volumio go-librespot[13929]: time="2026-01-28T14:51:48+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:51:48 volumio go-librespot[13929]: time="2026-01-28T14:51:48+07:00" level=debug msg="app state loaded" Jan 28 14:51:48 volumio go-librespot[13929]: time="2026-01-28T14:51:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:51:48 volumio volumio[13563]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 14:51:48 volumio volumio[13563]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 14:51:48 volumio volumio[13563]: info: Streaming services startup Jan 28 14:51:48 volumio volumio[13563]: info: Starting Streaming Daemon Jan 28 14:51:48 volumio go-librespot[13929]: time="2026-01-28T14:51:48+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 14:51:48 volumio go-librespot[13929]: time="2026-01-28T14:51:48+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 14:51:48 volumio go-librespot[13929]: time="2026-01-28T14:51:48+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 14:51:48 volumio go-librespot[13929]: time="2026-01-28T14:51:48+07:00" level=info msg="zeroconf server listening on port 32835" Jan 28 14:51:48 volumio sudo[13937]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 14:51:48 volumio sudo[13937]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:51:48 volumio volumio[13563]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 14:51:48 volumio sudo[13937]: pam_unix(sudo:session): session closed for user root Jan 28 14:51:48 volumio volumio[13563]: info: Getting Spotify volume Jan 28 14:51:48 volumio volumio[13563]: info: Initializing connection to go-librespot Websocket Jan 28 14:51:48 volumio volumio[13563]: error: Cannot start Volumio Streaming Daemon Jan 28 14:51:48 volumio volumio[13563]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 14:51:48 volumio volumio[13563]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 14:51:48 volumio go-librespot[13929]: time="2026-01-28T14:51:48+07:00" level=debug msg="obtained new client token: AACj41moXAjZT/wK4sNfMLa/pzEdT6Vku5JKrgA5XLBtefFJfcjC8rHnqmsZ+LZTb2jYsAgASzCXdp3UAR5WA5f63PHoWWPX8ExJ+TAwOoAMFP74Y2NZkwc+MKjjCF+txl57b0VZDHMakBs3z2sYsSb82g/eb4xck1Fm+sO5CnM8jrG2NWy2SwWGubu+Ve9BE/eV0D0IHzvcNksn4i/aHm9OAXfHf4DPkz5OxYNWz1wdL0RJVN8c/nwFYek=" Jan 28 14:51:48 volumio go-librespot[13929]: time="2026-01-28T14:51:48+07:00" level=debug msg="new websocket client" Jan 28 14:51:48 volumio volumio[13563]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 28 14:51:48 volumio volumio[13563]: info: Connection to go-librespot Websocket established Jan 28 14:51:48 volumio go-librespot[13929]: time="2026-01-28T14:51:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:51:49 volumio go-librespot[13929]: time="2026-01-28T14:51:49+07:00" level=debug msg="completed keyexchange" Jan 28 14:51:49 volumio go-librespot[13929]: time="2026-01-28T14:51:49+07:00" level=debug msg="completed challenge" Jan 28 14:51:49 volumio volumio[13563]: info: CoreCommandRouter::volumioGetState Jan 28 14:51:49 volumio volumio[13563]: info: CorePlayQueue::getTrack 0 Jan 28 14:51:49 volumio volumio[13563]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 28 14:51:49 volumio volumio[13563]: SPOTIFY: SPOTIFY VOLUME undefined Jan 28 14:51:49 volumio volumio[13563]: SPOTIFY: VOLUMIO VOLUME 100 Jan 28 14:51:49 volumio volumio[13563]: info: Aligning Spotify Volume to Volumio Volume Jan 28 14:51:49 volumio volumio[13563]: info: CoreCommandRouter::volumioGetState Jan 28 14:51:49 volumio volumio[13563]: info: CorePlayQueue::getTrack 0 Jan 28 14:51:49 volumio volumio[13563]: info: Setting Spotify Volume from Volumio: 100 Jan 28 14:51:49 volumio go-librespot[13929]: time="2026-01-28T14:51:49+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 14:51:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:51:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:51:49 volumio volumio[13563]: info: Connection to go-librespot Websocket closed Jan 28 14:51:49 volumio volumio[13563]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 14:51:49 volumio volumio[13563]: Error: socket hang up Jan 28 14:51:49 volumio volumio[13563]: at connResetException (node:internal/errors:720:14) Jan 28 14:51:49 volumio volumio[13563]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 14:51:49 volumio volumio[13563]: at Socket.emit (node:events:526:35) Jan 28 14:51:49 volumio volumio[13563]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 14:51:49 volumio volumio[13563]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 14:51:49 volumio volumio[13563]: code: 'ECONNRESET', Jan 28 14:51:49 volumio volumio[13563]: response: undefined Jan 28 14:51:49 volumio volumio[13563]: } Jan 28 14:51:49 volumio volumio[13563]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 14:51:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:51:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:51:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:51:50 volumio sudo[13957]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 14:50' Jan 28 14:51:50 volumio sudo[13957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:51:51 volumio sudo[13957]: pam_unix(sudo:session): session closed for user root Jan 28 14:51:51 volumio volumio-remote-updater[628]: [2026-01-28 14:51:51] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 28 14:51:51 volumio volumio-remote-updater[628]: [2026-01-28 14:51:51] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 28 14:51:51 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:51:51 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 14:51:51 volumio systemd[1]: volumio.service: Consumed 58.817s CPU time. Jan 28 14:51:51 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 14:51:51 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 14:51:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:51:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:51:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:51:51 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10285. Jan 28 14:51:51 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 14:51:51 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 14:51:51 volumio systemd[1]: volumio.service: Consumed 58.817s CPU time. Jan 28 14:51:51 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 14:51:51 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 14:51:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 28 14:51:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:51:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:51:52 volumio go-librespot[13984]: go-librespot daemon starting... Jan 28 14:51:52 volumio go-librespot[13985]: time="2026-01-28T14:51:52+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:51:52 volumio go-librespot[13985]: time="2026-01-28T14:51:52+07:00" level=debug msg="app state loaded" Jan 28 14:51:52 volumio go-librespot[13985]: time="2026-01-28T14:51:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:51:52 volumio go-librespot[13985]: time="2026-01-28T14:51:52+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 14:51:52 volumio go-librespot[13985]: time="2026-01-28T14:51:52+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 14:51:52 volumio go-librespot[13985]: time="2026-01-28T14:51:52+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 14:51:52 volumio go-librespot[13985]: time="2026-01-28T14:51:52+07:00" level=info msg="zeroconf server listening on port 39057" Jan 28 14:51:53 volumio go-librespot[13985]: time="2026-01-28T14:51:53+07:00" level=debug msg="obtained new client token: AAA6G5hZQNc/2CE+TbsnW2KPoc9RkBxl28tU9wybe2F7z1te3wvVLvFg0tYemV4Esifc0TfoxAd8ksNlDh07AEyymr1ksJYU1WEodxXLnwOAKgAciSvTIR3PFZUNialekefKPvyc6E15IAx/Lr4lb+VfdxX7Ay/Zkc41j+2QqDb4IAQTa5aufo1FzRUsBoyBP8gdMAzFn6GxKqwDp6tXR+bAtQO/9SiD1N4kpGuI4SVIkPW8lcooKuim" Jan 28 14:51:53 volumio go-librespot[13985]: time="2026-01-28T14:51:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:51:53 volumio go-librespot[13985]: time="2026-01-28T14:51:53+07:00" level=debug msg="completed keyexchange" Jan 28 14:51:53 volumio go-librespot[13985]: time="2026-01-28T14:51:53+07:00" level=debug msg="completed challenge" Jan 28 14:51:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:51:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:51:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:51:53 volumio go-librespot[13985]: time="2026-01-28T14:51:53+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 14:51:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:51:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:51:55 volumio volumio[13969]: info: ------------------------------------------- Jan 28 14:51:55 volumio volumio[13969]: info: ----- Volumio3 ---- Jan 28 14:51:55 volumio volumio[13969]: info: ------------------------------------------- Jan 28 14:51:55 volumio volumio[13969]: info: ----- System startup ---- Jan 28 14:51:55 volumio volumio[13969]: info: ------------------------------------------- Jan 28 14:51:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:51:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:51:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:51:56 volumio volumio-remote-updater[628]: [2026-01-28 14:51:56] [connect] Successful connection Jan 28 14:51:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 28 14:51:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:51:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:51:56 volumio go-librespot[13999]: go-librespot daemon starting... Jan 28 14:51:56 volumio volumio[13969]: info: MYVOLUMIO Environment detected Jan 28 14:51:56 volumio go-librespot[14002]: time="2026-01-28T14:51:56+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:51:56 volumio go-librespot[14002]: time="2026-01-28T14:51:56+07:00" level=debug msg="app state loaded" Jan 28 14:51:56 volumio go-librespot[14002]: time="2026-01-28T14:51:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:51:56 volumio volumio[13969]: info: Plugin folders cleanup Jan 28 14:51:56 volumio volumio[13969]: info: Scanning into folder /volumio/app/plugins/ Jan 28 14:51:56 volumio volumio[13969]: info: Scanning category audio_interface Jan 28 14:51:56 volumio volumio[13969]: info: Scanning category miscellanea Jan 28 14:51:56 volumio volumio[13969]: info: Scanning category music_service Jan 28 14:51:56 volumio volumio[13969]: info: Scanning category plugins.json Jan 28 14:51:56 volumio volumio[13969]: info: Scanning category system_controller Jan 28 14:51:56 volumio volumio[13969]: info: Scanning category user_interface Jan 28 14:51:56 volumio volumio[13969]: info: Scanning into folder /data/plugins/ Jan 28 14:51:56 volumio volumio[13969]: info: Scanning category music_service Jan 28 14:51:56 volumio volumio[13969]: info: Plugin folders cleanup completed Jan 28 14:51:56 volumio volumio[13969]: info: ------------------------------------------- Jan 28 14:51:56 volumio volumio[13969]: info: ----- Core plugins startup ---- Jan 28 14:51:56 volumio volumio[13969]: info: ------------------------------------------- Jan 28 14:51:56 volumio volumio[13969]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 14:51:56 volumio volumio[13969]: info: Adding plugin upnp to MyMusic Plugins Jan 28 14:51:56 volumio volumio[13969]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 14:51:56 volumio volumio[13969]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 14:51:56 volumio volumio[13969]: info: Loading plugins from folder /data/plugins/ Jan 28 14:51:56 volumio volumio[13969]: info: Loading plugin "system"... Jan 28 14:51:56 volumio volumio[13969]: info: Loading plugin "appearance"... Jan 28 14:51:57 volumio go-librespot[14002]: time="2026-01-28T14:51:57+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 14:51:57 volumio go-librespot[14002]: time="2026-01-28T14:51:57+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 14:51:57 volumio go-librespot[14002]: time="2026-01-28T14:51:57+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 14:51:57 volumio go-librespot[14002]: time="2026-01-28T14:51:57+07:00" level=info msg="zeroconf server listening on port 44913" Jan 28 14:51:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:51:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:51:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:51:57 volumio go-librespot[14002]: time="2026-01-28T14:51:57+07:00" level=debug msg="obtained new client token: AAAmUOBlvJldY5pe/OKeDc78VLtTYBWsQ/06dD0BT4mq7n6borYA/PxQwkkJaCuOvB4RfbhLlT9qwf/fr3AvZxtMl2b2oNDC/8AH2jYuETSlBcAbdpn6UX0BFWLytmREowuCUe4wT5155ei1h7musNaRjmhFOSryWuhVXmOzG7wDFs9v/r2qCykAVmydXe+9YUbxDHOE38bzn+6VkoJhEcVseg6P8E6lC7h9hrVfk2ZabNQ2D5R+mBJHoDw=" Jan 28 14:51:57 volumio go-librespot[14002]: time="2026-01-28T14:51:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:51:57 volumio go-librespot[14002]: time="2026-01-28T14:51:57+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 14:51:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:51:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:51:58 volumio volumio[13969]: info: Loading plugin "network"... Jan 28 14:51:58 volumio volumio[13969]: info: Refreshing Cached IP Addresses Jan 28 14:51:58 volumio sudo[14015]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 14:51:58 volumio sudo[14015]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:51:58 volumio volumio[13969]: info: Loading plugin "services"... Jan 28 14:51:58 volumio sudo[14015]: pam_unix(sudo:session): session closed for user root Jan 28 14:51:58 volumio sudo[14017]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 14:51:58 volumio sudo[14017]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:51:58 volumio volumio[13969]: info: Loading plugin "alsa_controller"... Jan 28 14:51:58 volumio sudo[14017]: pam_unix(sudo:session): session closed for user root Jan 28 14:51:58 volumio sudo[14025]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 14:51:58 volumio sudo[14025]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:51:59 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 14:51:59 volumio volumio[13969]: info: Loading plugin "wizard"... Jan 28 14:51:59 volumio volumio[13969]: info: Loading plugin "networkfs"... Jan 28 14:51:59 volumio volumio[13969]: info: Starting Udev Watcher for removable devices Jan 28 14:51:59 volumio volumio[13969]: info: Ignoring mount for partition: boot Jan 28 14:51:59 volumio volumio[13969]: info: Ignoring mount for partition: volumio Jan 28 14:51:59 volumio volumio[13969]: info: Ignoring mount for partition: volumio_data Jan 28 14:51:59 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 14:51:59 volumio volumio[13969]: info: Loading plugin "volumio_command_line_client"... Jan 28 14:51:59 volumio volumio[13969]: info: Loading plugin "upnp"... Jan 28 14:51:59 volumio volumio[13969]: info: [1769586719233] Starting Upmpd Daemon Jan 28 14:51:59 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 14:51:59 volumio volumio[13969]: info: Loading plugin "my_music"... Jan 28 14:51:59 volumio volumio[13969]: info: Loading plugin "mpd"... Jan 28 14:51:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:51:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:51:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:51:59 volumio volumio[13969]: info: Loading plugin "upnp_browser"... Jan 28 14:52:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 28 14:52:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:52:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:52:00 volumio go-librespot[14048]: go-librespot daemon starting... Jan 28 14:52:00 volumio go-librespot[14049]: time="2026-01-28T14:52:00+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:52:00 volumio go-librespot[14049]: time="2026-01-28T14:52:00+07:00" level=debug msg="app state loaded" Jan 28 14:52:00 volumio go-librespot[14049]: time="2026-01-28T14:52:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:52:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:52:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:52:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:52:01 volumio go-librespot[14049]: time="2026-01-28T14:52:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 14:52:01 volumio go-librespot[14049]: time="2026-01-28T14:52:01+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 14:52:01 volumio go-librespot[14049]: time="2026-01-28T14:52:01+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 14:52:01 volumio go-librespot[14049]: time="2026-01-28T14:52:01+07:00" level=info msg="zeroconf server listening on port 45679" Jan 28 14:52:01 volumio go-librespot[14049]: time="2026-01-28T14:52:01+07:00" level=debug msg="obtained new client token: AAByQHFV5N8GEI/xv2ublsiF2Dwj/Sxxkx9VfKvc47WG8v3+PAUo2g10sm9DO76qTJ9AOsPS32aizqLh6aVRK+naEMaO9jYw3rZgFp1Z52TB3gUjzK3ELw+Sl1tfjBIqtbvUVLcN6G140j5pwZpJ8tUz0KKWRm2ER2KWNps0EnU/p5OvPySTSJwGgEUO1mesvzEgGoFUulV8G7SMN1sjHVebAkHB4hUnOhr9ZdTSu2J0EwwhDBFhFPtmfUA=" Jan 28 14:52:01 volumio go-librespot[14049]: time="2026-01-28T14:52:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:52:01 volumio go-librespot[14049]: time="2026-01-28T14:52:01+07:00" level=debug msg="completed keyexchange" Jan 28 14:52:01 volumio go-librespot[14049]: time="2026-01-28T14:52:01+07:00" level=debug msg="completed challenge" Jan 28 14:52:01 volumio sudo[14025]: pam_unix(sudo:session): session closed for user root Jan 28 14:52:01 volumio go-librespot[14049]: time="2026-01-28T14:52: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 28 14:52:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:52:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:52:02 volumio volumio[13969]: info: Starting UPNP Browser Jan 28 14:52:02 volumio volumio[13969]: info: Loading plugin "alarm-clock"... Jan 28 14:52:03 volumio volumio[13969]: info: Loading plugin "airplay_emulation"... Jan 28 14:52:03 volumio volumio[13969]: info: Starting Shairport Sync Jan 28 14:52:03 volumio volumio[13969]: info: Loading plugin "last_100"... Jan 28 14:52:03 volumio volumio[13969]: info: Loading plugin "webradio"... Jan 28 14:52:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:52:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:52:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:52:03 volumio volumio[13969]: info: Loading plugin "i2s_dacs"... Jan 28 14:52:03 volumio volumio[13969]: info: Loading plugin "volumiodiscovery"... Jan 28 14:52:03 volumio volumio[13969]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 14:52:03 volumio volumio[13969]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 14:52:03 volumio volumio[13969]: *** WARNING *** For more information see Jan 28 14:52:03 volumio volumio[13969]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 14:52:03 volumio volumio[13969]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 14:52:03 volumio volumio[13969]: *** WARNING *** For more information see Jan 28 14:52:03 volumio node[13969]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 14:52:03 volumio node[13969]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 14:52:03 volumio node[13969]: *** WARNING *** For more information see Jan 28 14:52:03 volumio node[13969]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 14:52:03 volumio node[13969]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 14:52:03 volumio node[13969]: *** WARNING *** For more information see Jan 28 14:52:03 volumio volumio[13969]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 14:52:03 volumio volumio[13969]: info: Discovery: Started advertising with name: Volumio Jan 28 14:52:03 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 14:52:03 volumio volumio[13969]: info: Loading plugin "spop"... Jan 28 14:52:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 28 14:52:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:52:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:52:05 volumio go-librespot[14059]: go-librespot daemon starting... Jan 28 14:52:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:52:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:52:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:52:05 volumio go-librespot[14060]: time="2026-01-28T14:52:05+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:52:05 volumio go-librespot[14060]: time="2026-01-28T14:52:05+07:00" level=debug msg="app state loaded" Jan 28 14:52:05 volumio go-librespot[14060]: time="2026-01-28T14:52:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:52:05 volumio volumio[13969]: info: Loading plugin "ytcr"... Jan 28 14:52:05 volumio go-librespot[14060]: time="2026-01-28T14:52: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 28 14:52:05 volumio go-librespot[14060]: time="2026-01-28T14:52: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 28 14:52:05 volumio go-librespot[14060]: time="2026-01-28T14:52: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 28 14:52:05 volumio go-librespot[14060]: time="2026-01-28T14:52:05+07:00" level=info msg="zeroconf server listening on port 33163" Jan 28 14:52:06 volumio go-librespot[14060]: time="2026-01-28T14:52:06+07:00" level=debug msg="obtained new client token: AAAYINdF51AxCIkMO30CrOxGxZMN9bIiojpVhUcfQHrbUk53EePNVMm5Z1TtJ+h9rmZewc1VmD5NwJ2xsA4h6exgE6/VAdQSqF7cb265g4GsHTSE+DsrB3zSMsMRlgdN1dP1TrSQmWVidBZZR7nneEgTt8YsQ78t89gyD3S8fzeGy0OuZRDWJ5ywvPYCSefJ1YlWGsn0nEIUqxuCVtImjUejMzv38hsqytT6B7Q6lXJh21doB4JVHx4F" Jan 28 14:52:06 volumio go-librespot[14060]: time="2026-01-28T14:52:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:52:06 volumio go-librespot[14060]: time="2026-01-28T14:52:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 14:52:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:52:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:52:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:52:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:52:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:52:08 volumio volumio[13969]: info: Loading plugin "ytmusic"... Jan 28 14:52:08 volumio volumio-remote-updater[628]: [2026-01-28 14:52:08] [connect] Successful connection Jan 28 14:52:09 volumio volumio[13969]: info: Loading plugin "outputs"... Jan 28 14:52:09 volumio volumio[13969]: info: Loading plugin "albumart"... Jan 28 14:52:09 volumio volumio[13969]: info: Plugin example_plugin is not enabled Jan 28 14:52:09 volumio volumio[13969]: info: Loading plugin "inputs"... Jan 28 14:52:09 volumio volumio[13969]: info: Loading plugin "updater_comm"... Jan 28 14:52:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:52:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:52:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:52:09 volumio volumio[13969]: info: Plugin mpdemulation is not enabled Jan 28 14:52:09 volumio volumio[13969]: info: Loading plugin "rest_api"... Jan 28 14:52:09 volumio volumio[13969]: info: Loading plugin "websocket"... Jan 28 14:52:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 28 14:52:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:52:09 volumio volumio[13969]: info: Starting Socket.io Server version 1.7.4 Jan 28 14:52:09 volumio volumio[13969]: info: Loading plugin "RoonBridge"... Jan 28 14:52:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:52:09 volumio go-librespot[14093]: go-librespot daemon starting... Jan 28 14:52:09 volumio go-librespot[14094]: time="2026-01-28T14:52:09+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:52:09 volumio go-librespot[14094]: time="2026-01-28T14:52:09+07:00" level=debug msg="app state loaded" Jan 28 14:52:09 volumio go-librespot[14094]: time="2026-01-28T14:52:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:52:10 volumio volumio[13969]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 14:52:10 volumio volumio[13969]: info: Loading i18n strings for locale en Jan 28 14:52:10 volumio volumio[13969]: Updating browse sources language Jan 28 14:52:10 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 14:52:10 volumio go-librespot[14094]: time="2026-01-28T14:52: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 14:52:10 volumio go-librespot[14094]: time="2026-01-28T14:52:10+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 14:52:10 volumio go-librespot[14094]: time="2026-01-28T14:52:10+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 14:52:10 volumio go-librespot[14094]: time="2026-01-28T14:52:10+07:00" level=info msg="zeroconf server listening on port 36885" Jan 28 14:52:10 volumio volumio[14083]: Forking 3 albumart workers Jan 28 14:52:10 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 14:52:10 volumio volumio[13969]: info: CoreCommandRouter::initPlayerControls Jan 28 14:52:10 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:52:10 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:52:10 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:52:10 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:52:10 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:52:10 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:52:10 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:52:10 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:52:10 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 14:52:10 volumio volumio[13969]: Express server listening on port 3000 Jan 28 14:52:10 volumio volumio[13969]: [Metrics] WebUI: 16s 181.35ms Jan 28 14:52:10 volumio go-librespot[14094]: time="2026-01-28T14:52:10+07:00" level=debug msg="obtained new client token: AACyMellAYdswOdA8PB2gA1YGUVhJLqoLuDzon7OODX03iYsem8LwVOI3HpixFykGvY19JPV42PokZRhGdLqAzRuFburUyVYg9W7rUcSMIdbFvaKsG+LguvLgUAG1euyFBKL/83sUDb8vt/o3Ty21v2WB7BBZBJACmCAN2hCmAIBhARkeNDXJZGaWOYYzwf8clMwicycxTLqYry6NtnybLLCwMe+aKB26xb23I/935LvZHSpYnjQKFPsgqg=" Jan 28 14:52:10 volumio volumio[13969]: info: CoreStateMachine::resetVolumioState Jan 28 14:52:10 volumio volumio[13969]: info: CoreStateMachine::getcurrentVolume Jan 28 14:52:10 volumio volumio[13969]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 14:52:10 volumio go-librespot[14094]: time="2026-01-28T14:52:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:52:10 volumio sudo[14133]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 14:52:10 volumio sudo[14133]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:52:10 volumio sudo[14133]: pam_unix(sudo:session): session closed for user root Jan 28 14:52:10 volumio go-librespot[14094]: time="2026-01-28T14:52: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 28 14:52:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:52:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:52:10 volumio sudo[14135]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 14:52:10 volumio sudo[14135]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:52:10 volumio volumio[13969]: info: Volumio Network Manager: Network status updated: 1 Jan 28 14:52:10 volumio sudo[14135]: pam_unix(sudo:session): session closed for user root Jan 28 14:52:11 volumio volumio[13969]: info: VolumeController:: Volume=100 Mute =false Jan 28 14:52:11 volumio volumio[13969]: info: CoreStateMachine::pushState Jan 28 14:52:11 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Jan 28 14:52:11 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 14:52:11 volumio volumio[13969]: info: CoreCommandRouter::volumioPushState Jan 28 14:52:11 volumio volumio[13969]: info: CoreStateMachine::updateTrackBlock Jan 28 14:52:11 volumio volumio[13969]: info: CorePlayQueue::getTrackBlock Jan 28 14:52:11 volumio volumio[13969]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 14:52:11 volumio volumio-remote-updater[628]: [2026-01-28 14:52:11] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769586728 101 Jan 28 14:52:11 volumio volumio[13969]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 28 14:52:11 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:52:11 volumio volumio[13969]: info: Reloading queue from file Jan 28 14:52:11 volumio volumio[13969]: info: CoreStateMachine::setRepeat null single undefined Jan 28 14:52:11 volumio volumio[13969]: info: CoreStateMachine::pushState Jan 28 14:52:11 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Jan 28 14:52:11 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 14:52:11 volumio volumio[13969]: info: CoreCommandRouter::volumioPushState Jan 28 14:52:11 volumio volumio[13969]: info: CoreStateMachine::setRandom null Jan 28 14:52:11 volumio volumio[13969]: info: CoreStateMachine::pushState Jan 28 14:52:11 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Jan 28 14:52:11 volumio volumio[13969]: info: CoreCommandRouter::volumioPushState Jan 28 14:52:11 volumio volumio[13969]: info: Setting Device type: Raspberry PI Jan 28 14:52:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:52:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:52:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:52:11 volumio volumio[13969]: info: Completed loading Core Plugins Jan 28 14:52:11 volumio volumio[13969]: info: Preparing to generate the ALSA configuration file Jan 28 14:52:11 volumio volumio[13969]: info: VolumeController:: Volume=100 Mute =false Jan 28 14:52:11 volumio volumio[13969]: info: CoreStateMachine::pushState Jan 28 14:52:11 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Jan 28 14:52:11 volumio volumio[13969]: info: CoreCommandRouter::volumioPushState Jan 28 14:52:11 volumio volumio[13969]: info: Asound.conf file unchanged, so no further update is needed Jan 28 14:52:11 volumio volumio[13969]: info: Output device has changed, restarting MPD Jan 28 14:52:11 volumio volumio[13969]: info: Output device has changed, restarting Shairport Sync Jan 28 14:52:11 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:52:11 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:52:11 volumio sudo[14152]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 14:52:11 volumio sudo[14152]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:52:11 volumio sudo[14154]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 14:52:11 volumio sudo[14154]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:52:11 volumio sudo[14154]: pam_unix(sudo:session): session closed for user root Jan 28 14:52:11 volumio sudo[14156]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 14:52:11 volumio sudo[14156]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:52:11 volumio volumio[13969]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 14:52:11 volumio volumio[13969]: info: ___________ START PLUGINS ___________ Jan 28 14:52:11 volumio volumio[13969]: info: ControllerMpd::onStart: Initializing MPD Jan 28 14:52:11 volumio volumio[13969]: info: Creating MPD Configuration file Jan 28 14:52:11 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 14:52:11 volumio sudo[14152]: pam_unix(sudo:session): session closed for user root Jan 28 14:52:11 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 14:52:11 volumio volumio[13969]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 14:52:11 volumio volumio[13969]: info: [1769586731909] CoreMusicLibrary::Adding element Media Servers Jan 28 14:52:11 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 14:52:11 volumio sudo[14165]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 14:52:11 volumio sudo[14165]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:52:11 volumio sudo[14165]: pam_unix(sudo:session): session closed for user root Jan 28 14:52:11 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 14:52:11 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 14:52:11 volumio systemd[1]: mpd.service: Consumed 7.438s CPU time. Jan 28 14:52:11 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 14:52:11 volumio sudo[14167]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 14:52:11 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 14:52:11 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 14:52:12 volumio sudo[14167]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:52:12 volumio volumio[13969]: info: UPNP Browser: Client initialized successfully Jan 28 14:52:12 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:52:12 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:52:12 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 14:52:12 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 14:52:12 volumio volumio[13969]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 14:52:12 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:52:12 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:52:12 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 14:52:12 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 14:52:12 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 14:52:12 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 14:52:12 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 14:52:12 volumio volumio[13969]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 14:52:12 volumio volumio[13969]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 14:52:12 volumio volumio[13969]: info: [1769586732299] CoreMusicLibrary::Adding element Last_100 Jan 28 14:52:12 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 14:52:12 volumio volumio[13969]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 14:52:12 volumio volumio[13969]: info: [1769586732320] CoreMusicLibrary::Adding element Webradio Jan 28 14:52:12 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 14:52:12 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 14:52:12 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 14:52:12 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 14:52:12 volumio volumio[13969]: info: Initializing BBC Radios Jan 28 14:52:12 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 14:52:12 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:52:12 volumio volumio[13969]: info: Creating Spotify config file Jan 28 14:52:12 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:52:12 volumio sudo[14181]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 14:52:12 volumio sudo[14181]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 14:52:12 volumio sudo[14181]: pam_unix(sudo:session): session closed for user root Jan 28 14:52:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:52:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:52:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:52:13 volumio volumio[14102]: Starting albumart workers Jan 28 14:52:13 volumio volumio[13969]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 14:52:13 volumio volumio[13969]: info: [1769586733579] CoreMusicLibrary::Adding element YouTube Music Jan 28 14:52:13 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 14:52:13 volumio volumio[13969]: Cannot find translation for source YouTube Music Jan 28 14:52:13 volumio volumio[13969]: info: Volumio Calling Home Jan 28 14:52:13 volumio sudo[14199]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 14:52:13 volumio sudo[14199]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:52:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 28 14:52:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:52:13 volumio volumio[14103]: Starting albumart workers Jan 28 14:52:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:52:13 volumio go-librespot[14203]: go-librespot daemon starting... Jan 28 14:52:13 volumio sudo[14199]: pam_unix(sudo:session): session closed for user root Jan 28 14:52:13 volumio go-librespot[14205]: time="2026-01-28T14:52:13+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:52:14 volumio volumio[14101]: Starting albumart workers Jan 28 14:52:14 volumio volumio[13969]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 14:52:14 volumio volumio[13969]: info: Discovery: Found device Volumio Jan 28 14:52:14 volumio volumio[13969]: info: CoreCommandRouter::volumioGetState Jan 28 14:52:14 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Jan 28 14:52:14 volumio volumio[13969]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 14:52:14 volumio volumio[13969]: info: Discovery: Found device Volumio Jan 28 14:52:14 volumio volumio[13969]: info: CoreCommandRouter::volumioGetState Jan 28 14:52:14 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Jan 28 14:52:14 volumio go-librespot[14205]: time="2026-01-28T14:52:14+07:00" level=info msg="zeroconf server listening on port 34323" Jan 28 14:52:14 volumio volumio[13969]: info: MPD Permissions set Jan 28 14:52:14 volumio volumio[13969]: info: MPD Permissions set Jan 28 14:52:14 volumio volumio[13969]: info: Upmpdcli Daemon Started Jan 28 14:52:14 volumio volumio[13969]: info: Volumio called home Jan 28 14:52:14 volumio volumio[13969]: info: Spotify config file written Jan 28 14:52:15 volumio sudo[14213]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 14:52:15 volumio sudo[14213]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:52:15 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 14:52:15 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 14:52:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:52:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:52:15 volumio go-librespot[14215]: go-librespot daemon starting... Jan 28 14:52:15 volumio sudo[14213]: pam_unix(sudo:session): session closed for user root Jan 28 14:52:15 volumio go-librespot[14217]: time="2026-01-28T14:52:15+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:52:15 volumio go-librespot[14217]: time="2026-01-28T14:52:15+07:00" level=debug msg="app state loaded" Jan 28 14:52:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:52:15 volumio go-librespot[14217]: time="2026-01-28T14:52:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:52:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:52:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:52:15 volumio volumio[13969]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 14:52:15 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:52:15 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:52:15 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:52:15 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:52:15 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:52:15 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:52:15 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:52:15 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:52:15 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:52:15 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:52:15 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:52:15 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:52:15 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:52:15 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:52:15 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:52:15 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:52:15 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:52:15 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:52:15 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:52:15 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:52:15 volumio volumio[13969]: info: No need to fix Spotify hosts Jan 28 14:52:16 volumio go-librespot[14217]: time="2026-01-28T14:52:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 14:52:16 volumio go-librespot[14217]: time="2026-01-28T14:52:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 14:52:16 volumio go-librespot[14217]: time="2026-01-28T14:52:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 14:52:16 volumio go-librespot[14217]: time="2026-01-28T14:52:16+07:00" level=info msg="zeroconf server listening on port 36323" Jan 28 14:52:16 volumio go-librespot[14217]: time="2026-01-28T14:52:16+07:00" level=debug msg="obtained new client token: AADWw9sbpvlMriudZoLH5hfM1h2asnVd2As5tAk1fZ1H7A3hlG0O2V5FD5js9mVWaYEgdA5SXflukgCbIBUkU8bT43O703ABUq4N7SMDYzD+jRTbre/giZMEmXCBckbgniTKT8KrleTWl+LYCkZNkLI0Tvkv5CoPy58DYU7isVWHl4tGaj0A00wJU3Tx6y4xPSbmV9BruilvtfKd8OIoyrrIcC2fSoXFbRCA8A9QZvHKiFtyaEkpkCT0" Jan 28 14:52:16 volumio go-librespot[14217]: time="2026-01-28T14:52:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:52:16 volumio go-librespot[14217]: time="2026-01-28T14:52:16+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 14:52:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:52:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:52:16 volumio volumio[13969]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 14:52:16 volumio volumio[13969]: SPOTIFY: BQDeRX1V9u9zXKlGK5d_C8ot303fisUf9TaiwJfs14o_bAgEceWaYbZiR2jpDnbmWUXd2He04K2AtS7kt1aChPVg7H0hl9ZlvslkDTXp_9PHKAaZqq6JEVGLDCwiRGkW2BxJGXr05vkIQjbxEWLUycUPWbLD2ueGtmHO_NwMhua0s574cPVmauE0aWlOHe2b79VDdzwqqGdahx5TdCFP1UNLjFndPA7fkWck7mDrITWuvWuWiiXIqkaFcCDrJyRIS2iRv_JpS3RPa-S49pKfGhDOnmmcdWuPASSgv003rEBqoYTX57RIr0eW Jan 28 14:52:16 volumio volumio[13969]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 14:52:16 volumio volumio[13969]: info: New Spotify access token = BQDeRX1V9u9zXKlGK5d_C8ot303fisUf9TaiwJfs14o_bAgEceWaYbZiR2jpDnbmWUXd2He04K2AtS7kt1aChPVg7H0hl9ZlvslkDTXp_9PHKAaZqq6JEVGLDCwiRGkW2BxJGXr05vkIQjbxEWLUycUPWbLD2ueGtmHO_NwMhua0s574cPVmauE0aWlOHe2b79VDdzwqqGdahx5TdCFP1UNLjFndPA7fkWck7mDrITWuvWuWiiXIqkaFcCDrJyRIS2iRv_JpS3RPa-S49pKfGhDOnmmcdWuPASSgv003rEBqoYTX57RIr0eW Jan 28 14:52:16 volumio volumio[13969]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 14:52:16 volumio volumio[13969]: info: Starting Shairport Sync Jan 28 14:52:16 volumio volumio[13969]: info: Starting Shairport Sync Jan 28 14:52:16 volumio volumio[13969]: info: Starting Shairport Sync Jan 28 14:52:16 volumio sudo[14254]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 14:52:16 volumio sudo[14254]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:52:16 volumio sudo[14256]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 14:52:16 volumio sudo[14256]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:52:16 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 14:52:16 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 14:52:16 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 14:52:16 volumio systemd[1]: shairport-sync.service: Consumed 2.360s CPU time. Jan 28 14:52:16 volumio sudo[14259]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 14:52:16 volumio sudo[14259]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:52:17 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 14:52:17 volumio sudo[14254]: pam_unix(sudo:session): session closed for user root Jan 28 14:52:17 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 14:52:17 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 14:52:17 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 14:52:17 volumio volumio[13969]: info: Shairport-Sync Started Jan 28 14:52:17 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 14:52:17 volumio sudo[14259]: pam_unix(sudo:session): session closed for user root Jan 28 14:52:17 volumio volumio[13969]: Error adding Membership: Error: addMembership EINVAL Jan 28 14:52:17 volumio sudo[14256]: pam_unix(sudo:session): session closed for user root Jan 28 14:52:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:52:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:52:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:52:17 volumio volumio[13969]: info: Shairport-Sync Started Jan 28 14:52:17 volumio volumio[13969]: info: Shairport-Sync Started Jan 28 14:52:17 volumio volumio[13969]: info: CoreCommandRouter::volumioGetState Jan 28 14:52:17 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Jan 28 14:52:17 volumio volumio[13969]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Jan 28 14:52:17 volumio volumio[13969]: info: Spotify Successfully logged in Jan 28 14:52:17 volumio volumio[13969]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 14:52:17 volumio volumio[13969]: info: [1769586737718] CoreMusicLibrary::Adding element Spotify Jan 28 14:52:17 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 14:52:17 volumio volumio[13969]: Cannot find translation for source YouTube Music Jan 28 14:52:17 volumio volumio[13969]: Cannot find translation for source Spotify Jan 28 14:52:18 volumio volumio[13969]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 14:52:18 volumio volumio[13969]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 14:52:18 volumio volumio[13969]: info: VolumeController:: Volume=100 Mute =false Jan 28 14:52:18 volumio volumio[13969]: info: CoreCommandRouter::volumioGetState Jan 28 14:52:18 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Jan 28 14:52:18 volumio volumio[13969]: info: CoreStateMachine::pushState Jan 28 14:52:18 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Jan 28 14:52:18 volumio volumio[13969]: info: CoreCommandRouter::volumioPushState Jan 28 14:52:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:52:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:52:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:52:19 volumio volumio[13969]: info: go-librespot daemon successfully initialized Jan 28 14:52:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 14:52:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:52:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:52:19 volumio go-librespot[14294]: go-librespot daemon starting... Jan 28 14:52:19 volumio go-librespot[14295]: time="2026-01-28T14:52:19+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:52:19 volumio go-librespot[14295]: time="2026-01-28T14:52:19+07:00" level=debug msg="app state loaded" Jan 28 14:52:19 volumio go-librespot[14295]: time="2026-01-28T14:52:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:52:20 volumio mpd[14197]: 2026-01-28T14:52:20 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 14:52:20 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 14:52:20 volumio sudo[14156]: pam_unix(sudo:session): session closed for user root Jan 28 14:52:20 volumio sudo[14167]: pam_unix(sudo:session): session closed for user root Jan 28 14:52:20 volumio volumio[13969]: error: MPD error: The expression evaluated to a falsy value: Jan 28 14:52:20 volumio volumio[13969]: assert.ok(self.idling) Jan 28 14:52:20 volumio volumio[13969]: error: The expression evaluated to a falsy value: Jan 28 14:52:20 volumio volumio[13969]: assert.ok(self.idling) Jan 28 14:52:20 volumio go-librespot[14295]: time="2026-01-28T14:52: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 28 14:52:20 volumio go-librespot[14295]: time="2026-01-28T14:52: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 28 14:52:20 volumio go-librespot[14295]: time="2026-01-28T14:52: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 28 14:52:20 volumio volumio[13969]: error: updateQueue error: null Jan 28 14:52:20 volumio go-librespot[14295]: time="2026-01-28T14:52:20+07:00" level=info msg="zeroconf server listening on port 33921" Jan 28 14:52:20 volumio volumio[13969]: info: Completed starting Core Plugins Jan 28 14:52:20 volumio volumio[13969]: info: ------------------------------------------- Jan 28 14:52:20 volumio volumio[13969]: info: ----- MyVolumio plugins startup ---- Jan 28 14:52:20 volumio volumio[13969]: info: ------------------------------------------- Jan 28 14:52:20 volumio volumio[13969]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 14:52:20 volumio volumio[13969]: info: MPD running with PID14197 Jan 28 14:52:20 volumio volumio[13969]: ,establishing connection Jan 28 14:52:20 volumio volumio[13969]: error: updateQueue error: null Jan 28 14:52:20 volumio go-librespot[14295]: time="2026-01-28T14:52:20+07:00" level=debug msg="obtained new client token: AAC0oLpn8GmHcG4APaNmy6G/UKBu98K2QaUbXoc26N/v2mWgnD7Q5tXQz65cg5TnqdOc80p26NJo8b6p/ZdUY6KrT5mOnhGtllfIbtErHwT92/+os1tiKIINEdyQkp5JC1+yXS9Gw8scbHn0WXV3z74cGXDw5huT74TDQDGniPeN/yz2JdokzNC6k1A9nh9FebbjSLOgvVfFyeTcSWTD1LQxJpSydCDoYuriyvFKUO2eaxGhyktAXqs4ruo=" Jan 28 14:52:20 volumio go-librespot[14295]: time="2026-01-28T14:52:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:52:20 volumio go-librespot[14295]: time="2026-01-28T14:52:20+07:00" level=debug msg="completed keyexchange" Jan 28 14:52:20 volumio go-librespot[14295]: time="2026-01-28T14:52:20+07:00" level=debug msg="completed challenge" Jan 28 14:52:21 volumio go-librespot[14295]: time="2026-01-28T14:52:21+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 14:52:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:52:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:52:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:52:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:52:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:52:22 volumio volumio[13969]: info: Initializing connection to go-librespot Websocket Jan 28 14:52:22 volumio volumio[13969]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 14:52:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:52:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:52:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:52:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 14:52:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:52:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:52:24 volumio go-librespot[14307]: go-librespot daemon starting... Jan 28 14:52:24 volumio go-librespot[14308]: time="2026-01-28T14:52:24+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:52:24 volumio go-librespot[14308]: time="2026-01-28T14:52:24+07:00" level=debug msg="app state loaded" Jan 28 14:52:24 volumio go-librespot[14308]: time="2026-01-28T14:52:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:52:24 volumio go-librespot[14308]: time="2026-01-28T14:52: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-gew1.spotify.com:80]" Jan 28 14:52:24 volumio go-librespot[14308]: time="2026-01-28T14:52:24+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 14:52:24 volumio go-librespot[14308]: time="2026-01-28T14:52:24+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 14:52:24 volumio go-librespot[14308]: time="2026-01-28T14:52:24+07:00" level=info msg="zeroconf server listening on port 41453" Jan 28 14:52:25 volumio go-librespot[14308]: time="2026-01-28T14:52:25+07:00" level=debug msg="obtained new client token: AADaHPPRQlTrJOQGCfjFvpMHDaYAq3aKmvzMmDETmLX4HRSFvjkN2LzClqT4uFVRFnO57Z9TYngw2wA4SBhb9iDZMfwPw/QpgTDD+S1eC5ldUwkNRauNYE9n9pCDN8/CRWGfh+tU1OpN10uKBlmgpY7ira9/weoA1cviY3KJwTDEc+XpOWz0iBGMT4gBoCoS1UUa6SCDHJcf7wFRtTv/5l6YkGbLGw2UeF5nj+8+3j/e5PbARBxv4a1m" Jan 28 14:52:25 volumio go-librespot[14308]: time="2026-01-28T14:52:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:52:25 volumio go-librespot[14308]: time="2026-01-28T14:52:25+07:00" level=debug msg="completed keyexchange" Jan 28 14:52:25 volumio go-librespot[14308]: time="2026-01-28T14:52:25+07:00" level=debug msg="completed challenge" Jan 28 14:52:25 volumio volumio[13969]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 14:52:25 volumio go-librespot[14308]: time="2026-01-28T14:52:25+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 14:52:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:52:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:52:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:52:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:52:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:52:25 volumio volumio[13969]: info: Initializing connection to go-librespot Websocket Jan 28 14:52:25 volumio volumio[13969]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 14:52:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:52:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:52:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:52:28 volumio volumio[13969]: info: Initializing connection to go-librespot Websocket Jan 28 14:52:28 volumio volumio[13969]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 14:52:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 14:52:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:52:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:52:28 volumio go-librespot[14316]: go-librespot daemon starting... Jan 28 14:52:28 volumio go-librespot[14317]: time="2026-01-28T14:52:28+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:52:28 volumio go-librespot[14317]: time="2026-01-28T14:52:28+07:00" level=debug msg="app state loaded" Jan 28 14:52:28 volumio go-librespot[14317]: time="2026-01-28T14:52:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:52:29 volumio go-librespot[14317]: time="2026-01-28T14:52:29+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 14:52:29 volumio go-librespot[14317]: time="2026-01-28T14:52:29+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 14:52:29 volumio go-librespot[14317]: time="2026-01-28T14:52:29+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 14:52:29 volumio go-librespot[14317]: time="2026-01-28T14:52:29+07:00" level=info msg="zeroconf server listening on port 39431" Jan 28 14:52:29 volumio volumio[13969]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 14:52:29 volumio volumio[13969]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 14:52:29 volumio volumio[13969]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 14:52:29 volumio volumio[13969]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 14:52:29 volumio volumio[13969]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 14:52:29 volumio volumio[13969]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 14:52:29 volumio volumio[13969]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 14:52:29 volumio volumio[13969]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 14:52:29 volumio volumio[13969]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 14:52:29 volumio volumio[13969]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 14:52:29 volumio volumio[13969]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 14:52:29 volumio volumio[13969]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 14:52:29 volumio volumio[13969]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 14:52:29 volumio volumio[13969]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 14:52:29 volumio volumio[13969]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 14:52:29 volumio volumio[13969]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 14:52:29 volumio volumio[13969]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 14:52:29 volumio volumio[13969]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 14:52:29 volumio volumio[13969]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 14:52:29 volumio volumio[13969]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 14:52:29 volumio volumio[13969]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 14:52:29 volumio volumio[13969]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 14:52:29 volumio volumio[13969]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 14:52:29 volumio volumio[13969]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 14:52:29 volumio volumio[13969]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 14:52:29 volumio volumio[13969]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 14:52:29 volumio volumio[13969]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 14:52:29 volumio volumio[13969]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 14:52:29 volumio volumio[13969]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 14:52:29 volumio volumio[13969]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 14:52:29 volumio volumio[13969]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 14:52:29 volumio volumio[13969]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 14:52:29 volumio volumio[13969]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 14:52:29 volumio volumio[13969]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 14:52:29 volumio volumio[13969]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 14:52:29 volumio volumio[13969]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 14:52:29 volumio go-librespot[14317]: time="2026-01-28T14:52:29+07:00" level=debug msg="obtained new client token: AADZSXJ51lqUjetF5mrUmxpFo5DnX8MgI7EUIsl3+u/1KFv6fgzxpOxJvAjA/bwD124NUThege6MMm7Rk3Ayg7YSp6/YkwDheSoIeuCUsznWaKT4xzVvw96ZlPAQ4vz82ZiAoC1eWKNbgZ120YSbTH7KA04H7jNk820NBkPwbS+R4t5hlIYZhRMJMMCDkvrMKxmyNPXVt8lD4fLItFNSFgCnyArVbsFs65iZ/m+M2tcel2Y4QMPA4cm6dwI=" Jan 28 14:52:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:52:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:52:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:52:29 volumio go-librespot[14317]: time="2026-01-28T14:52:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:52:29 volumio go-librespot[14317]: time="2026-01-28T14:52:29+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 14:52:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:52:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:52:31 volumio volumio[13969]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 14:52:31 volumio volumio[13969]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 14:52:31 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:52:31 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:52:31 volumio volumio[13969]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 14:52:31 volumio volumio[13969]: info: MyVolumio login type: Token Jan 28 14:52:31 volumio volumio[13969]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 14:52:31 volumio volumio[13969]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 14:52:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:52:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:52:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:52:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 28 14:52:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:52:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:52:32 volumio go-librespot[14339]: go-librespot daemon starting... Jan 28 14:52:32 volumio go-librespot[14340]: time="2026-01-28T14:52:32+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:52:32 volumio go-librespot[14340]: time="2026-01-28T14:52:32+07:00" level=debug msg="app state loaded" Jan 28 14:52:32 volumio go-librespot[14340]: time="2026-01-28T14:52:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:52:32 volumio volumio[13969]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 14:52:32 volumio volumio[13969]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 14:52:32 volumio volumio[13969]: info: Streaming services startup Jan 28 14:52:32 volumio volumio[13969]: info: Starting Streaming Daemon Jan 28 14:52:32 volumio sudo[14348]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 14:52:32 volumio sudo[14348]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:52:32 volumio volumio[13969]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 14:52:33 volumio sudo[14348]: pam_unix(sudo:session): session closed for user root Jan 28 14:52:33 volumio volumio[13969]: info: Initializing connection to go-librespot Websocket Jan 28 14:52:33 volumio volumio[13969]: error: Cannot start Volumio Streaming Daemon Jan 28 14:52:33 volumio volumio[13969]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 14:52:33 volumio volumio[13969]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 14:52:33 volumio go-librespot[14340]: time="2026-01-28T14:52:33+07:00" level=debug msg="new websocket client" Jan 28 14:52:33 volumio volumio[13969]: info: Connection to go-librespot Websocket established Jan 28 14:52:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:52:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:52:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:52:33 volumio go-librespot[14340]: time="2026-01-28T14:52: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 28 14:52:33 volumio go-librespot[14340]: time="2026-01-28T14:52: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 28 14:52:33 volumio go-librespot[14340]: time="2026-01-28T14:52: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 28 14:52:33 volumio go-librespot[14340]: time="2026-01-28T14:52:33+07:00" level=info msg="zeroconf server listening on port 37289" Jan 28 14:52:33 volumio go-librespot[14340]: time="2026-01-28T14:52:33+07:00" level=debug msg="obtained new client token: AAAezi1WYcON++EDasYiFG7fG69J8gnz5w58MDtLIBiuk55c9TthjPnBX8wo62+RUB8yYduBeYAyoSOheZTY3pzjJq28ea4+WrfkcrBAkUT1vTAsaNXgeI3m1w3V/k31dKXrnIZFNPfPfvIL9tuJ8e/Povlg2w/j+AFDf1xp4pHaHRbVMrqOsnmCJb6i22eKc6sf+vg+ibRdmFyznfs6CXbagDLvl2XMhJcws3aBAkyXCgWG/4T/isqfco8=" Jan 28 14:52:33 volumio go-librespot[14340]: time="2026-01-28T14:52:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:52:33 volumio go-librespot[14340]: time="2026-01-28T14:52: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 28 14:52:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:52:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:52:33 volumio volumio[13969]: info: Connection to go-librespot Websocket closed Jan 28 14:52:34 volumio volumio[13969]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 28 14:52:34 volumio volumio[13969]: info: MyVolumio token set successfully Jan 28 14:52:34 volumio volumio[13969]: info: MYVOLUMIO: Adding device Jan 28 14:52:34 volumio volumio[13969]: info: MYVOLUMIO: Evaluating Server Jan 28 14:52:35 volumio volumio[13969]: info: MyVolumio status changed Jan 28 14:52:35 volumio volumio[13969]: info: Streaming services startup Jan 28 14:52:35 volumio volumio[13969]: info: Starting Streaming Daemon Jan 28 14:52:35 volumio volumio[13969]: info: Removing browser output: myVolumio user plan is not superstar Jan 28 14:52:35 volumio volumio[13969]: info: Removing audio output: Jan 28 14:52:35 volumio volumio[13969]: info: Stoppping Tunnel 1 Jan 28 14:52:35 volumio sudo[14384]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 14:52:35 volumio sudo[14384]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:52:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:52:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:52:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:52:35 volumio sudo[14384]: pam_unix(sudo:session): session closed for user root Jan 28 14:52:35 volumio volumio[13969]: error: Cannot start Volumio Streaming Daemon Jan 28 14:52:35 volumio volumio[13969]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 14:52:35 volumio volumio[13969]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 14:52:35 volumio sudo[14387]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 28 14:52:35 volumio sudo[14387]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:52:35 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 14:52:35 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 14:52:35 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 14:52:35 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 14:52:35 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 14:52:35 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 14:52:35 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 14:52:35 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 14:52:35 volumio sudo[14387]: pam_unix(sudo:session): session closed for user root Jan 28 14:52:35 volumio volumio[13969]: info: Remote SSH Stopped Jan 28 14:52:35 volumio volumio[13969]: info: Setting Geolocation for MyVolumio to as1 Jan 28 14:52:35 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:52:35 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:52:35 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:52:36 volumio volumio[13969]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 28 14:52:36 volumio volumio[13969]: info: Getting Spotify volume Jan 28 14:52:36 volumio volumio[13969]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 14:52:36 volumio volumio[13969]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 14:52:36 volumio volumio[13969]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 28 14:52:36 volumio volumio[13969]: errno: -111, Jan 28 14:52:36 volumio volumio[13969]: code: 'ECONNREFUSED', Jan 28 14:52:36 volumio volumio[13969]: syscall: 'connect', Jan 28 14:52:36 volumio volumio[13969]: address: '127.0.0.1', Jan 28 14:52:36 volumio volumio[13969]: port: 9879, Jan 28 14:52:36 volumio volumio[13969]: response: undefined Jan 28 14:52:36 volumio volumio[13969]: } Jan 28 14:52:36 volumio volumio[13969]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 14:52:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 28 14:52:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:52:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:52:37 volumio go-librespot[14401]: go-librespot daemon starting... Jan 28 14:52:37 volumio go-librespot[14402]: time="2026-01-28T14:52:37+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:52:37 volumio go-librespot[14402]: time="2026-01-28T14:52:37+07:00" level=debug msg="app state loaded" Jan 28 14:52:37 volumio go-librespot[14402]: time="2026-01-28T14:52:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:52:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:52:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:52:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:52:37 volumio go-librespot[14402]: time="2026-01-28T14:52:37+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 14:52:37 volumio go-librespot[14402]: time="2026-01-28T14:52:37+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 14:52:37 volumio go-librespot[14402]: time="2026-01-28T14:52:37+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 14:52:37 volumio go-librespot[14402]: time="2026-01-28T14:52:37+07:00" level=info msg="zeroconf server listening on port 43255" Jan 28 14:52:37 volumio sudo[14411]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 14:51' Jan 28 14:52:37 volumio sudo[14411]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:52:37 volumio go-librespot[14402]: time="2026-01-28T14:52:37+07:00" level=debug msg="obtained new client token: AADtU0dKAGtzk3J26lLFpCMQ60cERC9UnicUZLn1zVqwZ8DENpPj95CND/RnNBYuuhrR9HvVzwPxuEcJOx6uVKJwIYTv8AJ8iXrMT3SVFEm89iEjuyexOAciCndaaKO4lskKcGovRQDdZfbAvWWDV4JuffIxEBG0TJh/SppxMkYJVvyW+51znc0oBzyYAfDL19b4AeYr2yYMKnux7KoJtObS3HbdUgd7ca66ZPAB7eiecnmAQEzzwwUImYA=" Jan 28 14:52:37 volumio go-librespot[14402]: time="2026-01-28T14:52:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:52:37 volumio go-librespot[14402]: time="2026-01-28T14:52:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 14:52:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:52:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"