Feb 18 15:12:00 volumio volumio[21403]: info: go-librespot daemon successfully initialized Feb 18 15:12:00 volumio mpd[21624]: 2026-02-18T15:12:00 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 15:12:00 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 15:12:00 volumio sudo[21584]: pam_unix(sudo:session): session closed for user root Feb 18 15:12:00 volumio sudo[21594]: pam_unix(sudo:session): session closed for user root Feb 18 15:12:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 18 15:12:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:12:00 volumio volumio[21403]: error: MPD error: The expression evaluated to a falsy value: Feb 18 15:12:00 volumio volumio[21403]: assert.ok(self.idling) Feb 18 15:12:00 volumio volumio[21403]: error: The expression evaluated to a falsy value: Feb 18 15:12:00 volumio volumio[21403]: assert.ok(self.idling) Feb 18 15:12:00 volumio volumio[21403]: error: updateQueue error: null Feb 18 15:12:00 volumio volumio[21403]: info: MPD running with PID21624 Feb 18 15:12:00 volumio volumio[21403]: ,establishing connection Feb 18 15:12:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:12:00 volumio go-librespot[21725]: go-librespot daemon starting... Feb 18 15:12:00 volumio go-librespot[21726]: time="2026-02-18T15:12:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:12:00 volumio go-librespot[21726]: time="2026-02-18T15:12:00+07:00" level=debug msg="app state loaded" Feb 18 15:12:00 volumio go-librespot[21726]: time="2026-02-18T15:12:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:12:00 volumio volumio[21403]: info: Completed starting Core Plugins Feb 18 15:12:00 volumio volumio[21403]: info: ------------------------------------------- Feb 18 15:12:00 volumio volumio[21403]: info: ----- MyVolumio plugins startup ---- Feb 18 15:12:00 volumio volumio[21403]: info: ------------------------------------------- Feb 18 15:12:00 volumio volumio[21403]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 15:12:00 volumio volumio[21403]: error: updateQueue error: null Feb 18 15:12:01 volumio go-librespot[21726]: time="2026-02-18T15:12: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]" Feb 18 15:12:01 volumio go-librespot[21726]: time="2026-02-18T15:12: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]" Feb 18 15:12:01 volumio go-librespot[21726]: time="2026-02-18T15:12: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]" Feb 18 15:12:01 volumio go-librespot[21726]: time="2026-02-18T15:12:01+07:00" level=info msg="zeroconf server listening on port 36663" Feb 18 15:12:01 volumio go-librespot[21726]: time="2026-02-18T15:12:01+07:00" level=debug msg="obtained new client token: AAAG66463/8azYeB8wlagCOegXVfm8zVNNFrjzZcq9UF5KQWteGqPajSyf2/00FT0tfw8vBNI5lcNhDVaQ1HLo1OW0u0Tg8KLHwIjhMVlM2O3qgWRacRE/PV+Qo3R3Ihs96coHVZ4cZcpg/Bjqr3C6rKyAIsOdWNS2XoPzN1dN5dQDcsoWTcWeCHnL4qVYCHOtCHvi9E3MRSfVVudH4IkZcjX6BZSUzcxhOGgDLl6NGmXRXEMMw/M0xCQg==" Feb 18 15:12:01 volumio go-librespot[21726]: time="2026-02-18T15:12:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:12:01 volumio go-librespot[21726]: time="2026-02-18T15:12:01+07:00" level=debug msg="completed keyexchange" Feb 18 15:12:01 volumio go-librespot[21726]: time="2026-02-18T15:12:01+07:00" level=debug msg="completed challenge" Feb 18 15:12:01 volumio go-librespot[21726]: time="2026-02-18T15:12: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 " Feb 18 15:12:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:12:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:12:03 volumio volumio[21403]: info: Initializing connection to go-librespot Websocket Feb 18 15:12:03 volumio volumio[21403]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 15:12:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 18 15:12:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:12:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:12:05 volumio go-librespot[21735]: go-librespot daemon starting... Feb 18 15:12:05 volumio go-librespot[21736]: time="2026-02-18T15:12:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:12:05 volumio go-librespot[21736]: time="2026-02-18T15:12:05+07:00" level=debug msg="app state loaded" Feb 18 15:12:05 volumio go-librespot[21736]: time="2026-02-18T15:12:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:12:05 volumio go-librespot[21736]: time="2026-02-18T15:12: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:12:05 volumio go-librespot[21736]: time="2026-02-18T15:12:05+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]" Feb 18 15:12:05 volumio go-librespot[21736]: time="2026-02-18T15:12:05+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]" Feb 18 15:12:05 volumio go-librespot[21736]: time="2026-02-18T15:12:05+07:00" level=info msg="zeroconf server listening on port 43211" Feb 18 15:12:05 volumio volumio[21403]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 15:12:05 volumio go-librespot[21736]: time="2026-02-18T15:12:05+07:00" level=debug msg="obtained new client token: AABizwFIpiCB+m9/5kwiWlZx+7iKYx8vBAfn54NeqQkvnIzq1jf0QBgo1zWYUDbWjXInonE4dJZ1tiNN7NxRfAsDkVeMbdWhbxr/c28MYz37x27gcdXGZLqS3w8PQudePDqjZtxsEW/Z95RDXwWghagOJ2Xk3tFTM+K9yVT29nZsB4RkUpAEo3p/cPFLksTOM95a5sXX/8LjsBQ0yjWABqh+0QEeUWlHLnMJ4chUCh99SzaT1dG4jjBT1Q==" Feb 18 15:12:05 volumio go-librespot[21736]: time="2026-02-18T15:12:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:12:06 volumio go-librespot[21736]: time="2026-02-18T15:12:06+07:00" level=debug msg="completed keyexchange" Feb 18 15:12:06 volumio go-librespot[21736]: time="2026-02-18T15:12:06+07:00" level=debug msg="completed challenge" Feb 18 15:12:06 volumio go-librespot[21736]: time="2026-02-18T15:12:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 15:12:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:12:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:12:06 volumio volumio[21403]: info: Initializing connection to go-librespot Websocket Feb 18 15:12:06 volumio volumio[21403]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 15:12:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 18 15:12:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:12:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:12:09 volumio go-librespot[21744]: go-librespot daemon starting... Feb 18 15:12:09 volumio go-librespot[21745]: time="2026-02-18T15:12:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:12:09 volumio go-librespot[21745]: time="2026-02-18T15:12:09+07:00" level=debug msg="app state loaded" Feb 18 15:12:09 volumio go-librespot[21745]: time="2026-02-18T15:12:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:12:09 volumio volumio[21403]: info: Initializing connection to go-librespot Websocket Feb 18 15:12:09 volumio go-librespot[21745]: time="2026-02-18T15:12:09+07:00" level=debug msg="new websocket client" Feb 18 15:12:09 volumio volumio[21403]: info: Connection to go-librespot Websocket established Feb 18 15:12:09 volumio volumio[21403]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 15:12:09 volumio volumio[21403]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 15:12:09 volumio volumio[21403]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 15:12:09 volumio volumio[21403]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 15:12:09 volumio volumio[21403]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 15:12:09 volumio volumio[21403]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 15:12:09 volumio volumio[21403]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 15:12:09 volumio volumio[21403]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 15:12:09 volumio volumio[21403]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 15:12:09 volumio volumio[21403]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 15:12:09 volumio volumio[21403]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 15:12:09 volumio volumio[21403]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 15:12:09 volumio volumio[21403]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 15:12:09 volumio volumio[21403]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 15:12:09 volumio volumio[21403]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 15:12:09 volumio volumio[21403]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 15:12:09 volumio volumio[21403]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 15:12:09 volumio volumio[21403]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 15:12:09 volumio volumio[21403]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 15:12:09 volumio volumio[21403]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 15:12:09 volumio volumio[21403]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 15:12:09 volumio volumio[21403]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 15:12:09 volumio volumio[21403]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 15:12:09 volumio volumio[21403]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 15:12:09 volumio volumio[21403]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 15:12:09 volumio volumio[21403]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 15:12:09 volumio volumio[21403]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 15:12:09 volumio volumio[21403]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 15:12:09 volumio volumio[21403]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 15:12:09 volumio volumio[21403]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 15:12:09 volumio volumio[21403]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 15:12:09 volumio volumio[21403]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 15:12:09 volumio volumio[21403]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 15:12:09 volumio volumio[21403]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 15:12:09 volumio volumio[21403]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 15:12:09 volumio volumio[21403]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 15:12:09 volumio go-librespot[21745]: time="2026-02-18T15:12: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:12:09 volumio go-librespot[21745]: time="2026-02-18T15:12:09+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]" Feb 18 15:12:09 volumio go-librespot[21745]: time="2026-02-18T15:12:09+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]" Feb 18 15:12:09 volumio go-librespot[21745]: time="2026-02-18T15:12:09+07:00" level=info msg="zeroconf server listening on port 40201" Feb 18 15:12:10 volumio go-librespot[21745]: time="2026-02-18T15:12:10+07:00" level=debug msg="obtained new client token: AACJklswf10mXdMYCLxPRjc/7MdOVb2HwjOKQW35DV6+Gb6XHBPDPHFAfi1DQegq+fAFwahkM+M1NqTRjjILz2nK6AdnJ6KzhjG2W2LheEB1aQvFZzxwFDSv1Se3SdBdiLH8EyurWKp0GwmdyRl1aEQHSI2fo5ZefSElpK08WIVGwaWpzYJj73llpGcHVKVmANNK+TWsKGKmPOggykMel2ed2/8zFEU0aU4WC6p1n/2sgF55jjiokpI=" Feb 18 15:12:10 volumio go-librespot[21745]: time="2026-02-18T15:12:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:12:10 volumio go-librespot[21745]: time="2026-02-18T15:12:10+07:00" level=debug msg="completed keyexchange" Feb 18 15:12:10 volumio go-librespot[21745]: time="2026-02-18T15:12:10+07:00" level=debug msg="completed challenge" Feb 18 15:12:10 volumio go-librespot[21745]: time="2026-02-18T15:12:10+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 " Feb 18 15:12:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:12:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:12:11 volumio volumio[21403]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 15:12:11 volumio volumio[21403]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 15:12:11 volumio volumio[21403]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:12:11 volumio volumio[21403]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:12:11 volumio volumio[21403]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 15:12:11 volumio volumio[21403]: info: MyVolumio login type: Token Feb 18 15:12:11 volumio volumio[21403]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 15:12:11 volumio volumio[21403]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 15:12:13 volumio volumio[21403]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 15:12:13 volumio volumio[21403]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 15:12:13 volumio volumio[21403]: info: Streaming services startup Feb 18 15:12:13 volumio volumio[21403]: info: Starting Streaming Daemon Feb 18 15:12:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 18 15:12:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:12:13 volumio sudo[21771]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 15:12:13 volumio sudo[21771]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:12:13 volumio volumio[21403]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 15:12:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:12:13 volumio go-librespot[21776]: go-librespot daemon starting... Feb 18 15:12:13 volumio go-librespot[21778]: time="2026-02-18T15:12:13+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:12:13 volumio go-librespot[21778]: time="2026-02-18T15:12:13+07:00" level=debug msg="app state loaded" Feb 18 15:12:13 volumio sudo[21771]: pam_unix(sudo:session): session closed for user root Feb 18 15:12:13 volumio go-librespot[21778]: time="2026-02-18T15:12:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:12:13 volumio volumio[21403]: info: Getting Spotify volume Feb 18 15:12:13 volumio volumio[21403]: info: Connection to go-librespot Websocket closed Feb 18 15:12:13 volumio volumio[21403]: error: Cannot start Volumio Streaming Daemon Feb 18 15:12:13 volumio volumio[21403]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 15:12:13 volumio volumio[21403]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 15:12:13 volumio volumio[21403]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 18 15:12:14 volumio volumio[21403]: info: CoreCommandRouter::volumioGetState Feb 18 15:12:14 volumio volumio[21403]: info: CorePlayQueue::getTrack 0 Feb 18 15:12:14 volumio volumio[21403]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 18 15:12:14 volumio volumio[21403]: SPOTIFY: SPOTIFY VOLUME undefined Feb 18 15:12:14 volumio volumio[21403]: SPOTIFY: VOLUMIO VOLUME 100 Feb 18 15:12:14 volumio volumio[21403]: info: Aligning Spotify Volume to Volumio Volume Feb 18 15:12:14 volumio volumio[21403]: info: CoreCommandRouter::volumioGetState Feb 18 15:12:14 volumio volumio[21403]: info: CorePlayQueue::getTrack 0 Feb 18 15:12:14 volumio volumio[21403]: info: Setting Spotify Volume from Volumio: 100 Feb 18 15:12:14 volumio go-librespot[21778]: time="2026-02-18T15:12:14+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:12:14 volumio go-librespot[21778]: time="2026-02-18T15:12:14+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 15:12:14 volumio go-librespot[21778]: time="2026-02-18T15:12:14+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 15:12:14 volumio go-librespot[21778]: time="2026-02-18T15:12:14+07:00" level=info msg="zeroconf server listening on port 46321" Feb 18 15:12:14 volumio go-librespot[21778]: time="2026-02-18T15:12:14+07:00" level=debug msg="obtained new client token: AAC+jboGclDur8vKhaVVWu9/+vGrrqGRiYlJakZNKvr62B7lJTnqexgteC4wDatylwVhBX5+1LTCo1c5q5NDn4FLyHS3kf6Koyj0UMXuarhQy8nZd3iOWluIRr9cBWPZBKrFc0mGd//ugmmYRhUtGse/6BvN/rJUifbvbZNJ/kBgtmGqJa2S+sSyZUv9bRf3/xI7WPQM0DZ5wi9DvMSx2wrPsRRP0w0TwmraathtGEuyJcpZJYTdH+YiaQ==" Feb 18 15:12:14 volumio go-librespot[21778]: time="2026-02-18T15:12:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:12:14 volumio go-librespot[21778]: time="2026-02-18T15:12:14+07:00" level=debug msg="completed keyexchange" Feb 18 15:12:14 volumio go-librespot[21778]: time="2026-02-18T15:12:14+07:00" level=debug msg="completed challenge" Feb 18 15:12:14 volumio go-librespot[21778]: time="2026-02-18T15:12:14+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 " Feb 18 15:12:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:12:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:12:14 volumio volumio[21403]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 18 15:12:14 volumio volumio[21403]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 15:12:14 volumio volumio[21403]: Error: socket hang up Feb 18 15:12:14 volumio volumio[21403]: at connResetException (node:internal/errors:720:14) Feb 18 15:12:14 volumio volumio[21403]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 18 15:12:14 volumio volumio[21403]: at Socket.emit (node:events:526:35) Feb 18 15:12:14 volumio volumio[21403]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 18 15:12:14 volumio volumio[21403]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 18 15:12:14 volumio volumio[21403]: code: 'ECONNRESET', Feb 18 15:12:14 volumio volumio[21403]: response: undefined Feb 18 15:12:14 volumio volumio[21403]: } Feb 18 15:12:14 volumio volumio[21403]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 15:12:16 volumio sudo[21799]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 15:11' Feb 18 15:12:16 volumio sudo[21799]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:12:16 volumio sudo[21799]: pam_unix(sudo:session): session closed for user root Feb 18 15:12:16 volumio volumio-remote-updater[25144]: [2026-02-18 15:12:16] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 18 15:12:16 volumio volumio-remote-updater[25144]: [2026-02-18 15:12:16] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 18 15:12:16 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:12:16 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 18 15:12:16 volumio systemd[1]: volumio.service: Consumed 55.948s CPU time. Feb 18 15:12:16 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 15:12:16 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 15:12:16 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 22058. Feb 18 15:12:16 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 15:12:16 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 18 15:12:16 volumio systemd[1]: volumio.service: Consumed 55.948s CPU time. Feb 18 15:12:16 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 18 15:12:16 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 15:12:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 18 15:12:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:12:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:12:18 volumio go-librespot[21830]: go-librespot daemon starting... Feb 18 15:12:18 volumio go-librespot[21831]: time="2026-02-18T15:12:18+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:12:18 volumio go-librespot[21831]: time="2026-02-18T15:12:18+07:00" level=debug msg="app state loaded" Feb 18 15:12:18 volumio go-librespot[21831]: time="2026-02-18T15:12:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:12:18 volumio go-librespot[21831]: time="2026-02-18T15:12:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:12:18 volumio go-librespot[21831]: time="2026-02-18T15:12:18+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 15:12:18 volumio go-librespot[21831]: time="2026-02-18T15:12:18+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 15:12:18 volumio go-librespot[21831]: time="2026-02-18T15:12:18+07:00" level=info msg="zeroconf server listening on port 42597" Feb 18 15:12:18 volumio go-librespot[21831]: time="2026-02-18T15:12:18+07:00" level=debug msg="obtained new client token: AABxSYQiSq/MsD+MyJZKQ4760i5BAv0rVqr9qn0G1moAPjOZCpqW92Ze2RXrKebbG7rZJDhgkIAFjmoo7XFjhFxNj5YBUydtZ2hoLAA3We7X4NlCBS4D7YSGXeAiR/4BJL1CNz8S739BVG2Hn+1KwwYAfkVnCBeYleBmpshs5+MltyLPkxQn0YaUuNT208Tb0vr1fVh0Z+h/+ZZkfnilTORM2zUCxaXu8cEENqci7DJOj55k3bbMykV6MA==" Feb 18 15:12:19 volumio go-librespot[21831]: time="2026-02-18T15:12:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:12:19 volumio go-librespot[21831]: time="2026-02-18T15:12:19+07:00" level=debug msg="completed keyexchange" Feb 18 15:12:19 volumio go-librespot[21831]: time="2026-02-18T15:12:19+07:00" level=debug msg="completed challenge" Feb 18 15:12:19 volumio go-librespot[21831]: time="2026-02-18T15:12:19+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 " Feb 18 15:12:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:12:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:12:20 volumio volumio[21815]: info: ------------------------------------------- Feb 18 15:12:20 volumio volumio[21815]: info: ----- Volumio3 ---- Feb 18 15:12:20 volumio volumio[21815]: info: ------------------------------------------- Feb 18 15:12:20 volumio volumio[21815]: info: ----- System startup ---- Feb 18 15:12:20 volumio volumio[21815]: info: ------------------------------------------- Feb 18 15:12:21 volumio volumio-remote-updater[25144]: [2026-02-18 15:12:21] [connect] Successful connection Feb 18 15:12:21 volumio volumio[21815]: info: MYVOLUMIO Environment detected Feb 18 15:12:22 volumio volumio[21815]: info: Plugin folders cleanup Feb 18 15:12:22 volumio volumio[21815]: info: Scanning into folder /volumio/app/plugins/ Feb 18 15:12:22 volumio volumio[21815]: info: Scanning category audio_interface Feb 18 15:12:22 volumio volumio[21815]: info: Scanning category miscellanea Feb 18 15:12:22 volumio volumio[21815]: info: Scanning category music_service Feb 18 15:12:22 volumio volumio[21815]: info: Scanning category plugins.json Feb 18 15:12:22 volumio volumio[21815]: info: Scanning category system_controller Feb 18 15:12:22 volumio volumio[21815]: info: Scanning category user_interface Feb 18 15:12:22 volumio volumio[21815]: info: Scanning into folder /data/plugins/ Feb 18 15:12:22 volumio volumio[21815]: info: Scanning category music_service Feb 18 15:12:22 volumio volumio[21815]: info: Plugin folders cleanup completed Feb 18 15:12:22 volumio volumio[21815]: info: ------------------------------------------- Feb 18 15:12:22 volumio volumio[21815]: info: ----- Core plugins startup ---- Feb 18 15:12:22 volumio volumio[21815]: info: ------------------------------------------- Feb 18 15:12:22 volumio volumio[21815]: info: Loading plugins from folder /volumio/app/plugins/ Feb 18 15:12:22 volumio volumio[21815]: info: Adding plugin upnp to MyMusic Plugins Feb 18 15:12:22 volumio volumio[21815]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 18 15:12:22 volumio volumio[21815]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 18 15:12:22 volumio volumio[21815]: info: Loading plugins from folder /data/plugins/ Feb 18 15:12:22 volumio volumio[21815]: info: Loading plugin "system"... Feb 18 15:12:22 volumio volumio[21815]: info: Loading plugin "appearance"... Feb 18 15:12:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 18 15:12:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:12:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:12:22 volumio go-librespot[21850]: go-librespot daemon starting... Feb 18 15:12:22 volumio go-librespot[21851]: time="2026-02-18T15:12:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:12:22 volumio go-librespot[21851]: time="2026-02-18T15:12:22+07:00" level=debug msg="app state loaded" Feb 18 15:12:22 volumio go-librespot[21851]: time="2026-02-18T15:12:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:12:23 volumio go-librespot[21851]: time="2026-02-18T15:12:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:12:23 volumio go-librespot[21851]: time="2026-02-18T15:12:23+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]" Feb 18 15:12:23 volumio go-librespot[21851]: time="2026-02-18T15:12:23+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]" Feb 18 15:12:23 volumio go-librespot[21851]: time="2026-02-18T15:12:23+07:00" level=info msg="zeroconf server listening on port 44529" Feb 18 15:12:23 volumio go-librespot[21851]: time="2026-02-18T15:12:23+07:00" level=debug msg="obtained new client token: AAC3QxzoWMjvBlREpqOs2djCfqox2Bb9RKuMRlrUtbmZzWuopuzqxgTdxAb1Thjyl1iAa1s72cDsLv+tiEftqYT18MLpmd/tOMdWRTraZRQOlRsKxTrPxEy+4R+h0u58JtW49c4NeRz2LGu/3gqMgLCPTaNI3k77SOl2M9WLUGlWukhhZ0QFDK60piD9YJpI7Ghw3n0t7uoZO5kErYR/SYTjnL22LcVq8ALRLFVejT/c+51NeRT1jCM=" Feb 18 15:12:23 volumio go-librespot[21851]: time="2026-02-18T15:12:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:12:23 volumio go-librespot[21851]: time="2026-02-18T15:12:23+07:00" level=debug msg="completed keyexchange" Feb 18 15:12:23 volumio go-librespot[21851]: time="2026-02-18T15:12:23+07:00" level=debug msg="completed challenge" Feb 18 15:12:23 volumio go-librespot[21851]: time="2026-02-18T15:12:23+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 " Feb 18 15:12:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:12:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:12:24 volumio volumio[21815]: info: Loading plugin "network"... Feb 18 15:12:24 volumio volumio[21815]: info: Refreshing Cached IP Addresses Feb 18 15:12:24 volumio sudo[21860]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 15:12:24 volumio sudo[21860]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:12:24 volumio sudo[21860]: pam_unix(sudo:session): session closed for user root Feb 18 15:12:24 volumio sudo[21862]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 15:12:24 volumio sudo[21862]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:12:24 volumio volumio[21815]: info: Loading plugin "services"... Feb 18 15:12:24 volumio volumio[21815]: info: Loading plugin "alsa_controller"... Feb 18 15:12:24 volumio sudo[21862]: pam_unix(sudo:session): session closed for user root Feb 18 15:12:24 volumio sudo[21869]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 18 15:12:24 volumio sudo[21869]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:12:24 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 15:12:24 volumio volumio[21815]: info: Loading plugin "wizard"... Feb 18 15:12:24 volumio volumio[21815]: info: Loading plugin "networkfs"... Feb 18 15:12:24 volumio volumio[21815]: info: Starting Udev Watcher for removable devices Feb 18 15:12:24 volumio volumio[21815]: info: Ignoring mount for partition: boot Feb 18 15:12:24 volumio volumio[21815]: info: Ignoring mount for partition: volumio Feb 18 15:12:24 volumio volumio[21815]: info: Ignoring mount for partition: volumio_data Feb 18 15:12:24 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 15:12:24 volumio volumio[21815]: info: Loading plugin "volumio_command_line_client"... Feb 18 15:12:24 volumio volumio[21815]: info: Loading plugin "upnp"... Feb 18 15:12:24 volumio volumio[21815]: info: [1771402344555] Starting Upmpd Daemon Feb 18 15:12:24 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 15:12:24 volumio volumio[21815]: info: Loading plugin "my_music"... Feb 18 15:12:24 volumio volumio[21815]: info: Loading plugin "mpd"... Feb 18 15:12:25 volumio volumio[21815]: info: Loading plugin "upnp_browser"... Feb 18 15:12:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 18 15:12:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:12:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:12:26 volumio go-librespot[21893]: go-librespot daemon starting... Feb 18 15:12:26 volumio go-librespot[21894]: time="2026-02-18T15:12:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:12:26 volumio go-librespot[21894]: time="2026-02-18T15:12:26+07:00" level=debug msg="app state loaded" Feb 18 15:12:26 volumio go-librespot[21894]: time="2026-02-18T15:12:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:12:27 volumio sudo[21869]: pam_unix(sudo:session): session closed for user root Feb 18 15:12:27 volumio go-librespot[21894]: time="2026-02-18T15:12:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 15:12:27 volumio go-librespot[21894]: time="2026-02-18T15:12:27+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 15:12:27 volumio go-librespot[21894]: time="2026-02-18T15:12:27+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 15:12:27 volumio go-librespot[21894]: time="2026-02-18T15:12:27+07:00" level=info msg="zeroconf server listening on port 43255" Feb 18 15:12:27 volumio go-librespot[21894]: time="2026-02-18T15:12:27+07:00" level=debug msg="obtained new client token: AADa6dbEG/BBw2Wq+5ffRAD+e7MQKxJUYjPoCxqIygDT9ni42wOHIdRLz67l2G3iOZk7q0JbC9K/yrQ4wYYUdDl4GQJb1nzMhuJ9O8yUnvLrag5j44mS6vCf/aLCu6c8DHFQTn26RW9eE5Pg1/LM8iIKyI6K8ps4n74oGkKFWdpnqSpDWA1qAddgZfIFSePwSCA3UsDPuC0TnQpbFImyjsQa5MzlO27vp/azlhxZZwXw6ZbguK0KASd1zA==" Feb 18 15:12:27 volumio go-librespot[21894]: time="2026-02-18T15:12:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:12:27 volumio go-librespot[21894]: time="2026-02-18T15:12:27+07:00" level=debug msg="completed keyexchange" Feb 18 15:12:27 volumio go-librespot[21894]: time="2026-02-18T15:12:27+07:00" level=debug msg="completed challenge" Feb 18 15:12:27 volumio go-librespot[21894]: time="2026-02-18T15:12:27+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 " Feb 18 15:12:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:12:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:12:28 volumio volumio[21815]: info: Starting UPNP Browser Feb 18 15:12:28 volumio volumio[21815]: info: Loading plugin "alarm-clock"... Feb 18 15:12:28 volumio volumio[21815]: info: Loading plugin "airplay_emulation"... Feb 18 15:12:28 volumio volumio[21815]: info: Starting Shairport Sync Feb 18 15:12:28 volumio volumio[21815]: info: Loading plugin "last_100"... Feb 18 15:12:28 volumio volumio[21815]: info: Loading plugin "webradio"... Feb 18 15:12:28 volumio volumio[21815]: info: Loading plugin "i2s_dacs"... Feb 18 15:12:28 volumio volumio[21815]: info: Loading plugin "volumiodiscovery"... Feb 18 15:12:28 volumio volumio[21815]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 15:12:28 volumio node[21815]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 15:12:28 volumio volumio[21815]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 15:12:28 volumio node[21815]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 15:12:28 volumio volumio[21815]: *** WARNING *** For more information see Feb 18 15:12:28 volumio volumio[21815]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 15:12:28 volumio node[21815]: *** WARNING *** For more information see Feb 18 15:12:28 volumio volumio[21815]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 15:12:28 volumio volumio[21815]: *** WARNING *** For more information see Feb 18 15:12:28 volumio node[21815]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 15:12:28 volumio node[21815]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 15:12:28 volumio node[21815]: *** WARNING *** For more information see Feb 18 15:12:28 volumio volumio[21815]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 18 15:12:28 volumio volumio[21815]: info: Discovery: Started advertising with name: Volumio Feb 18 15:12:28 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 15:12:28 volumio volumio[21815]: info: Loading plugin "spop"... Feb 18 15:12:30 volumio volumio[21815]: info: Loading plugin "ytcr"... Feb 18 15:12:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 18 15:12:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:12:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:12:30 volumio go-librespot[21903]: go-librespot daemon starting... Feb 18 15:12:30 volumio go-librespot[21904]: time="2026-02-18T15:12:30+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:12:30 volumio go-librespot[21904]: time="2026-02-18T15:12:30+07:00" level=debug msg="app state loaded" Feb 18 15:12:30 volumio go-librespot[21904]: time="2026-02-18T15:12:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:12:31 volumio go-librespot[21904]: time="2026-02-18T15:12: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]" Feb 18 15:12:31 volumio go-librespot[21904]: time="2026-02-18T15:12: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]" Feb 18 15:12:31 volumio go-librespot[21904]: time="2026-02-18T15:12: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]" Feb 18 15:12:31 volumio go-librespot[21904]: time="2026-02-18T15:12:31+07:00" level=info msg="zeroconf server listening on port 43925" Feb 18 15:12:31 volumio go-librespot[21904]: time="2026-02-18T15:12:31+07:00" level=debug msg="obtained new client token: AABxw0C5xM3LJhvmOez7OR2TsGCfBC1+glvbhP6TZKYwGWTZyiulTYI/fbVSFhi0AM4+JS/k1MKSGz6iFEA3X1642i5ZrLzXOMAJ05KSWTUDQZ4GXuo1M/4szaoZ/d03sBrvmDzY9k9d12E6EUzFLYYqMXUlo06P6iDO32+KLv3GEos4dLO2kYuueelfngiyDXBf+Ew890sDDJBBGvD6NC7quyo/m3c0+8aTUzjPdZPPUKy8eunI+zRy0A==" Feb 18 15:12:31 volumio go-librespot[21904]: time="2026-02-18T15:12:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:12:31 volumio go-librespot[21904]: time="2026-02-18T15:12:31+07:00" level=debug msg="completed keyexchange" Feb 18 15:12:31 volumio go-librespot[21904]: time="2026-02-18T15:12:31+07:00" level=debug msg="completed challenge" Feb 18 15:12:31 volumio go-librespot[21904]: time="2026-02-18T15:12: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 " Feb 18 15:12:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:12:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:12:33 volumio volumio[21815]: info: Loading plugin "ytmusic"... Feb 18 15:12:34 volumio volumio-remote-updater[25144]: [2026-02-18 15:12:34] [connect] Successful connection Feb 18 15:12:34 volumio volumio[21815]: info: Loading plugin "outputs"... Feb 18 15:12:34 volumio volumio[21815]: info: Loading plugin "albumart"... Feb 18 15:12:34 volumio volumio[21815]: info: Plugin example_plugin is not enabled Feb 18 15:12:34 volumio volumio[21815]: info: Loading plugin "inputs"... Feb 18 15:12:34 volumio volumio[21815]: info: Loading plugin "updater_comm"... Feb 18 15:12:34 volumio volumio[21815]: info: Plugin mpdemulation is not enabled Feb 18 15:12:34 volumio volumio[21815]: info: Loading plugin "rest_api"... Feb 18 15:12:34 volumio volumio[21815]: info: Loading plugin "websocket"... Feb 18 15:12:34 volumio volumio[21815]: info: Starting Socket.io Server version 1.7.4 Feb 18 15:12:34 volumio volumio[21815]: info: Loading plugin "RoonBridge"... Feb 18 15:12:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 18 15:12:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:12:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:12:35 volumio go-librespot[21940]: go-librespot daemon starting... Feb 18 15:12:35 volumio go-librespot[21941]: time="2026-02-18T15:12:35+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:12:35 volumio go-librespot[21941]: time="2026-02-18T15:12:35+07:00" level=debug msg="app state loaded" Feb 18 15:12:35 volumio go-librespot[21941]: time="2026-02-18T15:12:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:12:35 volumio volumio[21815]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 15:12:35 volumio volumio[21815]: info: Loading i18n strings for locale en Feb 18 15:12:35 volumio volumio[21815]: Updating browse sources language Feb 18 15:12:35 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:12:35 volumio volumio[21930]: Forking 3 albumart workers Feb 18 15:12:35 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 15:12:35 volumio volumio[21815]: info: CoreCommandRouter::initPlayerControls Feb 18 15:12:35 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:12:35 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:12:35 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:12:35 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:12:35 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:12:35 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:12:35 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:12:35 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:12:35 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 15:12:35 volumio volumio[21815]: Express server listening on port 3000 Feb 18 15:12:35 volumio volumio[21815]: [Metrics] WebUI: 16s 32.39ms Feb 18 15:12:35 volumio go-librespot[21941]: time="2026-02-18T15:12: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:12:35 volumio go-librespot[21941]: time="2026-02-18T15:12:35+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]" Feb 18 15:12:35 volumio go-librespot[21941]: time="2026-02-18T15:12:35+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]" Feb 18 15:12:35 volumio volumio[21815]: info: CoreStateMachine::resetVolumioState Feb 18 15:12:35 volumio volumio[21815]: info: CoreStateMachine::getcurrentVolume Feb 18 15:12:35 volumio volumio[21815]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 15:12:35 volumio go-librespot[21941]: time="2026-02-18T15:12:35+07:00" level=info msg="zeroconf server listening on port 45499" Feb 18 15:12:35 volumio sudo[21981]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 15:12:35 volumio sudo[21981]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:12:35 volumio sudo[21983]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 15:12:35 volumio sudo[21983]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:12:36 volumio sudo[21983]: pam_unix(sudo:session): session closed for user root Feb 18 15:12:36 volumio sudo[21981]: pam_unix(sudo:session): session closed for user root Feb 18 15:12:36 volumio go-librespot[21941]: time="2026-02-18T15:12:36+07:00" level=debug msg="obtained new client token: AAAd5U07vknrXEwmec/K1faynbqFK4VQfl8z1Gy+nlsUpLOMKHFtbnCLJwMYDSpuYsOIB9GZgbAasxbXnFtf8K4KeIn0A21u0+LY/eMgyG32xIwYBVF73e+BTJpgvIT68AwadGmCsX2xV5Nfe/RtkGYft0dFcrFDWZExkBX831+YBGJScfrsJxVrhguGnA0hkRLmxQZ2bXj+7HeCGrrxIGTOj83xmcPYUTqid4gbwucGbkFdvyKVRFK0Aw==" Feb 18 15:12:36 volumio volumio[21815]: info: Volumio Network Manager: Network status updated: 1 Feb 18 15:12:36 volumio go-librespot[21941]: time="2026-02-18T15:12:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:12:36 volumio go-librespot[21941]: time="2026-02-18T15:12:36+07:00" level=debug msg="completed keyexchange" Feb 18 15:12:36 volumio go-librespot[21941]: time="2026-02-18T15:12:36+07:00" level=debug msg="completed challenge" Feb 18 15:12:36 volumio volumio[21815]: info: VolumeController:: Volume=100 Mute =false Feb 18 15:12:36 volumio volumio[21815]: info: CoreStateMachine::pushState Feb 18 15:12:36 volumio go-librespot[21941]: time="2026-02-18T15:12:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 15:12:36 volumio volumio[21815]: info: CorePlayQueue::getTrack 0 Feb 18 15:12:36 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 15:12:36 volumio volumio[21815]: info: CoreCommandRouter::volumioPushState Feb 18 15:12:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:12:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:12:36 volumio volumio[21815]: info: CoreStateMachine::updateTrackBlock Feb 18 15:12:36 volumio volumio[21815]: info: CorePlayQueue::getTrackBlock Feb 18 15:12:36 volumio volumio[21815]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 15:12:36 volumio volumio-remote-updater[25144]: [2026-02-18 15:12:36] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771402354 101 Feb 18 15:12:36 volumio volumio[21815]: 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 Feb 18 15:12:36 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:12:36 volumio volumio[21815]: info: Reloading queue from file Feb 18 15:12:36 volumio volumio[21815]: info: CoreStateMachine::setRepeat null single undefined Feb 18 15:12:36 volumio volumio[21815]: info: CoreStateMachine::pushState Feb 18 15:12:36 volumio volumio[21815]: info: CorePlayQueue::getTrack 0 Feb 18 15:12:36 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 15:12:36 volumio volumio[21815]: info: CoreCommandRouter::volumioPushState Feb 18 15:12:36 volumio volumio[21815]: info: CoreStateMachine::setRandom null Feb 18 15:12:36 volumio volumio[21815]: info: CoreStateMachine::pushState Feb 18 15:12:36 volumio volumio[21815]: info: CorePlayQueue::getTrack 0 Feb 18 15:12:36 volumio volumio[21815]: info: CoreCommandRouter::volumioPushState Feb 18 15:12:36 volumio volumio[21815]: info: Setting Device type: Raspberry PI Feb 18 15:12:36 volumio volumio[21815]: info: Completed loading Core Plugins Feb 18 15:12:36 volumio volumio[21815]: info: Preparing to generate the ALSA configuration file Feb 18 15:12:36 volumio volumio[21815]: info: VolumeController:: Volume=100 Mute =false Feb 18 15:12:36 volumio volumio[21815]: info: CoreStateMachine::pushState Feb 18 15:12:36 volumio volumio[21815]: info: CorePlayQueue::getTrack 0 Feb 18 15:12:36 volumio volumio[21815]: info: CoreCommandRouter::volumioPushState Feb 18 15:12:36 volumio volumio[21815]: info: Asound.conf file unchanged, so no further update is needed Feb 18 15:12:36 volumio volumio[21815]: info: Output device has changed, restarting MPD Feb 18 15:12:36 volumio volumio[21815]: info: Output device has changed, restarting Shairport Sync Feb 18 15:12:36 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:12:36 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:12:36 volumio sudo[22000]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 15:12:36 volumio sudo[22000]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:12:36 volumio sudo[22004]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 15:12:36 volumio sudo[22004]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:12:36 volumio sudo[22002]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 15:12:36 volumio sudo[22002]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:12:37 volumio sudo[22002]: pam_unix(sudo:session): session closed for user root Feb 18 15:12:37 volumio volumio[21815]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 15:12:37 volumio volumio[21815]: info: ___________ START PLUGINS ___________ Feb 18 15:12:37 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 15:12:37 volumio volumio[21815]: info: ControllerMpd::onStart: Initializing MPD Feb 18 15:12:37 volumio volumio[21815]: info: Creating MPD Configuration file Feb 18 15:12:37 volumio sudo[22000]: pam_unix(sudo:session): session closed for user root Feb 18 15:12:37 volumio sudo[22013]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 15:12:37 volumio sudo[22013]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:12:37 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 15:12:37 volumio volumio[21815]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:12:37 volumio volumio[21815]: info: [1771402357243] CoreMusicLibrary::Adding element Media Servers Feb 18 15:12:37 volumio sudo[22013]: pam_unix(sudo:session): session closed for user root Feb 18 15:12:37 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:12:37 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 15:12:37 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 15:12:37 volumio systemd[1]: mpd.service: Consumed 7.113s CPU time. Feb 18 15:12:37 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 15:12:37 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 15:12:37 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 15:12:37 volumio sudo[22015]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 15:12:37 volumio sudo[22015]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:12:37 volumio volumio[21815]: info: UPNP Browser: Client initialized successfully Feb 18 15:12:37 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 15:12:37 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:12:37 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:12:37 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 15:12:37 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 15:12:37 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 15:12:37 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 15:12:37 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 15:12:37 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 15:12:37 volumio volumio[21815]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 15:12:37 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:12:37 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:12:37 volumio volumio[21815]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 15:12:37 volumio volumio[21815]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:12:37 volumio volumio[21815]: info: [1771402357518] CoreMusicLibrary::Adding element Last_100 Feb 18 15:12:37 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:12:37 volumio volumio[21815]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:12:37 volumio volumio[21815]: info: [1771402357533] CoreMusicLibrary::Adding element Webradio Feb 18 15:12:37 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:12:37 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 15:12:37 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 15:12:37 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 15:12:37 volumio volumio[21815]: info: Initializing BBC Radios Feb 18 15:12:37 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 15:12:37 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:12:37 volumio volumio[21815]: info: Creating Spotify config file Feb 18 15:12:37 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:12:38 volumio sudo[22029]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 15:12:38 volumio sudo[22029]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 15:12:38 volumio sudo[22029]: pam_unix(sudo:session): session closed for user root Feb 18 15:12:38 volumio volumio[21949]: Starting albumart workers Feb 18 15:12:38 volumio volumio[21950]: Starting albumart workers Feb 18 15:12:39 volumio volumio[21951]: Starting albumart workers Feb 18 15:12:39 volumio volumio[21815]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:12:39 volumio volumio[21815]: info: [1771402359199] CoreMusicLibrary::Adding element YouTube Music Feb 18 15:12:39 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:12:39 volumio volumio[21815]: Cannot find translation for source YouTube Music Feb 18 15:12:39 volumio volumio[21815]: info: Volumio Calling Home Feb 18 15:12:39 volumio sudo[22046]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 15:12:39 volumio sudo[22046]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:12:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 18 15:12:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:12:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:12:39 volumio go-librespot[22051]: go-librespot daemon starting... Feb 18 15:12:39 volumio sudo[22046]: pam_unix(sudo:session): session closed for user root Feb 18 15:12:39 volumio go-librespot[22052]: time="2026-02-18T15:12:39+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:12:40 volumio volumio[21815]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 15:12:40 volumio volumio[21815]: info: Discovery: Found device Volumio Feb 18 15:12:40 volumio volumio[21815]: info: CoreCommandRouter::volumioGetState Feb 18 15:12:40 volumio volumio[21815]: info: CorePlayQueue::getTrack 0 Feb 18 15:12:40 volumio go-librespot[22052]: time="2026-02-18T15:12:40+07:00" level=info msg="zeroconf server listening on port 36057" Feb 18 15:12:40 volumio volumio[21815]: info: MPD Permissions set Feb 18 15:12:40 volumio volumio[21815]: info: MPD Permissions set Feb 18 15:12:40 volumio volumio[21815]: info: Upmpdcli Daemon Started Feb 18 15:12:40 volumio volumio[21815]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 15:12:40 volumio volumio[21815]: info: Discovery: Found device Volumio Feb 18 15:12:40 volumio volumio[21815]: info: CoreCommandRouter::volumioGetState Feb 18 15:12:40 volumio volumio[21815]: info: CorePlayQueue::getTrack 0 Feb 18 15:12:40 volumio volumio[21815]: info: Spotify config file written Feb 18 15:12:40 volumio volumio[21815]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 18 15:12:40 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:12:40 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:12:40 volumio sudo[22066]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 15:12:40 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:12:40 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:12:40 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:12:40 volumio sudo[22066]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:12:40 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:12:40 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:12:40 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:12:40 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:12:40 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:12:40 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:12:40 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:12:40 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:12:40 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:12:40 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:12:40 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:12:40 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:12:40 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:12:40 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 18 15:12:40 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 18 15:12:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:12:40 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:12:40 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:12:41 volumio volumio[21815]: info: No need to fix Spotify hosts Feb 18 15:12:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:12:41 volumio go-librespot[22078]: go-librespot daemon starting... Feb 18 15:12:41 volumio sudo[22066]: pam_unix(sudo:session): session closed for user root Feb 18 15:12:41 volumio go-librespot[22081]: time="2026-02-18T15:12:41+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:12:41 volumio go-librespot[22081]: time="2026-02-18T15:12:41+07:00" level=debug msg="app state loaded" Feb 18 15:12:41 volumio go-librespot[22081]: time="2026-02-18T15:12:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:12:41 volumio go-librespot[22081]: time="2026-02-18T15:12:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:12:41 volumio go-librespot[22081]: time="2026-02-18T15:12:41+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 15:12:41 volumio go-librespot[22081]: time="2026-02-18T15:12:41+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 15:12:41 volumio go-librespot[22081]: time="2026-02-18T15:12:41+07:00" level=info msg="zeroconf server listening on port 46413" Feb 18 15:12:41 volumio go-librespot[22081]: time="2026-02-18T15:12:41+07:00" level=debug msg="obtained new client token: AADsLcyRpl9ttO9426klhxBYQDsyWqJeZnyzE3TYNIQjAvSVkWRZCHpToXyyNFG3lRdCdEYE0xPFEQ4iyueo4lpM7LKzeeLxbxlZ3fQmzkeU/yVO4Hgz3aH+6EUnH6sqNmD9dH0x+YIyezY7t9RFimulOV3dcY0LtZuvavbOBy6HxsQhdV3fdC83U2L0E8XvAAhvO9w2pUxNWLxeHaf+IshYhGb3yXr9YEHEM2Wh4eqw0h5vF2+qaP5qzg==" Feb 18 15:12:41 volumio volumio[21815]: info: Volumio called home Feb 18 15:12:41 volumio volumio[21815]: info: Starting Shairport Sync Feb 18 15:12:41 volumio volumio[21815]: info: Starting Shairport Sync Feb 18 15:12:41 volumio volumio[21815]: info: Starting Shairport Sync Feb 18 15:12:42 volumio sudo[22099]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 15:12:42 volumio go-librespot[22081]: time="2026-02-18T15:12:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:12:42 volumio sudo[22099]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:12:42 volumio sudo[22102]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 15:12:42 volumio sudo[22102]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:12:42 volumio sudo[22103]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 15:12:42 volumio sudo[22103]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:12:42 volumio go-librespot[22081]: time="2026-02-18T15:12:42+07:00" level=debug msg="completed keyexchange" Feb 18 15:12:42 volumio volumio[21815]: info: CoreCommandRouter::volumioGetState Feb 18 15:12:42 volumio volumio[21815]: info: CorePlayQueue::getTrack 0 Feb 18 15:12:42 volumio go-librespot[22081]: time="2026-02-18T15:12:42+07:00" level=debug msg="completed challenge" Feb 18 15:12:42 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 15:12:42 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 15:12:42 volumio go-librespot[22081]: time="2026-02-18T15:12:42+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 15:12:42 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 15:12:42 volumio systemd[1]: shairport-sync.service: Consumed 2.297s CPU time. Feb 18 15:12:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:12:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:12:42 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 15:12:42 volumio volumio[21815]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 15:12:42 volumio volumio[21815]: SPOTIFY: BQBF3O2UI_dg2_3ZD7qFFHNVzq5kNs19_FPtlgYtE1_XGfmQnY5xfPqgzJlw9yjNud3XZg91l1Rh6G6Pseq6OKYUp9fvNKhuQrKdBHtd595hV54mAZ4ccUE_eY-Dyb3bTrI1nJKn3RsEjzt3bndlIU_1vyZOQUiPbPpJdTM_Vtx6lAhNZPubSY_3KisvVNtXjOzDP3PnXARZ5ghQ6X2Keb6uQClKu3mmltC6V5qaVyvx-PvDZ4bW11DMdelGpFG-vBvyTmc_vqEXh0Foxth8-KcygM_DiA9HY_RweYjxeCq98J6JOad_po7d Feb 18 15:12:42 volumio volumio[21815]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 15:12:42 volumio volumio[21815]: info: New Spotify access token = BQBF3O2UI_dg2_3ZD7qFFHNVzq5kNs19_FPtlgYtE1_XGfmQnY5xfPqgzJlw9yjNud3XZg91l1Rh6G6Pseq6OKYUp9fvNKhuQrKdBHtd595hV54mAZ4ccUE_eY-Dyb3bTrI1nJKn3RsEjzt3bndlIU_1vyZOQUiPbPpJdTM_Vtx6lAhNZPubSY_3KisvVNtXjOzDP3PnXARZ5ghQ6X2Keb6uQClKu3mmltC6V5qaVyvx-PvDZ4bW11DMdelGpFG-vBvyTmc_vqEXh0Foxth8-KcygM_DiA9HY_RweYjxeCq98J6JOad_po7d Feb 18 15:12:42 volumio volumio[21815]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 15:12:42 volumio sudo[22099]: pam_unix(sudo:session): session closed for user root Feb 18 15:12:42 volumio sudo[22102]: pam_unix(sudo:session): session closed for user root Feb 18 15:12:42 volumio volumio[21815]: info: Shairport-Sync Started Feb 18 15:12:42 volumio volumio[21815]: Error adding Membership: Error: addMembership EINVAL Feb 18 15:12:42 volumio volumio[21815]: info: Shairport-Sync Started Feb 18 15:12:42 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 15:12:42 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 15:12:42 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 15:12:42 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 15:12:42 volumio sudo[22103]: pam_unix(sudo:session): session closed for user root Feb 18 15:12:42 volumio volumio[21815]: info: Shairport-Sync Started Feb 18 15:12:42 volumio volumio[21815]: 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"} Feb 18 15:12:42 volumio volumio[21815]: info: Spotify Successfully logged in Feb 18 15:12:42 volumio volumio[21815]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:12:42 volumio volumio[21815]: info: [1771402362767] CoreMusicLibrary::Adding element Spotify Feb 18 15:12:42 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:12:42 volumio volumio[21815]: Cannot find translation for source YouTube Music Feb 18 15:12:42 volumio volumio[21815]: Cannot find translation for source Spotify Feb 18 15:12:43 volumio volumio[21815]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 15:12:43 volumio volumio[21815]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 15:12:43 volumio volumio[21815]: info: VolumeController:: Volume=100 Mute =false Feb 18 15:12:43 volumio volumio[21815]: info: CoreCommandRouter::volumioGetState Feb 18 15:12:43 volumio volumio[21815]: info: CorePlayQueue::getTrack 0 Feb 18 15:12:43 volumio volumio[21815]: info: CoreStateMachine::pushState Feb 18 15:12:43 volumio volumio[21815]: info: CorePlayQueue::getTrack 0 Feb 18 15:12:43 volumio volumio[21815]: info: CoreCommandRouter::volumioPushState Feb 18 15:12:44 volumio volumio[21815]: info: go-librespot daemon successfully initialized Feb 18 15:12:45 volumio mpd[22044]: 2026-02-18T15:12:45 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 15:12:45 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 15:12:45 volumio sudo[22004]: pam_unix(sudo:session): session closed for user root Feb 18 15:12:45 volumio sudo[22015]: pam_unix(sudo:session): session closed for user root Feb 18 15:12:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 18 15:12:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:12:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:12:45 volumio go-librespot[22145]: go-librespot daemon starting... Feb 18 15:12:45 volumio go-librespot[22146]: time="2026-02-18T15:12:45+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:12:45 volumio go-librespot[22146]: time="2026-02-18T15:12:45+07:00" level=debug msg="app state loaded" Feb 18 15:12:45 volumio go-librespot[22146]: time="2026-02-18T15:12:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:12:45 volumio volumio[21815]: error: MPD error: The expression evaluated to a falsy value: Feb 18 15:12:45 volumio volumio[21815]: assert.ok(self.idling) Feb 18 15:12:45 volumio volumio[21815]: error: The expression evaluated to a falsy value: Feb 18 15:12:45 volumio volumio[21815]: assert.ok(self.idling) Feb 18 15:12:45 volumio volumio[21815]: info: MPD running with PID22044 Feb 18 15:12:45 volumio volumio[21815]: ,establishing connection Feb 18 15:12:45 volumio volumio[21815]: error: updateQueue error: null Feb 18 15:12:45 volumio volumio[21815]: info: Completed starting Core Plugins Feb 18 15:12:45 volumio volumio[21815]: info: ------------------------------------------- Feb 18 15:12:45 volumio volumio[21815]: info: ----- MyVolumio plugins startup ---- Feb 18 15:12:45 volumio volumio[21815]: info: ------------------------------------------- Feb 18 15:12:45 volumio volumio[21815]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 15:12:45 volumio volumio[21815]: error: updateQueue error: null Feb 18 15:12:45 volumio go-librespot[22146]: time="2026-02-18T15:12:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:12:45 volumio go-librespot[22146]: time="2026-02-18T15:12:45+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]" Feb 18 15:12:45 volumio go-librespot[22146]: time="2026-02-18T15:12:45+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]" Feb 18 15:12:45 volumio go-librespot[22146]: time="2026-02-18T15:12:45+07:00" level=info msg="zeroconf server listening on port 33211" Feb 18 15:12:46 volumio go-librespot[22146]: time="2026-02-18T15:12:46+07:00" level=debug msg="obtained new client token: AAANGHnlqGo71LMsg/7Gpk2WYtorAZECMKn69ccyh6LAB6fXpbaubCNSrV26EuCDe2CzPXkmNnGmNIs9DaJGOviusfh0szrkk/UDIOpdYAJ3KxEWrd8TSlsCXbckomloCf58IUvd+NT2M9T7hYwMjFa7/TgRKpkamyjCKmwmJH88nO+xZc8bwlBQtZiFmK/pxMqWhiTWxKya0zbFSuQCVhAEl7pm1tU1uGHEWS0n1t0Y+0mrtsrhT10=" Feb 18 15:12:46 volumio go-librespot[22146]: time="2026-02-18T15:12:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:12:46 volumio go-librespot[22146]: time="2026-02-18T15:12:46+07:00" level=debug msg="completed keyexchange" Feb 18 15:12:46 volumio go-librespot[22146]: time="2026-02-18T15:12:46+07:00" level=debug msg="completed challenge" Feb 18 15:12:46 volumio go-librespot[22146]: time="2026-02-18T15:12:46+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 15:12:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:12:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:12:47 volumio volumio[21815]: info: Initializing connection to go-librespot Websocket Feb 18 15:12:47 volumio volumio[21815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 15:12:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 18 15:12:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:12:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:12:49 volumio go-librespot[22153]: go-librespot daemon starting... Feb 18 15:12:49 volumio go-librespot[22154]: time="2026-02-18T15:12:49+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:12:49 volumio go-librespot[22154]: time="2026-02-18T15:12:49+07:00" level=debug msg="app state loaded" Feb 18 15:12:49 volumio go-librespot[22154]: time="2026-02-18T15:12:49+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:12:50 volumio go-librespot[22154]: time="2026-02-18T15:12:50+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:12:50 volumio go-librespot[22154]: time="2026-02-18T15:12:50+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 15:12:50 volumio go-librespot[22154]: time="2026-02-18T15:12:50+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 15:12:50 volumio go-librespot[22154]: time="2026-02-18T15:12:50+07:00" level=info msg="zeroconf server listening on port 39961" Feb 18 15:12:50 volumio volumio[21815]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 15:12:50 volumio go-librespot[22154]: time="2026-02-18T15:12:50+07:00" level=debug msg="obtained new client token: AABB/SEu8LwKBQ6CYce2bB036nQ0sx5a1oRy8edN+ZBAT+IJ/YADxou8F4BG/dd74wFW7K9unnz50Oo81c67+BXOO+/ftu4fbsEpUwcwclF2G7Skp8bv64H2dr2S1AFxIFrwf6MM8YH1RSiS8sMZCWRtSMWOHS8YAHvgsAwS+znkDj6ea4+8fUk7p3G4AJJqUBOxRt+kSCBotN0Fgjt7BHJMcIrBQAwG96sGATkX/wRM2CmTq4w3O8Je4w==" Feb 18 15:12:50 volumio go-librespot[22154]: time="2026-02-18T15:12:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:12:50 volumio go-librespot[22154]: time="2026-02-18T15:12:50+07:00" level=debug msg="completed keyexchange" Feb 18 15:12:50 volumio go-librespot[22154]: time="2026-02-18T15:12:50+07:00" level=debug msg="completed challenge" Feb 18 15:12:50 volumio go-librespot[22154]: time="2026-02-18T15:12:50+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 " Feb 18 15:12:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:12:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:12:50 volumio volumio[21815]: info: Initializing connection to go-librespot Websocket Feb 18 15:12:50 volumio volumio[21815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 15:12:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 18 15:12:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:12:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:12:53 volumio go-librespot[22162]: go-librespot daemon starting... Feb 18 15:12:53 volumio go-librespot[22163]: time="2026-02-18T15:12:53+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:12:53 volumio go-librespot[22163]: time="2026-02-18T15:12:53+07:00" level=debug msg="app state loaded" Feb 18 15:12:53 volumio go-librespot[22163]: time="2026-02-18T15:12:53+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:12:53 volumio volumio[21815]: info: Initializing connection to go-librespot Websocket Feb 18 15:12:53 volumio go-librespot[22163]: time="2026-02-18T15:12:53+07:00" level=debug msg="new websocket client" Feb 18 15:12:53 volumio volumio[21815]: info: Connection to go-librespot Websocket established Feb 18 15:12:54 volumio go-librespot[22163]: time="2026-02-18T15:12:54+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 15:12:54 volumio go-librespot[22163]: time="2026-02-18T15:12:54+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]" Feb 18 15:12:54 volumio go-librespot[22163]: time="2026-02-18T15:12:54+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]" Feb 18 15:12:54 volumio go-librespot[22163]: time="2026-02-18T15:12:54+07:00" level=info msg="zeroconf server listening on port 41013" Feb 18 15:12:54 volumio volumio[21815]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 15:12:54 volumio volumio[21815]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 15:12:54 volumio volumio[21815]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 15:12:54 volumio volumio[21815]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 15:12:54 volumio volumio[21815]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 15:12:54 volumio volumio[21815]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 15:12:54 volumio volumio[21815]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 15:12:54 volumio volumio[21815]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 15:12:54 volumio volumio[21815]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 15:12:54 volumio volumio[21815]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 15:12:54 volumio volumio[21815]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 15:12:54 volumio volumio[21815]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 15:12:54 volumio volumio[21815]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 15:12:54 volumio volumio[21815]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 15:12:54 volumio volumio[21815]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 15:12:54 volumio volumio[21815]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 15:12:54 volumio volumio[21815]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 15:12:54 volumio volumio[21815]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 15:12:54 volumio volumio[21815]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 15:12:54 volumio volumio[21815]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 15:12:54 volumio volumio[21815]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 15:12:54 volumio volumio[21815]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 15:12:54 volumio volumio[21815]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 15:12:54 volumio volumio[21815]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 15:12:54 volumio volumio[21815]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 15:12:54 volumio volumio[21815]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 15:12:54 volumio volumio[21815]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 15:12:54 volumio volumio[21815]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 15:12:54 volumio volumio[21815]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 15:12:54 volumio volumio[21815]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 15:12:54 volumio volumio[21815]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 15:12:54 volumio volumio[21815]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 15:12:54 volumio volumio[21815]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 15:12:54 volumio volumio[21815]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 15:12:54 volumio volumio[21815]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 15:12:54 volumio volumio[21815]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 15:12:54 volumio go-librespot[22163]: time="2026-02-18T15:12:54+07:00" level=debug msg="obtained new client token: AADW02FGOD5rMjRRTaowWb4/4Mv14hTSxuqa57Oy3h303A11bv7zNit37BsDpV4vsm7dXv+0CJ5b1mz5ktoEtPtANlEO/4t1WTnXMr5UOQtR7Hro2EMAvp/1TVRhHKJHKa3DNb342UiUWveFW/015j1mI6gBI4UQcD22Jj0tE94T3v1bgcF7LMrJFtafrag00EVnhyj5gJjUDiZCpanD2+1HImg5hSVOX+kLKskS0cloF/yCFtYasPtiRQ==" Feb 18 15:12:54 volumio go-librespot[22163]: time="2026-02-18T15:12:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:12:54 volumio go-librespot[22163]: time="2026-02-18T15:12:54+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 15:12:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:12:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:12:56 volumio volumio[21815]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 15:12:56 volumio volumio[21815]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 15:12:56 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:12:56 volumio volumio[21815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:12:56 volumio volumio[21815]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 15:12:56 volumio volumio[21815]: info: MyVolumio login type: Token Feb 18 15:12:56 volumio volumio[21815]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 15:12:56 volumio volumio[21815]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 15:12:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 18 15:12:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:12:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:12:58 volumio go-librespot[22185]: go-librespot daemon starting... Feb 18 15:12:58 volumio volumio[21815]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 15:12:58 volumio volumio[21815]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 15:12:58 volumio volumio[21815]: info: Streaming services startup Feb 18 15:12:58 volumio volumio[21815]: info: Starting Streaming Daemon Feb 18 15:12:58 volumio go-librespot[22186]: time="2026-02-18T15:12:58+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:12:58 volumio go-librespot[22186]: time="2026-02-18T15:12:58+07:00" level=debug msg="app state loaded" Feb 18 15:12:58 volumio go-librespot[22186]: time="2026-02-18T15:12:58+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:12:58 volumio sudo[22193]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 15:12:58 volumio sudo[22193]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:12:58 volumio volumio[21815]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 15:12:58 volumio sudo[22193]: pam_unix(sudo:session): session closed for user root Feb 18 15:12:58 volumio volumio[21815]: info: Getting Spotify volume Feb 18 15:12:58 volumio volumio[21815]: info: Connection to go-librespot Websocket closed Feb 18 15:12:58 volumio volumio[21815]: error: Cannot start Volumio Streaming Daemon Feb 18 15:12:58 volumio volumio[21815]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 15:12:58 volumio volumio[21815]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 15:12:58 volumio volumio[21815]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 18 15:12:58 volumio volumio[21815]: info: CoreCommandRouter::volumioGetState Feb 18 15:12:58 volumio volumio[21815]: info: CorePlayQueue::getTrack 0 Feb 18 15:12:58 volumio volumio[21815]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 18 15:12:58 volumio volumio[21815]: SPOTIFY: SPOTIFY VOLUME undefined Feb 18 15:12:58 volumio volumio[21815]: SPOTIFY: VOLUMIO VOLUME 100 Feb 18 15:12:58 volumio volumio[21815]: info: Aligning Spotify Volume to Volumio Volume Feb 18 15:12:58 volumio volumio[21815]: info: CoreCommandRouter::volumioGetState Feb 18 15:12:58 volumio volumio[21815]: info: CorePlayQueue::getTrack 0 Feb 18 15:12:58 volumio volumio[21815]: info: Setting Spotify Volume from Volumio: 100 Feb 18 15:12:58 volumio go-librespot[22186]: time="2026-02-18T15:12:58+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:12:58 volumio go-librespot[22186]: time="2026-02-18T15:12:58+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]" Feb 18 15:12:58 volumio go-librespot[22186]: time="2026-02-18T15:12:58+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]" Feb 18 15:12:58 volumio go-librespot[22186]: time="2026-02-18T15:12:58+07:00" level=info msg="zeroconf server listening on port 40003" Feb 18 15:12:58 volumio go-librespot[22186]: time="2026-02-18T15:12:58+07:00" level=debug msg="obtained new client token: AADW4abGeYMBRlvwClUbYtxJT9jFzcTqylMB6KYHGFpB+nnZ4G5DEe9AAiLE/IqXYIKTTIKcRW1lB6D6DVmRKdVJye3fZ3VzvM73VFgZ9IWq12/hXhjW1tRyZcw+DtK02Ctk2cx/+c4vhNoICsQf9QKyjQxYIz64eAqgcAmpuD9Z64ww9Zo6+iH32Vb4nXR2CUaI1PoBRiPMDDwbQP9Eg2LIxjy4zhyIF8t+JcRgWtt34RYGM/boTfdsXg==" Feb 18 15:12:59 volumio go-librespot[22186]: time="2026-02-18T15:12:59+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:12:59 volumio go-librespot[22186]: time="2026-02-18T15:12:59+07:00" level=debug msg="completed keyexchange" Feb 18 15:12:59 volumio go-librespot[22186]: time="2026-02-18T15:12:59+07:00" level=debug msg="completed challenge" Feb 18 15:12:59 volumio go-librespot[22186]: time="2026-02-18T15:12:59+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 " Feb 18 15:12:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:12:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:12:59 volumio volumio[21815]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 15:12:59 volumio volumio[21815]: Error: socket hang up Feb 18 15:12:59 volumio volumio[21815]: at connResetException (node:internal/errors:720:14) Feb 18 15:12:59 volumio volumio[21815]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 18 15:12:59 volumio volumio[21815]: at Socket.emit (node:events:526:35) Feb 18 15:12:59 volumio volumio[21815]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 18 15:12:59 volumio volumio[21815]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 18 15:12:59 volumio volumio[21815]: code: 'ECONNRESET', Feb 18 15:12:59 volumio volumio[21815]: response: undefined Feb 18 15:12:59 volumio volumio[21815]: } Feb 18 15:12:59 volumio volumio[21815]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 15:13:00 volumio sudo[22215]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 15:12' Feb 18 15:13:00 volumio sudo[22215]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:13:00 volumio sudo[22215]: pam_unix(sudo:session): session closed for user root Feb 18 15:13:01 volumio volumio-remote-updater[25144]: [2026-02-18 15:13:01] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 18 15:13:01 volumio volumio-remote-updater[25144]: [2026-02-18 15:13:01] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 18 15:13:01 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:13:01 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 18 15:13:01 volumio systemd[1]: volumio.service: Consumed 55.638s CPU time. Feb 18 15:13:01 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 15:13:01 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 15:13:01 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 22059. Feb 18 15:13:01 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 15:13:01 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 18 15:13:01 volumio systemd[1]: volumio.service: Consumed 55.638s CPU time. Feb 18 15:13:01 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 18 15:13:01 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 15:13:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 18 15:13:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:13:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:13:02 volumio go-librespot[22244]: go-librespot daemon starting... Feb 18 15:13:02 volumio go-librespot[22245]: time="2026-02-18T15:13:02+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:13:02 volumio go-librespot[22245]: time="2026-02-18T15:13:02+07:00" level=debug msg="app state loaded" Feb 18 15:13:02 volumio go-librespot[22245]: time="2026-02-18T15:13:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:13:02 volumio go-librespot[22245]: time="2026-02-18T15:13:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:13:02 volumio go-librespot[22245]: time="2026-02-18T15:13:02+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]" Feb 18 15:13:02 volumio go-librespot[22245]: time="2026-02-18T15:13:02+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]" Feb 18 15:13:02 volumio go-librespot[22245]: time="2026-02-18T15:13:02+07:00" level=info msg="zeroconf server listening on port 39937" Feb 18 15:13:03 volumio go-librespot[22245]: time="2026-02-18T15:13:03+07:00" level=debug msg="obtained new client token: AAA2P8xTMgMVnRyJrqeCEW9px3sGTbrjInEWJG46L4Qv/aZlQtMxA0GZoO9oZDLV+Acwl8ByEjZUS9lLUjMTAvsY7UiLQtQizsOo+W9Bh+3e96V0mdmSFkdvknCdkDqtRQShY5iOtMArM49vGD9xYBxgnGrl1lUBseXArgxmbZcT+BXY9CYwV1+W3grTyfEEjW62TYKsSKxz0goQtaU0py2a/vs9M9tFWgaVr0dm6vW2kjvlkY+ydak=" Feb 18 15:13:03 volumio go-librespot[22245]: time="2026-02-18T15:13:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:13:03 volumio go-librespot[22245]: time="2026-02-18T15:13:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 15:13:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:13:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:13:04 volumio volumio[22229]: info: ------------------------------------------- Feb 18 15:13:04 volumio volumio[22229]: info: ----- Volumio3 ---- Feb 18 15:13:04 volumio volumio[22229]: info: ------------------------------------------- Feb 18 15:13:04 volumio volumio[22229]: info: ----- System startup ---- Feb 18 15:13:04 volumio volumio[22229]: info: ------------------------------------------- Feb 18 15:13:06 volumio volumio-remote-updater[25144]: [2026-02-18 15:13:06] [connect] Successful connection Feb 18 15:13:06 volumio volumio[22229]: info: MYVOLUMIO Environment detected Feb 18 15:13:06 volumio volumio[22229]: info: Plugin folders cleanup Feb 18 15:13:06 volumio volumio[22229]: info: Scanning into folder /volumio/app/plugins/ Feb 18 15:13:06 volumio volumio[22229]: info: Scanning category audio_interface Feb 18 15:13:06 volumio volumio[22229]: info: Scanning category miscellanea Feb 18 15:13:06 volumio volumio[22229]: info: Scanning category music_service Feb 18 15:13:06 volumio volumio[22229]: info: Scanning category plugins.json Feb 18 15:13:06 volumio volumio[22229]: info: Scanning category system_controller Feb 18 15:13:06 volumio volumio[22229]: info: Scanning category user_interface Feb 18 15:13:06 volumio volumio[22229]: info: Scanning into folder /data/plugins/ Feb 18 15:13:06 volumio volumio[22229]: info: Scanning category music_service Feb 18 15:13:06 volumio volumio[22229]: info: Plugin folders cleanup completed Feb 18 15:13:06 volumio volumio[22229]: info: ------------------------------------------- Feb 18 15:13:06 volumio volumio[22229]: info: ----- Core plugins startup ---- Feb 18 15:13:06 volumio volumio[22229]: info: ------------------------------------------- Feb 18 15:13:06 volumio volumio[22229]: info: Loading plugins from folder /volumio/app/plugins/ Feb 18 15:13:06 volumio volumio[22229]: info: Adding plugin upnp to MyMusic Plugins Feb 18 15:13:06 volumio volumio[22229]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 18 15:13:06 volumio volumio[22229]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 18 15:13:06 volumio volumio[22229]: info: Loading plugins from folder /data/plugins/ Feb 18 15:13:06 volumio volumio[22229]: info: Loading plugin "system"... Feb 18 15:13:06 volumio volumio[22229]: info: Loading plugin "appearance"... Feb 18 15:13:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 18 15:13:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:13:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:13:06 volumio go-librespot[22264]: go-librespot daemon starting... Feb 18 15:13:06 volumio go-librespot[22265]: time="2026-02-18T15:13:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:13:06 volumio go-librespot[22265]: time="2026-02-18T15:13:06+07:00" level=debug msg="app state loaded" Feb 18 15:13:06 volumio go-librespot[22265]: time="2026-02-18T15:13:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:13:07 volumio go-librespot[22265]: time="2026-02-18T15:13:07+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:13:07 volumio go-librespot[22265]: time="2026-02-18T15:13:07+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 15:13:07 volumio go-librespot[22265]: time="2026-02-18T15:13:07+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 15:13:07 volumio go-librespot[22265]: time="2026-02-18T15:13:07+07:00" level=info msg="zeroconf server listening on port 35715" Feb 18 15:13:07 volumio go-librespot[22265]: time="2026-02-18T15:13:07+07:00" level=debug msg="obtained new client token: AABhhn5oLGUrmMwaQn+hwY+ZyakZGqBzeA8Q71/UnE9KW1EXWxnJ5aNR2mUIkyZUfm1KMkZ426HTYNKW0UYL0i10u4FTrKM4RS+UH0lzI36OXRvlFMO1eamfG+FmbB1m2YZwzrdP8BSYmog6dG7AA1yUG3QXhHHaf1PixXCyxRiaTEkcsR/tKzpEEc/lhK8ej+hz6RKvAXShNEb27Jpm4yC2p2yXGKNAml56NSXDOEVwGbf5eDOSuq7AUg==" Feb 18 15:13:07 volumio go-librespot[22265]: time="2026-02-18T15:13:07+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 18 15:13:07 volumio go-librespot[22265]: time="2026-02-18T15:13:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 18 15:13:07 volumio go-librespot[22265]: time="2026-02-18T15:13:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 15:13:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:13:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:13:08 volumio volumio[22229]: info: Loading plugin "network"... Feb 18 15:13:08 volumio volumio[22229]: info: Refreshing Cached IP Addresses Feb 18 15:13:08 volumio sudo[22273]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 15:13:08 volumio sudo[22273]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:13:08 volumio sudo[22275]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 15:13:08 volumio sudo[22273]: pam_unix(sudo:session): session closed for user root Feb 18 15:13:08 volumio sudo[22275]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:13:08 volumio volumio[22229]: info: Loading plugin "services"... Feb 18 15:13:08 volumio volumio[22229]: info: Loading plugin "alsa_controller"... Feb 18 15:13:08 volumio sudo[22275]: pam_unix(sudo:session): session closed for user root Feb 18 15:13:08 volumio sudo[22283]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 18 15:13:08 volumio sudo[22283]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:13:08 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 15:13:08 volumio volumio[22229]: info: Loading plugin "wizard"... Feb 18 15:13:08 volumio volumio[22229]: info: Loading plugin "networkfs"... Feb 18 15:13:08 volumio volumio[22229]: info: Starting Udev Watcher for removable devices Feb 18 15:13:08 volumio volumio[22229]: info: Ignoring mount for partition: boot Feb 18 15:13:08 volumio volumio[22229]: info: Ignoring mount for partition: volumio Feb 18 15:13:08 volumio volumio[22229]: info: Ignoring mount for partition: volumio_data Feb 18 15:13:08 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 15:13:08 volumio volumio[22229]: info: Loading plugin "volumio_command_line_client"... Feb 18 15:13:08 volumio volumio[22229]: info: Loading plugin "upnp"... Feb 18 15:13:08 volumio volumio[22229]: info: [1771402388908] Starting Upmpd Daemon Feb 18 15:13:08 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 15:13:08 volumio volumio[22229]: info: Loading plugin "my_music"... Feb 18 15:13:08 volumio volumio[22229]: info: Loading plugin "mpd"... Feb 18 15:13:09 volumio volumio[22229]: info: Loading plugin "upnp_browser"... Feb 18 15:13:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 18 15:13:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:13:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:13:10 volumio go-librespot[22306]: go-librespot daemon starting... Feb 18 15:13:10 volumio go-librespot[22307]: time="2026-02-18T15:13:10+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:13:10 volumio go-librespot[22307]: time="2026-02-18T15:13:10+07:00" level=debug msg="app state loaded" Feb 18 15:13:10 volumio go-librespot[22307]: time="2026-02-18T15:13:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:13:11 volumio sudo[22283]: pam_unix(sudo:session): session closed for user root Feb 18 15:13:11 volumio go-librespot[22307]: time="2026-02-18T15:13:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:13:11 volumio go-librespot[22307]: time="2026-02-18T15:13:11+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]" Feb 18 15:13:11 volumio go-librespot[22307]: time="2026-02-18T15:13:11+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]" Feb 18 15:13:11 volumio go-librespot[22307]: time="2026-02-18T15:13:11+07:00" level=info msg="zeroconf server listening on port 42519" Feb 18 15:13:11 volumio go-librespot[22307]: time="2026-02-18T15:13:11+07:00" level=debug msg="obtained new client token: AAC5+LqKcOkNdFElEtm/o/xC5bCGE4NUXQyzPoLWr3lNH77MassJxeJU5lPNfPX4nm5TLc429J3koHDWgOq8GmUWh1WjwpS/Db1SQjdu8RfZL78yyZux7yBGBNkXXP85xC2EishybI0Ts+RGPb6QkYHvhYkdXYjZw0ZORA7BUtIR0hP76VhysDcwVdscFogSMvH4RX9mxkbT8aTSOPQ95INpzdQQxo2/V1OK6fCMUdzCOKWhn1hbtqXfww==" Feb 18 15:13:11 volumio go-librespot[22307]: time="2026-02-18T15:13:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:13:11 volumio go-librespot[22307]: time="2026-02-18T15:13:11+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 15:13:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:13:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:13:12 volumio volumio[22229]: info: Starting UPNP Browser Feb 18 15:13:12 volumio volumio[22229]: info: Loading plugin "alarm-clock"... Feb 18 15:13:12 volumio volumio[22229]: info: Loading plugin "airplay_emulation"... Feb 18 15:13:12 volumio volumio[22229]: info: Starting Shairport Sync Feb 18 15:13:12 volumio volumio[22229]: info: Loading plugin "last_100"... Feb 18 15:13:12 volumio volumio[22229]: info: Loading plugin "webradio"... Feb 18 15:13:13 volumio volumio[22229]: info: Loading plugin "i2s_dacs"... Feb 18 15:13:13 volumio volumio[22229]: info: Loading plugin "volumiodiscovery"... Feb 18 15:13:13 volumio volumio[22229]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 15:13:13 volumio volumio[22229]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 15:13:13 volumio volumio[22229]: *** WARNING *** For more information see Feb 18 15:13:13 volumio volumio[22229]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 15:13:13 volumio volumio[22229]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 15:13:13 volumio volumio[22229]: *** WARNING *** For more information see Feb 18 15:13:13 volumio node[22229]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 15:13:13 volumio node[22229]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 15:13:13 volumio node[22229]: *** WARNING *** For more information see Feb 18 15:13:13 volumio node[22229]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 15:13:13 volumio node[22229]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 15:13:13 volumio node[22229]: *** WARNING *** For more information see Feb 18 15:13:13 volumio volumio[22229]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 18 15:13:13 volumio volumio[22229]: info: Discovery: Started advertising with name: Volumio Feb 18 15:13:13 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 15:13:13 volumio volumio[22229]: info: Loading plugin "spop"... Feb 18 15:13:14 volumio volumio[22229]: info: Loading plugin "ytcr"... Feb 18 15:13:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 18 15:13:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:13:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:13:15 volumio go-librespot[22319]: go-librespot daemon starting... Feb 18 15:13:15 volumio go-librespot[22320]: time="2026-02-18T15:13:15+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:13:15 volumio go-librespot[22320]: time="2026-02-18T15:13:15+07:00" level=debug msg="app state loaded" Feb 18 15:13:15 volumio go-librespot[22320]: time="2026-02-18T15:13:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:13:15 volumio go-librespot[22320]: time="2026-02-18T15:13:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:13:15 volumio go-librespot[22320]: time="2026-02-18T15:13:15+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]" Feb 18 15:13:15 volumio go-librespot[22320]: time="2026-02-18T15:13:15+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]" Feb 18 15:13:15 volumio go-librespot[22320]: time="2026-02-18T15:13:15+07:00" level=info msg="zeroconf server listening on port 39735" Feb 18 15:13:15 volumio go-librespot[22320]: time="2026-02-18T15:13:15+07:00" level=debug msg="obtained new client token: AAAEmLPV3yGr71AJ0C2CqX/Yq6RMjUvVbA/JstKz4nzgc29MM6eq+wEPcBwRYmSNMBfZx2uRLWb+oplGWcowN6ln6t6oitSkXM9VqnTMuBTKEOMuG1wnXn9Smc53uZycWH7w9srDe7OmOz40c2kyY+xlTMs7GQ15DXTL5Am+R22sWWVdlyw/4d8BZIZZQZwUQ2e/sJobyMY+DU1iWElzGwokCFgrKzNlYYit7tUG6inZ3bZAb4ot3WHsKw==" Feb 18 15:13:15 volumio go-librespot[22320]: time="2026-02-18T15:13:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:13:16 volumio go-librespot[22320]: time="2026-02-18T15:13: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" Feb 18 15:13:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:13:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:13:17 volumio volumio[22229]: info: Loading plugin "ytmusic"... Feb 18 15:13:18 volumio volumio-remote-updater[25144]: [2026-02-18 15:13:18] [connect] Successful connection Feb 18 15:13:18 volumio volumio[22229]: info: Loading plugin "outputs"... Feb 18 15:13:18 volumio volumio[22229]: info: Loading plugin "albumart"... Feb 18 15:13:18 volumio volumio[22229]: info: Plugin example_plugin is not enabled Feb 18 15:13:18 volumio volumio[22229]: info: Loading plugin "inputs"... Feb 18 15:13:18 volumio volumio[22229]: info: Loading plugin "updater_comm"... Feb 18 15:13:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 18 15:13:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:13:19 volumio volumio[22229]: info: Plugin mpdemulation is not enabled Feb 18 15:13:19 volumio volumio[22229]: info: Loading plugin "rest_api"... Feb 18 15:13:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:13:19 volumio go-librespot[22351]: go-librespot daemon starting... Feb 18 15:13:19 volumio volumio[22229]: info: Loading plugin "websocket"... Feb 18 15:13:19 volumio volumio[22229]: info: Starting Socket.io Server version 1.7.4 Feb 18 15:13:19 volumio volumio[22229]: info: Loading plugin "RoonBridge"... Feb 18 15:13:19 volumio go-librespot[22352]: time="2026-02-18T15:13:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:13:19 volumio go-librespot[22352]: time="2026-02-18T15:13:19+07:00" level=debug msg="app state loaded" Feb 18 15:13:19 volumio go-librespot[22352]: time="2026-02-18T15:13:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:13:19 volumio volumio[22229]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 15:13:19 volumio volumio[22229]: info: Loading i18n strings for locale en Feb 18 15:13:19 volumio volumio[22229]: Updating browse sources language Feb 18 15:13:19 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:13:19 volumio go-librespot[22352]: time="2026-02-18T15:13:19+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:13:19 volumio go-librespot[22352]: time="2026-02-18T15:13:19+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 15:13:19 volumio go-librespot[22352]: time="2026-02-18T15:13:19+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 15:13:19 volumio go-librespot[22352]: time="2026-02-18T15:13:19+07:00" level=info msg="zeroconf server listening on port 34169" Feb 18 15:13:19 volumio volumio[22327]: Forking 3 albumart workers Feb 18 15:13:19 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 15:13:19 volumio volumio[22229]: info: CoreCommandRouter::initPlayerControls Feb 18 15:13:19 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:13:19 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:13:19 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:13:19 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:13:19 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:13:19 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:13:19 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:13:19 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:13:20 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 15:13:20 volumio volumio[22229]: Express server listening on port 3000 Feb 18 15:13:20 volumio volumio[22229]: [Metrics] WebUI: 16s 21.70ms Feb 18 15:13:20 volumio volumio[22229]: info: CoreStateMachine::resetVolumioState Feb 18 15:13:20 volumio volumio[22229]: info: CoreStateMachine::getcurrentVolume Feb 18 15:13:20 volumio volumio[22229]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 15:13:20 volumio go-librespot[22352]: time="2026-02-18T15:13:20+07:00" level=debug msg="obtained new client token: AAAwc4r8e9Phwho+CpIj1UwJ7RaMdXuu6ni96vTXi6TTaeg67J4Z3v8shnq0FE3PsWAQpaWFRoEd31fqp/LvCKK50HOOR30EPfZWSGMSH6I0IpN6DYxRCgyaBALFp+wOMs+YObiSFP8qwv3IXeKQ6+L0YIPiA5+2eo4g1gBV0QxcsJwvu3SmyqxR3bUFFQQ2YTTFa527JhgijyCsCS8NBji+vJGBTGPKGl5/VkYMZT8pbU8PbYtwXV0=" Feb 18 15:13:20 volumio go-librespot[22352]: time="2026-02-18T15:13:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:13:20 volumio sudo[22397]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 15:13:20 volumio sudo[22397]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:13:20 volumio sudo[22395]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 15:13:20 volumio sudo[22395]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:13:20 volumio go-librespot[22352]: time="2026-02-18T15:13:20+07:00" level=debug msg="completed keyexchange" Feb 18 15:13:20 volumio go-librespot[22352]: time="2026-02-18T15:13:20+07:00" level=debug msg="completed challenge" Feb 18 15:13:20 volumio sudo[22397]: pam_unix(sudo:session): session closed for user root Feb 18 15:13:20 volumio sudo[22395]: pam_unix(sudo:session): session closed for user root Feb 18 15:13:20 volumio volumio[22229]: info: Volumio Network Manager: Network status updated: 1 Feb 18 15:13:20 volumio go-librespot[22352]: time="2026-02-18T15:13:20+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 15:13:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:13:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:13:20 volumio volumio[22229]: info: VolumeController:: Volume=100 Mute =false Feb 18 15:13:20 volumio volumio[22229]: info: CoreStateMachine::pushState Feb 18 15:13:20 volumio volumio[22229]: info: CorePlayQueue::getTrack 0 Feb 18 15:13:20 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 15:13:20 volumio volumio[22229]: info: CoreCommandRouter::volumioPushState Feb 18 15:13:20 volumio volumio[22229]: info: CoreStateMachine::updateTrackBlock Feb 18 15:13:20 volumio volumio[22229]: info: CorePlayQueue::getTrackBlock Feb 18 15:13:20 volumio volumio[22229]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 15:13:20 volumio volumio-remote-updater[25144]: [2026-02-18 15:13:20] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771402398 101 Feb 18 15:13:20 volumio volumio[22229]: 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 Feb 18 15:13:20 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:13:20 volumio volumio[22229]: info: Reloading queue from file Feb 18 15:13:20 volumio volumio[22229]: info: CoreStateMachine::setRepeat null single undefined Feb 18 15:13:20 volumio volumio[22229]: info: CoreStateMachine::pushState Feb 18 15:13:20 volumio volumio[22229]: info: CorePlayQueue::getTrack 0 Feb 18 15:13:20 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 15:13:20 volumio volumio[22229]: info: CoreCommandRouter::volumioPushState Feb 18 15:13:20 volumio volumio[22229]: info: CoreStateMachine::setRandom null Feb 18 15:13:20 volumio volumio[22229]: info: CoreStateMachine::pushState Feb 18 15:13:20 volumio volumio[22229]: info: CorePlayQueue::getTrack 0 Feb 18 15:13:20 volumio volumio[22229]: info: CoreCommandRouter::volumioPushState Feb 18 15:13:20 volumio volumio[22229]: info: Setting Device type: Raspberry PI Feb 18 15:13:21 volumio volumio[22229]: info: Completed loading Core Plugins Feb 18 15:13:21 volumio volumio[22229]: info: Preparing to generate the ALSA configuration file Feb 18 15:13:21 volumio volumio[22229]: info: VolumeController:: Volume=100 Mute =false Feb 18 15:13:21 volumio volumio[22229]: info: CoreStateMachine::pushState Feb 18 15:13:21 volumio volumio[22229]: info: CorePlayQueue::getTrack 0 Feb 18 15:13:21 volumio volumio[22229]: info: CoreCommandRouter::volumioPushState Feb 18 15:13:21 volumio volumio[22229]: info: Asound.conf file unchanged, so no further update is needed Feb 18 15:13:21 volumio volumio[22229]: info: Output device has changed, restarting MPD Feb 18 15:13:21 volumio volumio[22229]: info: Output device has changed, restarting Shairport Sync Feb 18 15:13:21 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:13:21 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:13:21 volumio sudo[22410]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 15:13:21 volumio sudo[22410]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:13:21 volumio sudo[22414]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 15:13:21 volumio sudo[22414]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:13:21 volumio sudo[22412]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 15:13:21 volumio sudo[22412]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:13:21 volumio volumio[22229]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 15:13:21 volumio sudo[22412]: pam_unix(sudo:session): session closed for user root Feb 18 15:13:21 volumio volumio[22229]: info: ___________ START PLUGINS ___________ Feb 18 15:13:21 volumio sudo[22410]: pam_unix(sudo:session): session closed for user root Feb 18 15:13:21 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 15:13:21 volumio volumio[22229]: info: ControllerMpd::onStart: Initializing MPD Feb 18 15:13:21 volumio volumio[22229]: info: Creating MPD Configuration file Feb 18 15:13:21 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 15:13:21 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 15:13:21 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 15:13:21 volumio volumio[22229]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:13:21 volumio volumio[22229]: info: [1771402401627] CoreMusicLibrary::Adding element Media Servers Feb 18 15:13:21 volumio systemd[1]: mpd.service: Consumed 7.225s CPU time. Feb 18 15:13:21 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 15:13:21 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:13:21 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 15:13:21 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 15:13:21 volumio sudo[22425]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 15:13:21 volumio sudo[22425]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:13:21 volumio sudo[22423]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 15:13:21 volumio sudo[22423]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:13:21 volumio volumio[22229]: info: UPNP Browser: Client initialized successfully Feb 18 15:13:21 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 15:13:21 volumio sudo[22423]: pam_unix(sudo:session): session closed for user root Feb 18 15:13:21 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 15:13:21 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:13:21 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:13:21 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 15:13:21 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 15:13:21 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 15:13:21 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 15:13:21 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 15:13:21 volumio volumio[22229]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 15:13:21 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:13:21 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:13:21 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 15:13:21 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 15:13:21 volumio volumio[22229]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 15:13:21 volumio volumio[22229]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:13:21 volumio volumio[22229]: info: [1771402401988] CoreMusicLibrary::Adding element Last_100 Feb 18 15:13:21 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:13:22 volumio volumio[22229]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:13:22 volumio volumio[22229]: info: [1771402402010] CoreMusicLibrary::Adding element Webradio Feb 18 15:13:22 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:13:22 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 15:13:22 volumio volumio[22229]: info: Initializing BBC Radios Feb 18 15:13:22 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 15:13:22 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:13:22 volumio volumio[22229]: info: Creating Spotify config file Feb 18 15:13:22 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:13:22 volumio sudo[22440]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 15:13:22 volumio sudo[22440]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 15:13:22 volumio sudo[22440]: pam_unix(sudo:session): session closed for user root Feb 18 15:13:22 volumio volumio[22362]: Starting albumart workers Feb 18 15:13:23 volumio volumio[22361]: Starting albumart workers Feb 18 15:13:23 volumio volumio[22360]: Starting albumart workers Feb 18 15:13:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 18 15:13:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:13:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:13:23 volumio go-librespot[22456]: go-librespot daemon starting... Feb 18 15:13:23 volumio volumio[22229]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:13:23 volumio volumio[22229]: info: [1771402403747] CoreMusicLibrary::Adding element YouTube Music Feb 18 15:13:23 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:13:23 volumio volumio[22229]: Cannot find translation for source YouTube Music Feb 18 15:13:23 volumio go-librespot[22457]: time="2026-02-18T15:13:23+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:13:23 volumio volumio[22229]: info: Volumio Calling Home Feb 18 15:13:23 volumio sudo[22464]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 15:13:23 volumio sudo[22464]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:13:24 volumio sudo[22464]: pam_unix(sudo:session): session closed for user root Feb 18 15:13:24 volumio go-librespot[22457]: time="2026-02-18T15:13:24+07:00" level=info msg="zeroconf server listening on port 45799" Feb 18 15:13:24 volumio volumio[22229]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 15:13:24 volumio volumio[22229]: info: Discovery: Found device Volumio Feb 18 15:13:24 volumio volumio[22229]: info: CoreCommandRouter::volumioGetState Feb 18 15:13:24 volumio volumio[22229]: info: CorePlayQueue::getTrack 0 Feb 18 15:13:24 volumio volumio[22229]: info: MPD Permissions set Feb 18 15:13:24 volumio volumio[22229]: info: MPD Permissions set Feb 18 15:13:24 volumio volumio[22229]: info: Upmpdcli Daemon Started Feb 18 15:13:24 volumio volumio[22229]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 15:13:24 volumio volumio[22229]: info: Discovery: Found device Volumio Feb 18 15:13:24 volumio volumio[22229]: info: CoreCommandRouter::volumioGetState Feb 18 15:13:24 volumio volumio[22229]: info: CorePlayQueue::getTrack 0 Feb 18 15:13:24 volumio volumio[22229]: info: Spotify config file written Feb 18 15:13:25 volumio sudo[22478]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 15:13:25 volumio sudo[22478]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:13:25 volumio volumio[22229]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 18 15:13:25 volumio volumio[22229]: info: Volumio called home Feb 18 15:13:25 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:13:25 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:13:25 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:13:25 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:13:25 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:13:25 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:13:25 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:13:25 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:13:25 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:13:25 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:13:25 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:13:25 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:13:25 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:13:25 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:13:25 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:13:25 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:13:25 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:13:25 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:13:25 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 18 15:13:25 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 18 15:13:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:13:25 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:13:25 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:13:25 volumio volumio[22229]: info: No need to fix Spotify hosts Feb 18 15:13:25 volumio go-librespot[22503]: go-librespot daemon starting... Feb 18 15:13:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:13:25 volumio sudo[22478]: pam_unix(sudo:session): session closed for user root Feb 18 15:13:25 volumio go-librespot[22504]: time="2026-02-18T15:13:25+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:13:25 volumio go-librespot[22504]: time="2026-02-18T15:13:25+07:00" level=debug msg="app state loaded" Feb 18 15:13:25 volumio go-librespot[22504]: time="2026-02-18T15:13:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:13:26 volumio go-librespot[22504]: time="2026-02-18T15:13: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:13:26 volumio go-librespot[22504]: time="2026-02-18T15:13:26+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]" Feb 18 15:13:26 volumio go-librespot[22504]: time="2026-02-18T15:13:26+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]" Feb 18 15:13:26 volumio go-librespot[22504]: time="2026-02-18T15:13:26+07:00" level=info msg="zeroconf server listening on port 34539" Feb 18 15:13:26 volumio volumio[22229]: info: Starting Shairport Sync Feb 18 15:13:26 volumio volumio[22229]: info: Starting Shairport Sync Feb 18 15:13:26 volumio volumio[22229]: info: Starting Shairport Sync Feb 18 15:13:26 volumio go-librespot[22504]: time="2026-02-18T15:13:26+07:00" level=debug msg="obtained new client token: AABgTli/wZ2h5MfkvBXidELhGsY1Pyc6iRev/hSAKPqR2HIzX26d0+vC2S/wN8ff3u/kApYs5TBMfsJyMrZH/bI85mpEVCd60eYE8THPAVpivdXUrBmyulMLYNlnHFaAnvV8ansaA7uXIsSOGWD8Sz0BdlQ3Y3o09N9oBcdimVSQwm3Q9R0d0UTfGXDCG7GoaLYp6B7cP96g4EGEOHKUE4I5BiFvyINbfZCw8//jg+jXAsqcl6I0LXy6wA==" Feb 18 15:13:26 volumio sudo[22515]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 15:13:26 volumio sudo[22515]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:13:26 volumio sudo[22513]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 15:13:26 volumio sudo[22513]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:13:26 volumio sudo[22517]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 15:13:26 volumio sudo[22517]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:13:26 volumio go-librespot[22504]: time="2026-02-18T15:13:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:13:26 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 15:13:26 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 15:13:26 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 15:13:26 volumio systemd[1]: shairport-sync.service: Consumed 2.315s CPU time. Feb 18 15:13:26 volumio go-librespot[22504]: time="2026-02-18T15:13:26+07:00" level=debug msg="completed keyexchange" Feb 18 15:13:26 volumio go-librespot[22504]: time="2026-02-18T15:13:26+07:00" level=debug msg="completed challenge" Feb 18 15:13:26 volumio volumio[22229]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 15:13:26 volumio volumio[22229]: SPOTIFY: BQBtNmk73p1t5lCRFB6k960p6o82e7j-kph9lUJtwv3MVPWZkKBKQ8MK9QTZ1JYhLLUmzl67S7qUfe_vPmtci4Y6CM5uvm9oQ_1JTSsuNYjlKMuuHQpJhNUzNsyAwnaUl-Yj1JJA_78YY9NF8Mn_NP9BaGXUJr5BH68j_b2GObRahle3ktrZzyotN6BqkOR47qxxqboozwXARzyzmSKdWeZHceEDg2bdPNIcTsXFPTTmZliWGS1f5c_XULczjKJJBh5BDBwMKCKaOi9hnuaqemwVSkJa8xKBtqox2NqVNx9o8UqJvhnPtPGY Feb 18 15:13:26 volumio volumio[22229]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 15:13:26 volumio volumio[22229]: info: New Spotify access token = BQBtNmk73p1t5lCRFB6k960p6o82e7j-kph9lUJtwv3MVPWZkKBKQ8MK9QTZ1JYhLLUmzl67S7qUfe_vPmtci4Y6CM5uvm9oQ_1JTSsuNYjlKMuuHQpJhNUzNsyAwnaUl-Yj1JJA_78YY9NF8Mn_NP9BaGXUJr5BH68j_b2GObRahle3ktrZzyotN6BqkOR47qxxqboozwXARzyzmSKdWeZHceEDg2bdPNIcTsXFPTTmZliWGS1f5c_XULczjKJJBh5BDBwMKCKaOi9hnuaqemwVSkJa8xKBtqox2NqVNx9o8UqJvhnPtPGY Feb 18 15:13:26 volumio volumio[22229]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 15:13:26 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 15:13:26 volumio go-librespot[22504]: time="2026-02-18T15:13: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 " Feb 18 15:13:26 volumio sudo[22517]: pam_unix(sudo:session): session closed for user root Feb 18 15:13:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:13:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:13:26 volumio sudo[22515]: pam_unix(sudo:session): session closed for user root Feb 18 15:13:26 volumio sudo[22513]: pam_unix(sudo:session): session closed for user root Feb 18 15:13:26 volumio volumio[22229]: info: CoreCommandRouter::volumioGetState Feb 18 15:13:26 volumio volumio[22229]: info: CorePlayQueue::getTrack 0 Feb 18 15:13:26 volumio volumio[22229]: info: Shairport-Sync Started Feb 18 15:13:26 volumio volumio[22229]: Error adding Membership: Error: addMembership EINVAL Feb 18 15:13:26 volumio volumio[22229]: info: Shairport-Sync Started Feb 18 15:13:26 volumio volumio[22229]: info: Shairport-Sync Started Feb 18 15:13:27 volumio volumio[22229]: 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"} Feb 18 15:13:27 volumio volumio[22229]: info: Spotify Successfully logged in Feb 18 15:13:27 volumio volumio[22229]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:13:27 volumio volumio[22229]: info: [1771402407214] CoreMusicLibrary::Adding element Spotify Feb 18 15:13:27 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:13:27 volumio volumio[22229]: Cannot find translation for source YouTube Music Feb 18 15:13:27 volumio volumio[22229]: Cannot find translation for source Spotify Feb 18 15:13:27 volumio volumio[22229]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 15:13:27 volumio volumio[22229]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 15:13:28 volumio volumio[22229]: info: VolumeController:: Volume=100 Mute =false Feb 18 15:13:28 volumio volumio[22229]: info: CoreCommandRouter::volumioGetState Feb 18 15:13:28 volumio volumio[22229]: info: CorePlayQueue::getTrack 0 Feb 18 15:13:28 volumio volumio[22229]: info: CoreStateMachine::pushState Feb 18 15:13:28 volumio volumio[22229]: info: CorePlayQueue::getTrack 0 Feb 18 15:13:28 volumio volumio[22229]: info: CoreCommandRouter::volumioPushState Feb 18 15:13:29 volumio volumio[22229]: info: go-librespot daemon successfully initialized Feb 18 15:13:29 volumio mpd[22455]: 2026-02-18T15:13:29 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 15:13:29 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 15:13:29 volumio sudo[22425]: pam_unix(sudo:session): session closed for user root Feb 18 15:13:29 volumio sudo[22414]: pam_unix(sudo:session): session closed for user root Feb 18 15:13:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 18 15:13:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:13:29 volumio volumio[22229]: error: MPD error: The expression evaluated to a falsy value: Feb 18 15:13:29 volumio volumio[22229]: assert.ok(self.idling) Feb 18 15:13:29 volumio volumio[22229]: error: The expression evaluated to a falsy value: Feb 18 15:13:29 volumio volumio[22229]: assert.ok(self.idling) Feb 18 15:13:29 volumio volumio[22229]: error: updateQueue error: null Feb 18 15:13:29 volumio volumio[22229]: info: MPD running with PID22455 Feb 18 15:13:29 volumio volumio[22229]: ,establishing connection Feb 18 15:13:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:13:29 volumio go-librespot[22558]: go-librespot daemon starting... Feb 18 15:13:29 volumio volumio[22229]: info: Completed starting Core Plugins Feb 18 15:13:29 volumio volumio[22229]: info: ------------------------------------------- Feb 18 15:13:29 volumio volumio[22229]: info: ----- MyVolumio plugins startup ---- Feb 18 15:13:29 volumio volumio[22229]: info: ------------------------------------------- Feb 18 15:13:29 volumio volumio[22229]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 15:13:29 volumio go-librespot[22559]: time="2026-02-18T15:13:29+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:13:29 volumio go-librespot[22559]: time="2026-02-18T15:13:29+07:00" level=debug msg="app state loaded" Feb 18 15:13:29 volumio volumio[22229]: error: updateQueue error: null Feb 18 15:13:29 volumio go-librespot[22559]: time="2026-02-18T15:13:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:13:30 volumio go-librespot[22559]: time="2026-02-18T15:13:30+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 15:13:30 volumio go-librespot[22559]: time="2026-02-18T15:13:30+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]" Feb 18 15:13:30 volumio go-librespot[22559]: time="2026-02-18T15:13:30+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]" Feb 18 15:13:30 volumio go-librespot[22559]: time="2026-02-18T15:13:30+07:00" level=info msg="zeroconf server listening on port 46315" Feb 18 15:13:30 volumio go-librespot[22559]: time="2026-02-18T15:13:30+07:00" level=debug msg="obtained new client token: AAA8dO7125yFXFpitmLLLBHMIRg9lBFLwSQjLJHnlcDVS6WNR75JRtUcjnG9cCleYWqLTDmhcNMDE4G848UHrD/GUjihx5Xu9wLrzHn7N6GpzmfKudTfbWraM4v4aToYwx9n9UatVUdOJmK+mxQKopDNeinW9oIBCrczIe34hHoC2Dy+c+oHx/PlVkyiT1t6qON7iPwkmtcnsy3aDwJk9r69OHbMqIWNtjeUWCNdRj6QmcIFUQRa2hRMQg==" Feb 18 15:13:30 volumio go-librespot[22559]: time="2026-02-18T15:13:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:13:30 volumio go-librespot[22559]: time="2026-02-18T15:13:30+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" Feb 18 15:13:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:13:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:13:32 volumio volumio[22229]: info: Initializing connection to go-librespot Websocket Feb 18 15:13:32 volumio volumio[22229]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 15:13:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 18 15:13:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:13:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:13:34 volumio go-librespot[22567]: go-librespot daemon starting... Feb 18 15:13:34 volumio go-librespot[22568]: time="2026-02-18T15:13:34+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:13:34 volumio go-librespot[22568]: time="2026-02-18T15:13:34+07:00" level=debug msg="app state loaded" Feb 18 15:13:34 volumio go-librespot[22568]: time="2026-02-18T15:13:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:13:34 volumio go-librespot[22568]: time="2026-02-18T15:13:34+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]" Feb 18 15:13:34 volumio go-librespot[22568]: time="2026-02-18T15:13:34+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]" Feb 18 15:13:34 volumio go-librespot[22568]: time="2026-02-18T15:13:34+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]" Feb 18 15:13:34 volumio volumio[22229]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 15:13:34 volumio go-librespot[22568]: time="2026-02-18T15:13:34+07:00" level=info msg="zeroconf server listening on port 37223" Feb 18 15:13:34 volumio go-librespot[22568]: time="2026-02-18T15:13:34+07:00" level=debug msg="obtained new client token: AADAdY85C9Xe28fiy8YaY5/UsfLE8sCC4ooP2cVxVABbiyidHhUSjBgq/q85mp9rU+hHmOX9jfewlfvBMd43UnsqbgoW4kUt9JQZZWGsiKY0BU+UAUXKfbr3OBt8qjeZ9LQC9Pl+ShnS3in9K3jUaQw/MHUVfTCu9J5PA9amnlMATL/56zfOKzjb8h4dP0QbhDY44Jj46wsyI6mcKkRTdxQ9QpYKJTWeKwguoanZAbFRhvTyhcltP2RZkw==" Feb 18 15:13:35 volumio go-librespot[22568]: time="2026-02-18T15:13:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:13:35 volumio go-librespot[22568]: time="2026-02-18T15:13:35+07:00" level=debug msg="completed keyexchange" Feb 18 15:13:35 volumio go-librespot[22568]: time="2026-02-18T15:13:35+07:00" level=debug msg="completed challenge" Feb 18 15:13:35 volumio go-librespot[22568]: time="2026-02-18T15:13:35+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 " Feb 18 15:13:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:13:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:13:35 volumio volumio[22229]: info: Initializing connection to go-librespot Websocket Feb 18 15:13:35 volumio volumio[22229]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 15:13:38 volumio volumio[22229]: info: Initializing connection to go-librespot Websocket Feb 18 15:13:38 volumio volumio[22229]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 15:13:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 18 15:13:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:13:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:13:38 volumio go-librespot[22575]: go-librespot daemon starting... Feb 18 15:13:38 volumio go-librespot[22576]: time="2026-02-18T15:13:38+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:13:38 volumio go-librespot[22576]: time="2026-02-18T15:13:38+07:00" level=debug msg="app state loaded" Feb 18 15:13:38 volumio go-librespot[22576]: time="2026-02-18T15:13:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:13:38 volumio volumio[22229]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 15:13:38 volumio volumio[22229]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 15:13:38 volumio volumio[22229]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 15:13:38 volumio volumio[22229]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 15:13:38 volumio volumio[22229]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 15:13:38 volumio volumio[22229]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 15:13:38 volumio volumio[22229]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 15:13:38 volumio volumio[22229]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 15:13:38 volumio volumio[22229]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 15:13:38 volumio volumio[22229]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 15:13:38 volumio volumio[22229]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 15:13:38 volumio volumio[22229]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 15:13:38 volumio volumio[22229]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 15:13:38 volumio volumio[22229]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 15:13:38 volumio volumio[22229]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 15:13:38 volumio volumio[22229]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 15:13:38 volumio volumio[22229]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 15:13:38 volumio volumio[22229]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 15:13:38 volumio volumio[22229]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 15:13:38 volumio volumio[22229]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 15:13:38 volumio volumio[22229]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 15:13:38 volumio volumio[22229]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 15:13:38 volumio volumio[22229]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 15:13:38 volumio volumio[22229]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 15:13:38 volumio volumio[22229]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 15:13:38 volumio volumio[22229]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 15:13:38 volumio volumio[22229]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 15:13:38 volumio volumio[22229]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 15:13:38 volumio volumio[22229]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 15:13:38 volumio volumio[22229]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 15:13:38 volumio volumio[22229]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 15:13:38 volumio volumio[22229]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 15:13:38 volumio volumio[22229]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 15:13:38 volumio volumio[22229]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 15:13:38 volumio volumio[22229]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 15:13:38 volumio volumio[22229]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 15:13:38 volumio go-librespot[22576]: time="2026-02-18T15:13:38+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:13:38 volumio go-librespot[22576]: time="2026-02-18T15:13:38+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]" Feb 18 15:13:38 volumio go-librespot[22576]: time="2026-02-18T15:13:38+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]" Feb 18 15:13:38 volumio go-librespot[22576]: time="2026-02-18T15:13:38+07:00" level=info msg="zeroconf server listening on port 41013" Feb 18 15:13:39 volumio go-librespot[22576]: time="2026-02-18T15:13:39+07:00" level=debug msg="obtained new client token: AABYK/W225uUZGCgXZBWXOdQDd+ipuCDv5Vset9aqXZloSrf0TIupoY02qSvFs4C/JIEj1MN96Ge6gyyujFHygFHgZAQhiOr6Oo9h5Jf8zyR+6FXj8iciK6tozMcO5ltEoQH+LzSz22J3z2iYVIDoI3zEq1jzDCb+Wxv1mMcs+zHUGge3GhlRqAJ6gxQkq9WVI/gZMywMh5cPCxHn8trmdNHONhrVriiXqAW7Oc+4UPrbHF6ogMgRV8=" Feb 18 15:13:39 volumio go-librespot[22576]: time="2026-02-18T15:13:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:13:39 volumio go-librespot[22576]: time="2026-02-18T15:13:39+07:00" level=debug msg="completed keyexchange" Feb 18 15:13:39 volumio go-librespot[22576]: time="2026-02-18T15:13:39+07:00" level=debug msg="completed challenge" Feb 18 15:13:39 volumio go-librespot[22576]: time="2026-02-18T15:13:39+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 " Feb 18 15:13:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:13:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:13:40 volumio volumio[22229]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 15:13:40 volumio volumio[22229]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 15:13:40 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:13:40 volumio volumio[22229]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:13:40 volumio volumio[22229]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 15:13:40 volumio volumio[22229]: info: MyVolumio login type: Token Feb 18 15:13:40 volumio volumio[22229]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 15:13:40 volumio volumio[22229]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 15:13:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 18 15:13:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:13:42 volumio volumio[22229]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 15:13:42 volumio volumio[22229]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 15:13:42 volumio volumio[22229]: info: Streaming services startup Feb 18 15:13:42 volumio volumio[22229]: info: Starting Streaming Daemon Feb 18 15:13:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:13:42 volumio go-librespot[22598]: go-librespot daemon starting... Feb 18 15:13:42 volumio sudo[22601]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 15:13:42 volumio sudo[22601]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:13:42 volumio volumio[22229]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 15:13:42 volumio go-librespot[22603]: time="2026-02-18T15:13:42+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:13:42 volumio go-librespot[22603]: time="2026-02-18T15:13:42+07:00" level=debug msg="app state loaded" Feb 18 15:13:42 volumio go-librespot[22603]: time="2026-02-18T15:13:42+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:13:42 volumio sudo[22601]: pam_unix(sudo:session): session closed for user root Feb 18 15:13:42 volumio volumio[22229]: info: Initializing connection to go-librespot Websocket Feb 18 15:13:42 volumio volumio[22229]: error: Cannot start Volumio Streaming Daemon Feb 18 15:13:42 volumio volumio[22229]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 15:13:42 volumio volumio[22229]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 15:13:42 volumio go-librespot[22603]: time="2026-02-18T15:13:42+07:00" level=debug msg="new websocket client" Feb 18 15:13:42 volumio volumio[22229]: info: Connection to go-librespot Websocket established Feb 18 15:13:43 volumio go-librespot[22603]: time="2026-02-18T15:13:43+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 15:13:43 volumio go-librespot[22603]: time="2026-02-18T15:13:43+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]" Feb 18 15:13:43 volumio go-librespot[22603]: time="2026-02-18T15:13:43+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]" Feb 18 15:13:43 volumio go-librespot[22603]: time="2026-02-18T15:13:43+07:00" level=info msg="zeroconf server listening on port 33313" Feb 18 15:13:43 volumio go-librespot[22603]: time="2026-02-18T15:13:43+07:00" level=debug msg="obtained new client token: AACoNdZ6GtIOBaJt5beF9pdgKS1WXI7cvyM1/cr4WyeHg+9z07YAy6JXKUYCbP+lSGVC0d9v3uvMqtnRzv2ozD0tCFWcfufWQ395DTFHUdEV0dCip3eeE/I6Gp0dKrA7In3OqXZFudB2TVD8dOP6bBz0/YlqF9Akbnl8/JnrgWKPg8oUB1NG7Qotgus9E2FenoxlK+R8+53LgI42itBTTgblofwzAwvH+Mi5gkx34WedQHnBtnzpDG32mA==" Feb 18 15:13:43 volumio go-librespot[22603]: time="2026-02-18T15:13:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:13:43 volumio go-librespot[22603]: time="2026-02-18T15:13:43+07:00" level=debug msg="completed keyexchange" Feb 18 15:13:43 volumio go-librespot[22603]: time="2026-02-18T15:13:43+07:00" level=debug msg="completed challenge" Feb 18 15:13:43 volumio go-librespot[22603]: time="2026-02-18T15:13:43+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 15:13:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:13:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:13:43 volumio volumio[22229]: info: Connection to go-librespot Websocket closed Feb 18 15:13:43 volumio volumio[22229]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 18 15:13:44 volumio volumio[22229]: info: MyVolumio token set successfully Feb 18 15:13:44 volumio volumio[22229]: info: MYVOLUMIO: Adding device Feb 18 15:13:44 volumio volumio[22229]: info: MYVOLUMIO: Evaluating Server Feb 18 15:13:45 volumio volumio[22229]: info: MyVolumio status changed Feb 18 15:13:45 volumio volumio[22229]: info: Streaming services startup Feb 18 15:13:45 volumio volumio[22229]: info: Starting Streaming Daemon Feb 18 15:13:45 volumio volumio[22229]: info: Removing browser output: myVolumio user plan is not superstar Feb 18 15:13:45 volumio volumio[22229]: info: Removing audio output: Feb 18 15:13:45 volumio volumio[22229]: info: Stoppping Tunnel 1 Feb 18 15:13:45 volumio sudo[22637]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 15:13:45 volumio sudo[22637]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:13:45 volumio sudo[22637]: pam_unix(sudo:session): session closed for user root Feb 18 15:13:45 volumio sudo[22640]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 18 15:13:45 volumio sudo[22640]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:13:45 volumio volumio[22229]: error: Cannot start Volumio Streaming Daemon Feb 18 15:13:45 volumio volumio[22229]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 15:13:45 volumio volumio[22229]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 15:13:45 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. Feb 18 15:13:45 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. Feb 18 15:13:45 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. Feb 18 15:13:45 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. Feb 18 15:13:45 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. Feb 18 15:13:45 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. Feb 18 15:13:45 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. Feb 18 15:13:45 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. Feb 18 15:13:45 volumio sudo[22640]: pam_unix(sudo:session): session closed for user root Feb 18 15:13:45 volumio volumio[22229]: info: Remote SSH Stopped Feb 18 15:13:45 volumio volumio[22229]: info: Getting Spotify volume Feb 18 15:13:45 volumio volumio[22229]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 15:13:45 volumio volumio[22229]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 15:13:45 volumio volumio[22229]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 18 15:13:45 volumio volumio[22229]: errno: -111, Feb 18 15:13:45 volumio volumio[22229]: code: 'ECONNREFUSED', Feb 18 15:13:45 volumio volumio[22229]: syscall: 'connect', Feb 18 15:13:45 volumio volumio[22229]: address: '127.0.0.1', Feb 18 15:13:45 volumio volumio[22229]: port: 9879, Feb 18 15:13:45 volumio volumio[22229]: response: undefined Feb 18 15:13:45 volumio volumio[22229]: } Feb 18 15:13:45 volumio volumio[22229]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 15:13:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 18 15:13:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:13:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:13:46 volumio go-librespot[22654]: go-librespot daemon starting... Feb 18 15:13:46 volumio go-librespot[22655]: time="2026-02-18T15:13:46+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:13:46 volumio go-librespot[22655]: time="2026-02-18T15:13:46+07:00" level=debug msg="app state loaded" Feb 18 15:13:46 volumio go-librespot[22655]: time="2026-02-18T15:13:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:13:47 volumio sudo[22664]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 15:12' Feb 18 15:13:47 volumio sudo[22664]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:13:47 volumio go-librespot[22655]: time="2026-02-18T15:13:47+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:13:47 volumio go-librespot[22655]: time="2026-02-18T15:13:47+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]" Feb 18 15:13:47 volumio go-librespot[22655]: time="2026-02-18T15:13:47+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]" Feb 18 15:13:47 volumio go-librespot[22655]: time="2026-02-18T15:13:47+07:00" level=info msg="zeroconf server listening on port 39481" Feb 18 15:13:47 volumio go-librespot[22655]: time="2026-02-18T15:13:47+07:00" level=debug msg="obtained new client token: AADJHuLeSF2WdRjC9Dq8bk0sZ4adMz595YfJGeXpP+0SSQORtfPgsSz9yGz+ddk2wpdxMg958NTsEnC0ZXzDrWm+EBaY8BO7RTYtNYkLag8O5XrEyJw3lfECmuzxPgFVmxvnsozYkvMYFyniEbEzg0Y3YWF6ZNq7oeJb49azb+6wUO64K8Rb1oHSzv+V7swnTjXGn8LOrSYSt67CUO1GbkXEdDj7b6hWuLUB2Kk52pyAubGg9QZsyuGWiA==" 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"