Feb 18 21:22:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 18 21:22:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:01 volumio go-librespot[8054]: go-librespot daemon starting... Feb 18 21:22:01 volumio go-librespot[8055]: time="2026-02-18T21:22:01+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:22:01 volumio go-librespot[8055]: time="2026-02-18T21:22:01+07:00" level=debug msg="app state loaded" Feb 18 21:22:01 volumio go-librespot[8055]: time="2026-02-18T21:22:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:22:01 volumio go-librespot[8055]: time="2026-02-18T21:22: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 21:22:01 volumio go-librespot[8055]: time="2026-02-18T21:22:01+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 21:22:01 volumio go-librespot[8055]: time="2026-02-18T21:22:01+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 21:22:01 volumio go-librespot[8055]: time="2026-02-18T21:22:01+07:00" level=info msg="zeroconf server listening on port 44669" Feb 18 21:22:02 volumio volumio[7719]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 21:22:02 volumio go-librespot[8055]: time="2026-02-18T21:22:02+07:00" level=debug msg="obtained new client token: AABlPd+nnWVHGNUvg41mK9dx+oFHtXurJWZLTQenSEE5Z7DHm6EsNjQoZ+2UgWgMYOfJdt3uas1YYkpO1daAaXOQ9AJhc8uBFniT/7dthFmqRa/avAdPBEUFLZYvHA4ADhHjj+q66alAMtrIxYsR8OJBjKr4Ed5WCPo/QBvw6Tkhv2hfvrIaqIt0+tbr9c349TCqW9yo0BpKS99lX3mFHhAaw1WRnkvnAakQYmoham1Dx6v2DEl+ABM=" Feb 18 21:22:02 volumio go-librespot[8055]: time="2026-02-18T21:22:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:22:02 volumio go-librespot[8055]: time="2026-02-18T21:22:02+07:00" level=debug msg="completed keyexchange" Feb 18 21:22:02 volumio go-librespot[8055]: time="2026-02-18T21:22:02+07:00" level=debug msg="completed challenge" Feb 18 21:22:02 volumio go-librespot[8055]: time="2026-02-18T21:22:02+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 21:22:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:22:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:22:02 volumio volumio[7719]: info: Initializing connection to go-librespot Websocket Feb 18 21:22:02 volumio volumio[7719]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 21:22:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 18 21:22:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:05 volumio go-librespot[8062]: go-librespot daemon starting... Feb 18 21:22:05 volumio go-librespot[8063]: time="2026-02-18T21:22:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:22:05 volumio go-librespot[8063]: time="2026-02-18T21:22:05+07:00" level=debug msg="app state loaded" Feb 18 21:22:05 volumio go-librespot[8063]: time="2026-02-18T21:22:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:22:05 volumio volumio[7719]: info: Initializing connection to go-librespot Websocket Feb 18 21:22:05 volumio go-librespot[8063]: time="2026-02-18T21:22:05+07:00" level=debug msg="new websocket client" Feb 18 21:22:05 volumio volumio[7719]: info: Connection to go-librespot Websocket established Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 21:22:05 volumio volumio[7719]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 21:22:05 volumio volumio[7719]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 21:22:05 volumio volumio[7719]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 21:22:05 volumio volumio[7719]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 21:22:05 volumio volumio[7719]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 21:22:05 volumio volumio[7719]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 21:22:05 volumio volumio[7719]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 21:22:06 volumio go-librespot[8063]: time="2026-02-18T21:22:06+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 21:22:06 volumio go-librespot[8063]: time="2026-02-18T21:22:06+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 21:22:06 volumio go-librespot[8063]: time="2026-02-18T21:22:06+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 21:22:06 volumio go-librespot[8063]: time="2026-02-18T21:22:06+07:00" level=info msg="zeroconf server listening on port 46285" Feb 18 21:22:06 volumio go-librespot[8063]: time="2026-02-18T21:22:06+07:00" level=debug msg="obtained new client token: AADNIRkGB0HY4TY/RU/21+PIxpL47vaOcMcYurYEctdY4IcCFqMFv5+aq+MLG+Qlh2FEMb3z/8QM6Gmv+PoZqN277pmNKTupeLyO+STg5bnnGemLrv9QdooOaTCCdhEmumecvLcOQRJvFtv25yWH++xM1LbE2rEpvAwuZTNdh1LqmmaYtrpU+PmQ4Zb78RFnklaaJ4idCUG+8aok687Y74zXxjCTtvnRDGVp9DEkbeOkyVkF3tBtVCDWOA==" Feb 18 21:22:06 volumio go-librespot[8063]: time="2026-02-18T21:22:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:22:06 volumio go-librespot[8063]: time="2026-02-18T21:22:06+07:00" level=debug msg="completed keyexchange" Feb 18 21:22:06 volumio go-librespot[8063]: time="2026-02-18T21:22:06+07:00" level=debug msg="completed challenge" Feb 18 21:22:06 volumio go-librespot[8063]: time="2026-02-18T21:22: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 21:22:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:22:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:22:07 volumio volumio[7719]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 21:22:07 volumio volumio[7719]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 21:22:07 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:22:07 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:22:07 volumio volumio[7719]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 21:22:07 volumio volumio[7719]: info: MyVolumio login type: Token Feb 18 21:22:07 volumio volumio[7719]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 21:22:07 volumio volumio[7719]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 21:22:09 volumio volumio[7719]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 21:22:09 volumio volumio[7719]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 21:22:09 volumio volumio[7719]: info: Streaming services startup Feb 18 21:22:09 volumio volumio[7719]: info: Starting Streaming Daemon Feb 18 21:22:09 volumio sudo[8086]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 21:22:09 volumio sudo[8086]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:09 volumio volumio[7719]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 21:22:09 volumio sudo[8086]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:09 volumio volumio[7719]: info: Getting Spotify volume Feb 18 21:22:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 18 21:22:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:09 volumio volumio[7719]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 21:22:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:09 volumio go-librespot[8092]: go-librespot daemon starting... Feb 18 21:22:09 volumio volumio[7719]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 21:22:09 volumio volumio[7719]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 18 21:22:09 volumio volumio[7719]: errno: -111, Feb 18 21:22:09 volumio volumio[7719]: code: 'ECONNREFUSED', Feb 18 21:22:09 volumio volumio[7719]: syscall: 'connect', Feb 18 21:22:09 volumio volumio[7719]: address: '127.0.0.1', Feb 18 21:22:09 volumio volumio[7719]: port: 9879, Feb 18 21:22:09 volumio volumio[7719]: response: undefined Feb 18 21:22:09 volumio volumio[7719]: } Feb 18 21:22:09 volumio volumio[7719]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 21:22:09 volumio go-librespot[8093]: time="2026-02-18T21:22:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:22:09 volumio go-librespot[8093]: time="2026-02-18T21:22:09+07:00" level=debug msg="app state loaded" Feb 18 21:22:09 volumio go-librespot[8093]: time="2026-02-18T21:22:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:22:10 volumio go-librespot[8093]: time="2026-02-18T21:22:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 21:22:10 volumio go-librespot[8093]: time="2026-02-18T21:22:10+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 21:22:10 volumio go-librespot[8093]: time="2026-02-18T21:22:10+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 21:22:10 volumio go-librespot[8093]: time="2026-02-18T21:22:10+07:00" level=info msg="zeroconf server listening on port 42305" Feb 18 21:22:10 volumio go-librespot[8093]: time="2026-02-18T21:22:10+07:00" level=debug msg="obtained new client token: AADM3PPkD9jc0+/fibQy54OaIMl0lk3Z2dP/ouZ/4Ey8+AmR2gctlu0xHvc0DMymLvIrwryXbRBkvIq3+y6ZjJ27ykAnODd0Mfx+/PKIbsrDkxmnWwhHlp0VPjPOs0/73Sns27sTq9/9u9MzXJbECCP+ctNvYUmBWNOWH5gGJ1I0qUiikt5tTkOFWbxQpEsIZldZidrD5GS9slkvmpn4p19myHbVRXIGvj2IXn0lJ6V9ehMSnt+mg7V0Hw==" Feb 18 21:22:10 volumio go-librespot[8093]: time="2026-02-18T21:22:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:22:10 volumio go-librespot[8093]: time="2026-02-18T21:22:10+07:00" level=debug msg="completed keyexchange" Feb 18 21:22:10 volumio go-librespot[8093]: time="2026-02-18T21:22:10+07:00" level=debug msg="completed challenge" Feb 18 21:22:10 volumio go-librespot[8093]: time="2026-02-18T21:22: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 21:22:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:22:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:22:11 volumio sudo[8115]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 21:21' Feb 18 21:22:11 volumio sudo[8115]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:11 volumio sudo[8115]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:13 volumio volumio-remote-updater[25144]: [2026-02-18 21:22:13] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 18 21:22:13 volumio volumio-remote-updater[25144]: [2026-02-18 21:22:13] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 18 21:22:13 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:22:13 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 18 21:22:13 volumio systemd[1]: volumio.service: Consumed 55.386s CPU time. Feb 18 21:22:13 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 21:22:13 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 21:22:13 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 22460. Feb 18 21:22:13 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 21:22:13 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 18 21:22:13 volumio systemd[1]: volumio.service: Consumed 55.386s CPU time. Feb 18 21:22:13 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 18 21:22:13 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 21:22:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 18 21:22:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:14 volumio go-librespot[8146]: go-librespot daemon starting... Feb 18 21:22:14 volumio go-librespot[8147]: time="2026-02-18T21:22:14+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:22:14 volumio go-librespot[8147]: time="2026-02-18T21:22:14+07:00" level=debug msg="app state loaded" Feb 18 21:22:14 volumio go-librespot[8147]: time="2026-02-18T21:22:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:22:14 volumio go-librespot[8147]: time="2026-02-18T21:22: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 21:22:14 volumio go-librespot[8147]: time="2026-02-18T21:22: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 21:22:14 volumio go-librespot[8147]: time="2026-02-18T21:22: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 21:22:14 volumio go-librespot[8147]: time="2026-02-18T21:22:14+07:00" level=info msg="zeroconf server listening on port 45871" Feb 18 21:22:14 volumio go-librespot[8147]: time="2026-02-18T21:22:14+07:00" level=debug msg="obtained new client token: AADFC7QWWNCV2SY/BeZ7SCrAhE6nQDkdV0XwJpQrfC0L0kirMHMU0M4BehMMF5ElK9jUiQSU+4drHOvZp7nUB7SddHGL1Pg/wui8r5F3bMM8Nj5C/qEo+9nS3YISUDVpRPYNyIDE6BUC8PxNWKokN531sy19KPZZ8GXKJQ+1cMf6N9IReECqIxfw/PzysO/X8kK6j6QsQsKH/OvELVVjm1PGn4wfD/UCFQHNmV8bF5kM/GhYSq70Fyp9Cg==" Feb 18 21:22:15 volumio go-librespot[8147]: time="2026-02-18T21:22:15+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 21:22:15 volumio go-librespot[8147]: time="2026-02-18T21:22:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 18 21:22:15 volumio go-librespot[8147]: time="2026-02-18T21:22:15+07:00" level=debug msg="completed keyexchange" Feb 18 21:22:15 volumio go-librespot[8147]: time="2026-02-18T21:22:15+07:00" level=debug msg="completed challenge" Feb 18 21:22:15 volumio go-librespot[8147]: time="2026-02-18T21:22:15+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 21:22:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:22:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:22:16 volumio volumio[8130]: info: ------------------------------------------- Feb 18 21:22:16 volumio volumio[8130]: info: ----- Volumio3 ---- Feb 18 21:22:16 volumio volumio[8130]: info: ------------------------------------------- Feb 18 21:22:16 volumio volumio[8130]: info: ----- System startup ---- Feb 18 21:22:16 volumio volumio[8130]: info: ------------------------------------------- Feb 18 21:22:18 volumio volumio-remote-updater[25144]: [2026-02-18 21:22:18] [connect] Successful connection Feb 18 21:22:18 volumio volumio[8130]: info: MYVOLUMIO Environment detected Feb 18 21:22:18 volumio volumio[8130]: info: Plugin folders cleanup Feb 18 21:22:18 volumio volumio[8130]: info: Scanning into folder /volumio/app/plugins/ Feb 18 21:22:18 volumio volumio[8130]: info: Scanning category audio_interface Feb 18 21:22:18 volumio volumio[8130]: info: Scanning category miscellanea Feb 18 21:22:18 volumio volumio[8130]: info: Scanning category music_service Feb 18 21:22:18 volumio volumio[8130]: info: Scanning category plugins.json Feb 18 21:22:18 volumio volumio[8130]: info: Scanning category system_controller Feb 18 21:22:18 volumio volumio[8130]: info: Scanning category user_interface Feb 18 21:22:18 volumio volumio[8130]: info: Scanning into folder /data/plugins/ Feb 18 21:22:18 volumio volumio[8130]: info: Scanning category music_service Feb 18 21:22:18 volumio volumio[8130]: info: Plugin folders cleanup completed Feb 18 21:22:18 volumio volumio[8130]: info: ------------------------------------------- Feb 18 21:22:18 volumio volumio[8130]: info: ----- Core plugins startup ---- Feb 18 21:22:18 volumio volumio[8130]: info: ------------------------------------------- Feb 18 21:22:18 volumio volumio[8130]: info: Loading plugins from folder /volumio/app/plugins/ Feb 18 21:22:18 volumio volumio[8130]: info: Adding plugin upnp to MyMusic Plugins Feb 18 21:22:18 volumio volumio[8130]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 18 21:22:18 volumio volumio[8130]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 18 21:22:18 volumio volumio[8130]: info: Loading plugins from folder /data/plugins/ Feb 18 21:22:18 volumio volumio[8130]: info: Loading plugin "system"... Feb 18 21:22:18 volumio volumio[8130]: info: Loading plugin "appearance"... Feb 18 21:22:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 18 21:22:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:18 volumio go-librespot[8167]: go-librespot daemon starting... Feb 18 21:22:18 volumio go-librespot[8168]: time="2026-02-18T21:22:18+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:22:18 volumio go-librespot[8168]: time="2026-02-18T21:22:18+07:00" level=debug msg="app state loaded" Feb 18 21:22:18 volumio go-librespot[8168]: time="2026-02-18T21:22:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:22:19 volumio go-librespot[8168]: time="2026-02-18T21:22: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 21:22:19 volumio go-librespot[8168]: time="2026-02-18T21:22:19+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 21:22:19 volumio go-librespot[8168]: time="2026-02-18T21:22:19+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 21:22:19 volumio go-librespot[8168]: time="2026-02-18T21:22:19+07:00" level=info msg="zeroconf server listening on port 32785" Feb 18 21:22:19 volumio go-librespot[8168]: time="2026-02-18T21:22:19+07:00" level=debug msg="obtained new client token: AACOcR6Fdp498rYSUIFT64opbIKZLbILMndHJ6UhxsI1IF0xnytsCT7HcEjvw/WFcH6s1sa9T7YP/vk3dARLvWIy3YEML7bteW4CGi69pnDntXIsGjgGNz1yICiCCp9D5i+3D6wni/sSlsTc9wEPrOzR8xdrUjwFoqWLvfZlibwo++CcTOMqqaOkcMPRGJSXLzMbkPdd5ZsRQEsGgkTiZSj9txvHDhPUFoKUx7Md/NRaFB8tVYUqf3LuXA==" Feb 18 21:22:19 volumio go-librespot[8168]: time="2026-02-18T21:22:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:22:19 volumio go-librespot[8168]: time="2026-02-18T21:22:19+07:00" level=debug msg="completed keyexchange" Feb 18 21:22:19 volumio go-librespot[8168]: time="2026-02-18T21:22:19+07:00" level=debug msg="completed challenge" Feb 18 21:22:19 volumio go-librespot[8168]: time="2026-02-18T21:22: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 21:22:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:22:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:22:20 volumio volumio[8130]: info: Loading plugin "network"... Feb 18 21:22:20 volumio volumio[8130]: info: Refreshing Cached IP Addresses Feb 18 21:22:20 volumio sudo[8176]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 21:22:20 volumio sudo[8176]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:20 volumio volumio[8130]: info: Loading plugin "services"... Feb 18 21:22:20 volumio sudo[8178]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 21:22:20 volumio sudo[8178]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:20 volumio volumio[8130]: info: Loading plugin "alsa_controller"... Feb 18 21:22:20 volumio sudo[8176]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:20 volumio sudo[8178]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:20 volumio sudo[8185]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 18 21:22:20 volumio sudo[8185]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:20 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 21:22:20 volumio volumio[8130]: info: Loading plugin "wizard"... Feb 18 21:22:20 volumio volumio[8130]: info: Loading plugin "networkfs"... Feb 18 21:22:20 volumio volumio[8130]: info: Starting Udev Watcher for removable devices Feb 18 21:22:20 volumio volumio[8130]: info: Ignoring mount for partition: boot Feb 18 21:22:20 volumio volumio[8130]: info: Ignoring mount for partition: volumio Feb 18 21:22:20 volumio volumio[8130]: info: Ignoring mount for partition: volumio_data Feb 18 21:22:20 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 21:22:20 volumio volumio[8130]: info: Loading plugin "volumio_command_line_client"... Feb 18 21:22:20 volumio volumio[8130]: info: Loading plugin "upnp"... Feb 18 21:22:20 volumio volumio[8130]: info: [1771424540887] Starting Upmpd Daemon Feb 18 21:22:20 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 21:22:20 volumio volumio[8130]: info: Loading plugin "my_music"... Feb 18 21:22:20 volumio volumio[8130]: info: Loading plugin "mpd"... Feb 18 21:22:21 volumio volumio[8130]: info: Loading plugin "upnp_browser"... Feb 18 21:22:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 18 21:22:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:23 volumio go-librespot[8209]: go-librespot daemon starting... Feb 18 21:22:23 volumio go-librespot[8210]: time="2026-02-18T21:22:23+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:22:23 volumio go-librespot[8210]: time="2026-02-18T21:22:23+07:00" level=debug msg="app state loaded" Feb 18 21:22:23 volumio go-librespot[8210]: time="2026-02-18T21:22:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:22:23 volumio sudo[8185]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:23 volumio go-librespot[8210]: time="2026-02-18T21:22:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 21:22:23 volumio go-librespot[8210]: time="2026-02-18T21:22:23+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 21:22:23 volumio go-librespot[8210]: time="2026-02-18T21:22:23+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 21:22:23 volumio go-librespot[8210]: time="2026-02-18T21:22:23+07:00" level=info msg="zeroconf server listening on port 38663" Feb 18 21:22:23 volumio go-librespot[8210]: time="2026-02-18T21:22:23+07:00" level=debug msg="obtained new client token: AADfNHUDyLHkOGPpiEVyq6DMaCJPBCLS96oHs7bjsb2ukbiFbZIK4xp3JtznDOafgRywHISQMe87ZuOvqc071AEgU2xZ7LPnwTscBzLcApRo4yNY++4Rbg4r6gIQol64wE1z3OwGnhjZXPqrSUf8ETLKIgDEprm6DRWjK2k3PmSaU0fb1IXA32aQoEEIDhB+cNagHXKDEcQwCK73A9Q4n6wcQ5yGD+vE3oRgdC25ypcxcgjWmqMl325cmg==" Feb 18 21:22:23 volumio go-librespot[8210]: time="2026-02-18T21:22:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:22:24 volumio go-librespot[8210]: time="2026-02-18T21:22:24+07:00" level=debug msg="completed keyexchange" Feb 18 21:22:24 volumio go-librespot[8210]: time="2026-02-18T21:22:24+07:00" level=debug msg="completed challenge" Feb 18 21:22:24 volumio go-librespot[8210]: time="2026-02-18T21:22:24+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 21:22:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:22:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:22:24 volumio volumio[8130]: info: Starting UPNP Browser Feb 18 21:22:24 volumio volumio[8130]: info: Loading plugin "alarm-clock"... Feb 18 21:22:24 volumio volumio[8130]: info: Loading plugin "airplay_emulation"... Feb 18 21:22:24 volumio volumio[8130]: info: Starting Shairport Sync Feb 18 21:22:24 volumio volumio[8130]: info: Loading plugin "last_100"... Feb 18 21:22:24 volumio volumio[8130]: info: Loading plugin "webradio"... Feb 18 21:22:25 volumio volumio[8130]: info: Loading plugin "i2s_dacs"... Feb 18 21:22:25 volumio volumio[8130]: info: Loading plugin "volumiodiscovery"... Feb 18 21:22:25 volumio volumio[8130]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 21:22:25 volumio volumio[8130]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 21:22:25 volumio node[8130]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 21:22:25 volumio volumio[8130]: *** WARNING *** For more information see Feb 18 21:22:25 volumio volumio[8130]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 21:22:25 volumio volumio[8130]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 21:22:25 volumio volumio[8130]: *** WARNING *** For more information see Feb 18 21:22:25 volumio node[8130]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 21:22:25 volumio node[8130]: *** WARNING *** For more information see Feb 18 21:22:25 volumio node[8130]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 21:22:25 volumio node[8130]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 21:22:25 volumio node[8130]: *** WARNING *** For more information see Feb 18 21:22:25 volumio volumio[8130]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 18 21:22:25 volumio volumio[8130]: info: Discovery: Started advertising with name: Volumio Feb 18 21:22:25 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 21:22:25 volumio volumio[8130]: info: Loading plugin "spop"... Feb 18 21:22:27 volumio volumio[8130]: info: Loading plugin "ytcr"... Feb 18 21:22:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 18 21:22:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:27 volumio go-librespot[8219]: go-librespot daemon starting... Feb 18 21:22:27 volumio go-librespot[8220]: time="2026-02-18T21:22:27+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:22:27 volumio go-librespot[8220]: time="2026-02-18T21:22:27+07:00" level=debug msg="app state loaded" Feb 18 21:22:27 volumio go-librespot[8220]: time="2026-02-18T21:22:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:22:27 volumio go-librespot[8220]: time="2026-02-18T21:22: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 21:22:27 volumio go-librespot[8220]: time="2026-02-18T21:22:27+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 21:22:27 volumio go-librespot[8220]: time="2026-02-18T21:22:27+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 21:22:27 volumio go-librespot[8220]: time="2026-02-18T21:22:27+07:00" level=info msg="zeroconf server listening on port 37741" Feb 18 21:22:28 volumio go-librespot[8220]: time="2026-02-18T21:22:28+07:00" level=debug msg="obtained new client token: AABjZHZfaQ94nR4sJlnKVrW1rSFOgvV+rGCKBIBXPazG9QGSCtSq++cAaXWXgpfRrKDSBFgdBxQPxScDjxGUz9DwbZXtG+/8CMuK80mf6W00J3VUVUwY7lSjYUFvz11V7+zHvN/W06g0vF6RO6iKYv7hM9f0swEpJfsh9queTo/c09waTBcYR+tfK2q41q0bAtIe+pyy0+apGguLzBAsBHqbYGSi2TLRcpp9VD3dFe64KrsbfIJx1Oo=" Feb 18 21:22:28 volumio go-librespot[8220]: time="2026-02-18T21:22:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:22:28 volumio go-librespot[8220]: time="2026-02-18T21:22:28+07:00" level=debug msg="completed keyexchange" Feb 18 21:22:28 volumio go-librespot[8220]: time="2026-02-18T21:22:28+07:00" level=debug msg="completed challenge" Feb 18 21:22:28 volumio go-librespot[8220]: time="2026-02-18T21:22:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 21:22:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:22:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:22:29 volumio volumio[8130]: info: Loading plugin "ytmusic"... Feb 18 21:22:30 volumio volumio-remote-updater[25144]: [2026-02-18 21:22:30] [connect] Successful connection Feb 18 21:22:30 volumio volumio[8130]: info: Loading plugin "outputs"... Feb 18 21:22:30 volumio volumio[8130]: info: Loading plugin "albumart"... Feb 18 21:22:30 volumio volumio[8130]: info: Plugin example_plugin is not enabled Feb 18 21:22:30 volumio volumio[8130]: info: Loading plugin "inputs"... Feb 18 21:22:30 volumio volumio[8130]: info: Loading plugin "updater_comm"... Feb 18 21:22:31 volumio volumio[8130]: info: Plugin mpdemulation is not enabled Feb 18 21:22:31 volumio volumio[8130]: info: Loading plugin "rest_api"... Feb 18 21:22:31 volumio volumio[8130]: info: Loading plugin "websocket"... Feb 18 21:22:31 volumio volumio[8130]: info: Starting Socket.io Server version 1.7.4 Feb 18 21:22:31 volumio volumio[8130]: info: Loading plugin "RoonBridge"... Feb 18 21:22:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 18 21:22:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:31 volumio go-librespot[8251]: go-librespot daemon starting... Feb 18 21:22:31 volumio go-librespot[8252]: time="2026-02-18T21:22:31+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:22:31 volumio go-librespot[8252]: time="2026-02-18T21:22:31+07:00" level=debug msg="app state loaded" Feb 18 21:22:31 volumio go-librespot[8252]: time="2026-02-18T21:22:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:22:31 volumio volumio[8130]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 21:22:31 volumio volumio[8130]: info: Loading i18n strings for locale en Feb 18 21:22:31 volumio volumio[8130]: Updating browse sources language Feb 18 21:22:31 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 21:22:31 volumio volumio[8241]: Forking 3 albumart workers Feb 18 21:22:32 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 21:22:32 volumio volumio[8130]: info: CoreCommandRouter::initPlayerControls Feb 18 21:22:32 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:32 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:32 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:32 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:32 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:32 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:32 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:32 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:32 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 21:22:32 volumio volumio[8130]: Express server listening on port 3000 Feb 18 21:22:32 volumio volumio[8130]: [Metrics] WebUI: 16s 145.15ms Feb 18 21:22:32 volumio volumio[8130]: info: CoreStateMachine::resetVolumioState Feb 18 21:22:32 volumio volumio[8130]: info: CoreStateMachine::getcurrentVolume Feb 18 21:22:32 volumio volumio[8130]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 21:22:32 volumio go-librespot[8252]: time="2026-02-18T21:22:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 21:22:32 volumio go-librespot[8252]: time="2026-02-18T21:22:32+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 21:22:32 volumio go-librespot[8252]: time="2026-02-18T21:22:32+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 21:22:32 volumio go-librespot[8252]: time="2026-02-18T21:22:32+07:00" level=info msg="zeroconf server listening on port 42857" Feb 18 21:22:32 volumio sudo[8297]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 21:22:32 volumio sudo[8297]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:32 volumio sudo[8297]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:32 volumio sudo[8294]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 21:22:32 volumio sudo[8294]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:32 volumio sudo[8294]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:32 volumio volumio[8130]: info: Volumio Network Manager: Network status updated: 1 Feb 18 21:22:32 volumio go-librespot[8252]: time="2026-02-18T21:22:32+07:00" level=debug msg="obtained new client token: AACsfM+QlnlOx+irrbw/i1I/WhNxkPTe1+C1IgmrX9ozZrRX1T0mNH3NYgsPCldwBXB2NUbXGUyZ2g02QdagGSoaWfbSDACIJYrjBYCbXgc9cpNr8RktCLHSTsI3+liYYRVp46QGIbnp51xOJBg6KVzprASh2+6OxAxFFzRfWiygi8S625G4gI7eMVv6XekbcM3THtRb+Ecnpja1s2naqyCFTsnOx/EGL8CjjaG3iIaKtmsz1/DPV1xswg==" Feb 18 21:22:32 volumio go-librespot[8252]: time="2026-02-18T21:22:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:22:32 volumio go-librespot[8252]: time="2026-02-18T21:22:32+07:00" level=debug msg="completed keyexchange" Feb 18 21:22:32 volumio go-librespot[8252]: time="2026-02-18T21:22:32+07:00" level=debug msg="completed challenge" Feb 18 21:22:32 volumio volumio-remote-updater[25144]: [2026-02-18 21:22:32] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771424550 101 Feb 18 21:22:32 volumio volumio[8130]: 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 21:22:32 volumio volumio[8130]: info: VolumeController:: Volume=100 Mute =false Feb 18 21:22:32 volumio volumio[8130]: info: CoreStateMachine::pushState Feb 18 21:22:32 volumio volumio[8130]: info: CorePlayQueue::getTrack 0 Feb 18 21:22:32 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 21:22:32 volumio go-librespot[8252]: time="2026-02-18T21:22:32+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 21:22:32 volumio volumio[8130]: info: CoreCommandRouter::volumioPushState Feb 18 21:22:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:22:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:22:32 volumio volumio[8130]: info: CoreStateMachine::updateTrackBlock Feb 18 21:22:32 volumio volumio[8130]: info: CorePlayQueue::getTrackBlock Feb 18 21:22:32 volumio volumio[8130]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 21:22:32 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:22:32 volumio volumio[8130]: info: Reloading queue from file Feb 18 21:22:33 volumio volumio[8130]: info: CoreStateMachine::setRepeat null single undefined Feb 18 21:22:33 volumio volumio[8130]: info: CoreStateMachine::pushState Feb 18 21:22:33 volumio volumio[8130]: info: CorePlayQueue::getTrack 0 Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::volumioPushState Feb 18 21:22:33 volumio volumio[8130]: info: CoreStateMachine::setRandom null Feb 18 21:22:33 volumio volumio[8130]: info: CoreStateMachine::pushState Feb 18 21:22:33 volumio volumio[8130]: info: CorePlayQueue::getTrack 0 Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::volumioPushState Feb 18 21:22:33 volumio volumio[8130]: info: Setting Device type: Raspberry PI Feb 18 21:22:33 volumio volumio[8130]: info: Completed loading Core Plugins Feb 18 21:22:33 volumio volumio[8130]: info: Preparing to generate the ALSA configuration file Feb 18 21:22:33 volumio volumio[8130]: info: VolumeController:: Volume=100 Mute =false Feb 18 21:22:33 volumio volumio[8130]: info: CoreStateMachine::pushState Feb 18 21:22:33 volumio volumio[8130]: info: CorePlayQueue::getTrack 0 Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::volumioPushState Feb 18 21:22:33 volumio volumio[8130]: info: Asound.conf file unchanged, so no further update is needed Feb 18 21:22:33 volumio volumio[8130]: info: Output device has changed, restarting MPD Feb 18 21:22:33 volumio volumio[8130]: info: Output device has changed, restarting Shairport Sync Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:22:33 volumio sudo[8312]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 21:22:33 volumio sudo[8312]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:33 volumio volumio[8130]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 21:22:33 volumio volumio[8130]: info: ___________ START PLUGINS ___________ Feb 18 21:22:33 volumio sudo[8314]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 21:22:33 volumio sudo[8314]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:33 volumio sudo[8314]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:33 volumio volumio[8130]: info: ControllerMpd::onStart: Initializing MPD Feb 18 21:22:33 volumio volumio[8130]: info: Creating MPD Configuration file Feb 18 21:22:33 volumio sudo[8312]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:33 volumio sudo[8316]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 21:22:33 volumio sudo[8316]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 21:22:33 volumio volumio[8130]: info: [1771424553536] CoreMusicLibrary::Adding element Media Servers Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 21:22:33 volumio volumio[8130]: info: UPNP Browser: Client initialized successfully Feb 18 21:22:33 volumio sudo[8325]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 21:22:33 volumio sudo[8327]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 21:22:33 volumio sudo[8327]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:33 volumio sudo[8325]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:33 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:22:33 volumio sudo[8325]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:33 volumio volumio[8130]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:22:33 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 21:22:33 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 21:22:33 volumio systemd[1]: mpd.service: Consumed 7.195s CPU time. Feb 18 21:22:33 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 21:22:33 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 21:22:33 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 21:22:33 volumio volumio[8130]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 21:22:33 volumio volumio[8130]: info: [1771424553872] CoreMusicLibrary::Adding element Last_100 Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 21:22:33 volumio volumio[8130]: info: [1771424553891] CoreMusicLibrary::Adding element Webradio Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 21:22:33 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 21:22:33 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 21:22:33 volumio volumio[8130]: info: Initializing BBC Radios Feb 18 21:22:34 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 21:22:34 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:22:34 volumio volumio[8130]: info: Creating Spotify config file Feb 18 21:22:34 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:34 volumio sudo[8339]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 21:22:34 volumio sudo[8339]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 21:22:34 volumio sudo[8339]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:35 volumio volumio[8260]: Starting albumart workers Feb 18 21:22:35 volumio volumio[8130]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 21:22:35 volumio volumio[8130]: info: [1771424555197] CoreMusicLibrary::Adding element YouTube Music Feb 18 21:22:35 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 21:22:35 volumio volumio[8130]: Cannot find translation for source YouTube Music Feb 18 21:22:35 volumio volumio[8130]: info: Volumio Calling Home Feb 18 21:22:35 volumio sudo[8356]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 21:22:35 volumio sudo[8356]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:35 volumio volumio[8259]: Starting albumart workers Feb 18 21:22:35 volumio sudo[8356]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:35 volumio volumio[8258]: Starting albumart workers Feb 18 21:22:35 volumio volumio[8130]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 21:22:35 volumio volumio[8130]: info: Discovery: Found device Volumio Feb 18 21:22:35 volumio volumio[8130]: info: CoreCommandRouter::volumioGetState Feb 18 21:22:35 volumio volumio[8130]: info: CorePlayQueue::getTrack 0 Feb 18 21:22:35 volumio volumio[8130]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 21:22:35 volumio volumio[8130]: info: Discovery: Found device Volumio Feb 18 21:22:35 volumio volumio[8130]: info: CoreCommandRouter::volumioGetState Feb 18 21:22:35 volumio volumio[8130]: info: CorePlayQueue::getTrack 0 Feb 18 21:22:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 18 21:22:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:36 volumio volumio[8130]: info: MPD Permissions set Feb 18 21:22:36 volumio volumio[8130]: info: MPD Permissions set Feb 18 21:22:36 volumio volumio[8130]: info: Upmpdcli Daemon Started Feb 18 21:22:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:36 volumio go-librespot[8362]: go-librespot daemon starting... Feb 18 21:22:36 volumio volumio[8130]: 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 21:22:36 volumio volumio[8130]: info: Spotify config file written Feb 18 21:22:36 volumio go-librespot[8363]: time="2026-02-18T21:22:36+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:22:36 volumio go-librespot[8363]: time="2026-02-18T21:22:36+07:00" level=debug msg="app state loaded" Feb 18 21:22:36 volumio go-librespot[8363]: time="2026-02-18T21:22:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:22:36 volumio sudo[8370]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 21:22:36 volumio sudo[8370]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:36 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 18 21:22:36 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 18 21:22:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:36 volumio go-librespot[8372]: go-librespot daemon starting... Feb 18 21:22:36 volumio sudo[8370]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:36 volumio go-librespot[8373]: time="2026-02-18T21:22:36+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:22:36 volumio go-librespot[8373]: time="2026-02-18T21:22:36+07:00" level=debug msg="app state loaded" Feb 18 21:22:36 volumio go-librespot[8373]: time="2026-02-18T21:22:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: No need to fix Spotify hosts Feb 18 21:22:37 volumio go-librespot[8373]: time="2026-02-18T21:22:37+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 21:22:37 volumio go-librespot[8373]: time="2026-02-18T21:22:37+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 21:22:37 volumio go-librespot[8373]: time="2026-02-18T21:22:37+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 21:22:37 volumio go-librespot[8373]: time="2026-02-18T21:22:37+07:00" level=info msg="zeroconf server listening on port 41455" Feb 18 21:22:37 volumio go-librespot[8373]: time="2026-02-18T21:22:37+07:00" level=debug msg="obtained new client token: AACObElZVtuA81R8aDwvNmx7xAs6aY9NHqfYz0T8ESWon1ybh123pjoh+A1iIK2CP/6bBxn9gOXBHpdbqwvMvuJnWSTJeADuoncI/iFh2a6JmFhGnnFf4I9MO/gyQYuHEeJb1kzFHnfOuRRA/+EIDbXSeZdJFmAi0TUWspP4NdrVGVNbBUO1k3zTMW2HD4UyNIu8iTyNDq6Q5E/lAP6kFf/YrdF1N+Z8T42WRD73han+/l6dMb5AXPMmAg==" Feb 18 21:22:37 volumio go-librespot[8373]: time="2026-02-18T21:22:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:22:38 volumio go-librespot[8373]: time="2026-02-18T21:22:38+07:00" level=debug msg="completed keyexchange" Feb 18 21:22:38 volumio go-librespot[8373]: time="2026-02-18T21:22:38+07:00" level=debug msg="completed challenge" Feb 18 21:22:38 volumio go-librespot[8373]: time="2026-02-18T21:22:38+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 21:22:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:22:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:22:38 volumio volumio[8130]: info: Volumio called home Feb 18 21:22:38 volumio volumio[8130]: info: Starting Shairport Sync Feb 18 21:22:38 volumio volumio[8130]: info: Starting Shairport Sync Feb 18 21:22:38 volumio volumio[8130]: info: Starting Shairport Sync Feb 18 21:22:38 volumio sudo[8409]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 21:22:38 volumio sudo[8409]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:38 volumio sudo[8411]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 21:22:38 volumio sudo[8411]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:38 volumio sudo[8413]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 21:22:38 volumio sudo[8413]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:38 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 21:22:38 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 21:22:38 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 21:22:38 volumio systemd[1]: shairport-sync.service: Consumed 2.287s CPU time. Feb 18 21:22:38 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 21:22:38 volumio sudo[8409]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:38 volumio volumio[8130]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 21:22:38 volumio volumio[8130]: SPOTIFY: BQBbkzSNnKt7OCMQmuBsQ45FHJNBoU2zd9EyGraSMpk7NrfqK22tP34EBIJtCxYh0h0on_NO0HExqVW5763oEA-Q1eF2AHJVczAuvr0meyrky-u1eqPPl8RABemZhza62l-cL82sYzF3-OieIjichC4P-PRl1tY_PAu4VvhkXDLyUqzJatUH65pyluYWB2CyJHmEnFOOuTJKhhk5LDzduCgAgfDHInpUkcdizl1Ufx5gqpeZ4I_Fe9htEDeZmGJUAWdrpXOUV44vbcbwqgf94XYYr4-sG_nBBa-ortMXMGbREF9eMPoAdxkm Feb 18 21:22:38 volumio volumio[8130]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 21:22:38 volumio volumio[8130]: info: New Spotify access token = BQBbkzSNnKt7OCMQmuBsQ45FHJNBoU2zd9EyGraSMpk7NrfqK22tP34EBIJtCxYh0h0on_NO0HExqVW5763oEA-Q1eF2AHJVczAuvr0meyrky-u1eqPPl8RABemZhza62l-cL82sYzF3-OieIjichC4P-PRl1tY_PAu4VvhkXDLyUqzJatUH65pyluYWB2CyJHmEnFOOuTJKhhk5LDzduCgAgfDHInpUkcdizl1Ufx5gqpeZ4I_Fe9htEDeZmGJUAWdrpXOUV44vbcbwqgf94XYYr4-sG_nBBa-ortMXMGbREF9eMPoAdxkm Feb 18 21:22:38 volumio volumio[8130]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 21:22:38 volumio sudo[8411]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:38 volumio volumio[8130]: info: Shairport-Sync Started Feb 18 21:22:38 volumio volumio[8130]: Error adding Membership: Error: addMembership EINVAL Feb 18 21:22:38 volumio volumio[8130]: info: CoreCommandRouter::volumioGetState Feb 18 21:22:38 volumio volumio[8130]: info: CorePlayQueue::getTrack 0 Feb 18 21:22:38 volumio volumio[8130]: info: Shairport-Sync Started Feb 18 21:22:38 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 21:22:38 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 21:22:38 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 21:22:38 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 21:22:38 volumio sudo[8413]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:39 volumio volumio[8130]: info: Shairport-Sync Started Feb 18 21:22:39 volumio volumio[8130]: 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 21:22:39 volumio volumio[8130]: info: Spotify Successfully logged in Feb 18 21:22:39 volumio volumio[8130]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 21:22:39 volumio volumio[8130]: info: [1771424559249] CoreMusicLibrary::Adding element Spotify Feb 18 21:22:39 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 21:22:39 volumio volumio[8130]: Cannot find translation for source YouTube Music Feb 18 21:22:39 volumio volumio[8130]: Cannot find translation for source Spotify Feb 18 21:22:39 volumio volumio[8130]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 21:22:39 volumio volumio[8130]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 21:22:39 volumio volumio[8130]: info: VolumeController:: Volume=100 Mute =false Feb 18 21:22:39 volumio volumio[8130]: info: CoreCommandRouter::volumioGetState Feb 18 21:22:39 volumio volumio[8130]: info: CorePlayQueue::getTrack 0 Feb 18 21:22:39 volumio volumio[8130]: info: CoreStateMachine::pushState Feb 18 21:22:39 volumio volumio[8130]: info: CorePlayQueue::getTrack 0 Feb 18 21:22:39 volumio volumio[8130]: info: CoreCommandRouter::volumioPushState Feb 18 21:22:41 volumio volumio[8130]: info: go-librespot daemon successfully initialized Feb 18 21:22:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 18 21:22:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:41 volumio mpd[8354]: 2026-02-18T21:22:41 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 21:22:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:41 volumio go-librespot[8450]: go-librespot daemon starting... Feb 18 21:22:41 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 21:22:41 volumio sudo[8327]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:41 volumio sudo[8316]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:41 volumio go-librespot[8453]: time="2026-02-18T21:22:41+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:22:41 volumio go-librespot[8453]: time="2026-02-18T21:22:41+07:00" level=debug msg="app state loaded" Feb 18 21:22:41 volumio go-librespot[8453]: time="2026-02-18T21:22:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:22:41 volumio volumio[8130]: error: MPD error: The expression evaluated to a falsy value: Feb 18 21:22:41 volumio volumio[8130]: assert.ok(self.idling) Feb 18 21:22:41 volumio volumio[8130]: error: The expression evaluated to a falsy value: Feb 18 21:22:41 volumio volumio[8130]: assert.ok(self.idling) Feb 18 21:22:41 volumio volumio[8130]: error: updateQueue error: null Feb 18 21:22:41 volumio volumio[8130]: info: MPD running with PID8354 Feb 18 21:22:41 volumio volumio[8130]: ,establishing connection Feb 18 21:22:41 volumio volumio[8130]: info: Completed starting Core Plugins Feb 18 21:22:41 volumio volumio[8130]: info: ------------------------------------------- Feb 18 21:22:41 volumio volumio[8130]: info: ----- MyVolumio plugins startup ---- Feb 18 21:22:41 volumio volumio[8130]: info: ------------------------------------------- Feb 18 21:22:41 volumio volumio[8130]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 21:22:41 volumio volumio[8130]: error: updateQueue error: null Feb 18 21:22:41 volumio go-librespot[8453]: time="2026-02-18T21:22: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 21:22:41 volumio go-librespot[8453]: time="2026-02-18T21:22:41+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 21:22:41 volumio go-librespot[8453]: time="2026-02-18T21:22:41+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 21:22:42 volumio go-librespot[8453]: time="2026-02-18T21:22:42+07:00" level=info msg="zeroconf server listening on port 33489" Feb 18 21:22:42 volumio go-librespot[8453]: time="2026-02-18T21:22:42+07:00" level=debug msg="obtained new client token: AAA74Dn8qieqfP1Qlds+nP22cCLgCv37H1mtCCK+UltDcBfN01KbXLB315LHqYKe7knLYbbtE0jauv6w47qvpME2uzIvz+bJSuiU4rOJw/7BuoKJ3WrgUTDjsSbQTJpMxZCyWJao8PtiYzMKXy5ur69qRcdX2rcTBDl0vGUYIVEfaP9aSvb1usGH7xbPg2Ofc0Fg/QBIlArKqQauVIJ7DQ4s6W7oExuHJUaw81DKkeQ/s9NWa04ZbN8=" Feb 18 21:22:42 volumio go-librespot[8453]: time="2026-02-18T21:22:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:22:42 volumio go-librespot[8453]: time="2026-02-18T21:22:42+07:00" level=debug msg="completed keyexchange" Feb 18 21:22:42 volumio go-librespot[8453]: time="2026-02-18T21:22:42+07:00" level=debug msg="completed challenge" Feb 18 21:22:42 volumio go-librespot[8453]: time="2026-02-18T21:22: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 21:22:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:22:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:22:44 volumio volumio[8130]: info: Initializing connection to go-librespot Websocket Feb 18 21:22:44 volumio volumio[8130]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 21:22:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 18 21:22:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:45 volumio go-librespot[8462]: go-librespot daemon starting... Feb 18 21:22:45 volumio go-librespot[8463]: time="2026-02-18T21:22:45+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:22:45 volumio go-librespot[8463]: time="2026-02-18T21:22:45+07:00" level=debug msg="app state loaded" Feb 18 21:22:45 volumio go-librespot[8463]: time="2026-02-18T21:22:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:22:46 volumio go-librespot[8463]: time="2026-02-18T21:22:46+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 21:22:46 volumio go-librespot[8463]: time="2026-02-18T21:22:46+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 21:22:46 volumio go-librespot[8463]: time="2026-02-18T21:22:46+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 21:22:46 volumio go-librespot[8463]: time="2026-02-18T21:22:46+07:00" level=info msg="zeroconf server listening on port 33549" Feb 18 21:22:46 volumio volumio[8130]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 21:22:46 volumio go-librespot[8463]: time="2026-02-18T21:22:46+07:00" level=debug msg="obtained new client token: AABvsDr54HEaNFS5Y13MsRhSTczoCGvZ4J52J9jrPOMsGqH+f1lhs0DcT42yTBRyciQqiL8iYrPUZm5a+iu0y/M74CCts4hmcS1/6P+UZZljGVqPxoQ9GrW/mufbT0YrtABdh4BrVrqYR7f425HyS5+c34hM1DgIJ+UZ8vFESctXf1JH0cu4AIS2j9St0ev60dzsBddh4QJT5jVq0gLFIfSdNvyqFS3ni+ZyHXFtWJFu3f9aNJq3ANn+3Q==" Feb 18 21:22:46 volumio go-librespot[8463]: time="2026-02-18T21:22:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:22:46 volumio go-librespot[8463]: time="2026-02-18T21:22:46+07:00" level=debug msg="completed keyexchange" Feb 18 21:22:46 volumio go-librespot[8463]: time="2026-02-18T21:22:46+07:00" level=debug msg="completed challenge" Feb 18 21:22:46 volumio go-librespot[8463]: time="2026-02-18T21:22: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 21:22:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:22:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:22:47 volumio volumio[8130]: info: Initializing connection to go-librespot Websocket Feb 18 21:22:47 volumio volumio[8130]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 21:22:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 18 21:22:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:50 volumio go-librespot[8470]: go-librespot daemon starting... Feb 18 21:22:50 volumio go-librespot[8471]: time="2026-02-18T21:22:50+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:22:50 volumio go-librespot[8471]: time="2026-02-18T21:22:50+07:00" level=debug msg="app state loaded" Feb 18 21:22:50 volumio go-librespot[8471]: time="2026-02-18T21:22:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:22:50 volumio volumio[8130]: info: Initializing connection to go-librespot Websocket Feb 18 21:22:50 volumio go-librespot[8471]: time="2026-02-18T21:22:50+07:00" level=debug msg="new websocket client" Feb 18 21:22:50 volumio volumio[8130]: info: Connection to go-librespot Websocket established Feb 18 21:22:50 volumio go-librespot[8471]: time="2026-02-18T21:22:50+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 21:22:50 volumio go-librespot[8471]: time="2026-02-18T21:22:50+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 21:22:50 volumio go-librespot[8471]: time="2026-02-18T21:22:50+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 21:22:50 volumio go-librespot[8471]: time="2026-02-18T21:22:50+07:00" level=info msg="zeroconf server listening on port 40221" Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 21:22:50 volumio volumio[8130]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 21:22:50 volumio volumio[8130]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 21:22:50 volumio volumio[8130]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 21:22:50 volumio volumio[8130]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 21:22:50 volumio volumio[8130]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 21:22:50 volumio volumio[8130]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 21:22:50 volumio volumio[8130]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 21:22:50 volumio go-librespot[8471]: time="2026-02-18T21:22:50+07:00" level=debug msg="obtained new client token: AAD1bXDeOzAFAI5y+RSPYoPL2v4YZjcE8LNXPwXMEB/p5WgB8kZ5owyQiYutICGFIdn1hodqSv8F8AVnXRFhG3maYZ93RitrTPSXOUt/GRluoENqY79AlI85gcn3fmR+9XCx8qu98nSx9+0Zced0nwbyr66VxclbugKi+zMP4o5pQ4F9Lr6JXbP/4veP3aYWKZ5joQ8aoFEaFU4/BigQevCqTz0UKL120Q5w9P6qpJvA7sWkjqpKaxt+lw==" Feb 18 21:22:50 volumio go-librespot[8471]: time="2026-02-18T21:22:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:22:51 volumio go-librespot[8471]: time="2026-02-18T21:22:51+07:00" level=debug msg="completed keyexchange" Feb 18 21:22:51 volumio go-librespot[8471]: time="2026-02-18T21:22:51+07:00" level=debug msg="completed challenge" Feb 18 21:22:51 volumio go-librespot[8471]: time="2026-02-18T21:22:51+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 21:22:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:22:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:22:52 volumio volumio[8130]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 21:22:52 volumio volumio[8130]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 21:22:52 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:22:52 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:22:52 volumio volumio[8130]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 21:22:52 volumio volumio[8130]: info: MyVolumio login type: Token Feb 18 21:22:52 volumio volumio[8130]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 21:22:52 volumio volumio[8130]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 21:22:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 18 21:22:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:54 volumio volumio[8130]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 21:22:54 volumio volumio[8130]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 21:22:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:54 volumio volumio[8130]: info: Streaming services startup Feb 18 21:22:54 volumio go-librespot[8492]: go-librespot daemon starting... Feb 18 21:22:54 volumio volumio[8130]: info: Starting Streaming Daemon Feb 18 21:22:54 volumio go-librespot[8493]: time="2026-02-18T21:22:54+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:22:54 volumio go-librespot[8493]: time="2026-02-18T21:22:54+07:00" level=debug msg="app state loaded" Feb 18 21:22:54 volumio go-librespot[8493]: time="2026-02-18T21:22:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:22:54 volumio volumio[8130]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 21:22:54 volumio sudo[8500]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 21:22:54 volumio sudo[8500]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:54 volumio sudo[8500]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:54 volumio volumio[8130]: info: Getting Spotify volume Feb 18 21:22:54 volumio volumio[8130]: info: Connection to go-librespot Websocket closed Feb 18 21:22:54 volumio volumio[8130]: error: Cannot start Volumio Streaming Daemon Feb 18 21:22:54 volumio volumio[8130]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 21:22:54 volumio volumio[8130]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 21:22:54 volumio volumio[8130]: 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 21:22:54 volumio volumio[8130]: info: CoreCommandRouter::volumioGetState Feb 18 21:22:54 volumio volumio[8130]: info: CorePlayQueue::getTrack 0 Feb 18 21:22:54 volumio volumio[8130]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 18 21:22:54 volumio volumio[8130]: SPOTIFY: SPOTIFY VOLUME undefined Feb 18 21:22:54 volumio volumio[8130]: SPOTIFY: VOLUMIO VOLUME 100 Feb 18 21:22:54 volumio volumio[8130]: info: Aligning Spotify Volume to Volumio Volume Feb 18 21:22:54 volumio volumio[8130]: info: CoreCommandRouter::volumioGetState Feb 18 21:22:54 volumio volumio[8130]: info: CorePlayQueue::getTrack 0 Feb 18 21:22:54 volumio volumio[8130]: info: Setting Spotify Volume from Volumio: 100 Feb 18 21:22:55 volumio go-librespot[8493]: time="2026-02-18T21:22:55+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 21:22:55 volumio go-librespot[8493]: time="2026-02-18T21:22:55+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 21:22:55 volumio go-librespot[8493]: time="2026-02-18T21:22:55+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 21:22:55 volumio go-librespot[8493]: time="2026-02-18T21:22:55+07:00" level=info msg="zeroconf server listening on port 43383" Feb 18 21:22:55 volumio go-librespot[8493]: time="2026-02-18T21:22:55+07:00" level=debug msg="obtained new client token: AAAB4wWBR9VnwkR2cayGQOp4RG5j4Zh30EYSAR4laj4Vw3KvGUwsaCN6LUE6/Wrx4nilEqiXkScOijsY0yfN2BhemZWeHKpGbsYKdAXtPZKJycGcgVgxhSp/Su+JWKnICePQ5NE8PaURm9Zj2aWM/C3ojw86iTShlZjbe9x0plZsDEjy/lrg03oPvO3m4YulUBFPz502IPex6gtl/INVhYUW4FzjwWyiUEc3HqqhFhPnXYFXbIBzdYw=" Feb 18 21:22:55 volumio go-librespot[8493]: time="2026-02-18T21:22:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:22:55 volumio go-librespot[8493]: time="2026-02-18T21:22:55+07:00" level=debug msg="completed keyexchange" Feb 18 21:22:55 volumio go-librespot[8493]: time="2026-02-18T21:22:55+07:00" level=debug msg="completed challenge" Feb 18 21:22:55 volumio go-librespot[8493]: time="2026-02-18T21:22:55+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 21:22:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:22:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:22:55 volumio volumio[8130]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 21:22:55 volumio volumio[8130]: Error: socket hang up Feb 18 21:22:55 volumio volumio[8130]: at connResetException (node:internal/errors:720:14) Feb 18 21:22:55 volumio volumio[8130]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 18 21:22:55 volumio volumio[8130]: at Socket.emit (node:events:526:35) Feb 18 21:22:55 volumio volumio[8130]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 18 21:22:55 volumio volumio[8130]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 18 21:22:55 volumio volumio[8130]: code: 'ECONNRESET', Feb 18 21:22:55 volumio volumio[8130]: response: undefined Feb 18 21:22:55 volumio volumio[8130]: } Feb 18 21:22:55 volumio volumio[8130]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 21:22:57 volumio sudo[8522]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 21:21' Feb 18 21:22:57 volumio sudo[8522]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:57 volumio sudo[8522]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 18 21:22:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:58 volumio go-librespot[8530]: go-librespot daemon starting... Feb 18 21:22:58 volumio volumio-remote-updater[25144]: [2026-02-18 21:22:58] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Feb 18 21:22:58 volumio volumio-remote-updater[25144]: [2026-02-18 21:22:58] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Feb 18 21:22:58 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:22:58 volumio go-librespot[8531]: time="2026-02-18T21:22:58+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:22:58 volumio go-librespot[8531]: time="2026-02-18T21:22:58+07:00" level=debug msg="app state loaded" Feb 18 21:22:58 volumio go-librespot[8531]: time="2026-02-18T21:22:58+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:22:58 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 18 21:22:58 volumio systemd[1]: volumio.service: Consumed 56.056s CPU time. Feb 18 21:22:59 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 21:22:59 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 21:22:59 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 22461. Feb 18 21:22:59 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 21:22:59 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 18 21:22:59 volumio systemd[1]: volumio.service: Consumed 56.056s CPU time. Feb 18 21:22:59 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 18 21:22:59 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 21:22:59 volumio go-librespot[8531]: time="2026-02-18T21:22:59+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 21:22:59 volumio go-librespot[8531]: time="2026-02-18T21:22:59+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 21:22:59 volumio go-librespot[8531]: time="2026-02-18T21:22:59+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 21:22:59 volumio go-librespot[8531]: time="2026-02-18T21:22:59+07:00" level=info msg="zeroconf server listening on port 37015" Feb 18 21:22:59 volumio go-librespot[8531]: time="2026-02-18T21:22:59+07:00" level=debug msg="obtained new client token: AABFgPLJIwaNIxVTJlftQWK+Yn86/Dx4HWXqvuMFDj2OjlpMTWpS3reIVKKeyvoVQBKOeYH52znC66gbdp0C14cqERYGPbaMCO7gBCr48BH7CPIP49ZlvDGxM1dD9KLFvJBvM7Hwtfbo2LS/KjiM9VdhJuPpsLiTJ0b/xIKRHFy8A+DOaKOjnCfAHzeFpsWcOLzT9VbYNRCERJOwxEzeQIJLf8S72o/HtxB3GHJnkT+aDIgnVYww6hg2PA==" Feb 18 21:22:59 volumio go-librespot[8531]: time="2026-02-18T21:22:59+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:22:59 volumio go-librespot[8531]: time="2026-02-18T21:22:59+07:00" level=debug msg="completed keyexchange" Feb 18 21:22:59 volumio go-librespot[8531]: time="2026-02-18T21:22:59+07:00" level=debug msg="completed challenge" Feb 18 21:23:00 volumio go-librespot[8531]: time="2026-02-18T21:23:00+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 21:23:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:23:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:23:02 volumio volumio[8545]: info: ------------------------------------------- Feb 18 21:23:02 volumio volumio[8545]: info: ----- Volumio3 ---- Feb 18 21:23:02 volumio volumio[8545]: info: ------------------------------------------- Feb 18 21:23:02 volumio volumio[8545]: info: ----- System startup ---- Feb 18 21:23:02 volumio volumio[8545]: info: ------------------------------------------- Feb 18 21:23:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 18 21:23:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:23:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:23:03 volumio go-librespot[8568]: go-librespot daemon starting... Feb 18 21:23:03 volumio go-librespot[8569]: time="2026-02-18T21:23:03+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:23:03 volumio go-librespot[8569]: time="2026-02-18T21:23:03+07:00" level=debug msg="app state loaded" Feb 18 21:23:03 volumio go-librespot[8569]: time="2026-02-18T21:23:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:23:03 volumio go-librespot[8569]: time="2026-02-18T21:23:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 21:23:03 volumio go-librespot[8569]: time="2026-02-18T21:23:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 21:23:03 volumio go-librespot[8569]: time="2026-02-18T21:23:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 21:23:03 volumio go-librespot[8569]: time="2026-02-18T21:23:03+07:00" level=info msg="zeroconf server listening on port 40409" Feb 18 21:23:03 volumio volumio-remote-updater[25144]: [2026-02-18 21:23:03] [connect] Successful connection Feb 18 21:23:04 volumio go-librespot[8569]: time="2026-02-18T21:23:04+07:00" level=debug msg="obtained new client token: AABSDRQMqmHXvzpBU29y7d98j8LLaMp8q5nsIChIpxwYuat34EJqLF/NQ1XlNJtBZwSHQHjIlMG3gLjVlVEgVtzNtI8gQfDhaRZawQLT11yFolu8of+0jPaViJ0GYRymw510pMQ0li5lrbeMhv79PhLyrLdu2zzT486U2Zg6uHCOsC0ZwQr6m7CqAPbhTb1rOz8nW6HZrFikfnl4K8RLWP2odQfteWk+Zji4464tV+eUt3WZz3lN" Feb 18 21:23:04 volumio go-librespot[8569]: time="2026-02-18T21:23:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:23:04 volumio volumio[8545]: info: MYVOLUMIO Environment detected Feb 18 21:23:04 volumio go-librespot[8569]: time="2026-02-18T21:23:04+07:00" level=debug msg="completed keyexchange" Feb 18 21:23:04 volumio go-librespot[8569]: time="2026-02-18T21:23:04+07:00" level=debug msg="completed challenge" Feb 18 21:23:04 volumio volumio[8545]: info: Plugin folders cleanup Feb 18 21:23:04 volumio volumio[8545]: info: Scanning into folder /volumio/app/plugins/ Feb 18 21:23:04 volumio volumio[8545]: info: Scanning category audio_interface Feb 18 21:23:04 volumio volumio[8545]: info: Scanning category miscellanea Feb 18 21:23:04 volumio volumio[8545]: info: Scanning category music_service Feb 18 21:23:04 volumio volumio[8545]: info: Scanning category plugins.json Feb 18 21:23:04 volumio volumio[8545]: info: Scanning category system_controller Feb 18 21:23:04 volumio volumio[8545]: info: Scanning category user_interface Feb 18 21:23:04 volumio volumio[8545]: info: Scanning into folder /data/plugins/ Feb 18 21:23:04 volumio volumio[8545]: info: Scanning category music_service Feb 18 21:23:04 volumio go-librespot[8569]: time="2026-02-18T21:23:04+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 21:23:04 volumio volumio[8545]: info: Plugin folders cleanup completed Feb 18 21:23:04 volumio volumio[8545]: info: ------------------------------------------- Feb 18 21:23:04 volumio volumio[8545]: info: ----- Core plugins startup ---- Feb 18 21:23:04 volumio volumio[8545]: info: ------------------------------------------- Feb 18 21:23:04 volumio volumio[8545]: info: Loading plugins from folder /volumio/app/plugins/ Feb 18 21:23:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:23:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:23:04 volumio volumio[8545]: info: Adding plugin upnp to MyMusic Plugins Feb 18 21:23:04 volumio volumio[8545]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 18 21:23:04 volumio volumio[8545]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 18 21:23:04 volumio volumio[8545]: info: Loading plugins from folder /data/plugins/ Feb 18 21:23:04 volumio volumio[8545]: info: Loading plugin "system"... Feb 18 21:23:04 volumio volumio[8545]: info: Loading plugin "appearance"... Feb 18 21:23:06 volumio volumio[8545]: info: Loading plugin "network"... Feb 18 21:23:06 volumio volumio[8545]: info: Refreshing Cached IP Addresses Feb 18 21:23:06 volumio sudo[8584]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 21:23:06 volumio sudo[8584]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:23:06 volumio volumio[8545]: info: Loading plugin "services"... Feb 18 21:23:06 volumio sudo[8586]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 21:23:06 volumio sudo[8586]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:23:06 volumio volumio[8545]: info: Loading plugin "alsa_controller"... Feb 18 21:23:06 volumio sudo[8584]: pam_unix(sudo:session): session closed for user root Feb 18 21:23:06 volumio sudo[8586]: pam_unix(sudo:session): session closed for user root Feb 18 21:23:06 volumio sudo[8593]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 18 21:23:06 volumio sudo[8593]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:23:06 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 21:23:06 volumio volumio[8545]: info: Loading plugin "wizard"... Feb 18 21:23:06 volumio volumio[8545]: info: Loading plugin "networkfs"... Feb 18 21:23:06 volumio volumio[8545]: info: Starting Udev Watcher for removable devices Feb 18 21:23:06 volumio volumio[8545]: info: Ignoring mount for partition: boot Feb 18 21:23:06 volumio volumio[8545]: info: Ignoring mount for partition: volumio Feb 18 21:23:06 volumio volumio[8545]: info: Ignoring mount for partition: volumio_data Feb 18 21:23:06 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 21:23:06 volumio volumio[8545]: info: Loading plugin "volumio_command_line_client"... Feb 18 21:23:06 volumio volumio[8545]: info: Loading plugin "upnp"... Feb 18 21:23:06 volumio volumio[8545]: info: [1771424586767] Starting Upmpd Daemon Feb 18 21:23:06 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 21:23:06 volumio volumio[8545]: info: Loading plugin "my_music"... Feb 18 21:23:06 volumio volumio[8545]: info: Loading plugin "mpd"... Feb 18 21:23:07 volumio volumio[8545]: info: Loading plugin "upnp_browser"... Feb 18 21:23:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 18 21:23:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:23:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:23:07 volumio go-librespot[8617]: go-librespot daemon starting... Feb 18 21:23:07 volumio go-librespot[8618]: time="2026-02-18T21:23:07+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:23:07 volumio go-librespot[8618]: time="2026-02-18T21:23:07+07:00" level=debug msg="app state loaded" Feb 18 21:23:07 volumio go-librespot[8618]: time="2026-02-18T21:23:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:23:08 volumio go-librespot[8618]: time="2026-02-18T21:23:08+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 21:23:08 volumio go-librespot[8618]: time="2026-02-18T21:23:08+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 21:23:08 volumio go-librespot[8618]: time="2026-02-18T21:23:08+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 21:23:08 volumio go-librespot[8618]: time="2026-02-18T21:23:08+07:00" level=info msg="zeroconf server listening on port 42623" Feb 18 21:23:08 volumio go-librespot[8618]: time="2026-02-18T21:23:08+07:00" level=debug msg="obtained new client token: AAB85CrWdcD9mQc6l/+9bd9jVb0rEHEmHLzRh19o9tpodJyoBT0huIu6m1G2J/aeAcQZxPW3C2A2eSTeoYqsNIUPgqMRWRO3YHDfFZFPRY1FwiXtA/uEvjDlmyHVVEPoRjFFCUV4XZJl29pasIkyJdOaIuHEH7H8PJofTSa86cdcGgZ0mbax9BQZmP4BdxWIKOBVAGzLJivxW0IdvCNiirnzNwNYI/4KjSzArMQLpogxbLUvybBocRLaqg==" Feb 18 21:23:08 volumio go-librespot[8618]: time="2026-02-18T21:23:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:23:08 volumio go-librespot[8618]: time="2026-02-18T21:23:08+07:00" level=debug msg="completed keyexchange" Feb 18 21:23:08 volumio go-librespot[8618]: time="2026-02-18T21:23:08+07:00" level=debug msg="completed challenge" Feb 18 21:23:08 volumio go-librespot[8618]: time="2026-02-18T21:23:08+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 21:23:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:23:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:23:09 volumio sudo[8593]: pam_unix(sudo:session): session closed for user root Feb 18 21:23:10 volumio volumio[8545]: info: Starting UPNP Browser Feb 18 21:23:10 volumio volumio[8545]: info: Loading plugin "alarm-clock"... Feb 18 21:23:10 volumio volumio[8545]: info: Loading plugin "airplay_emulation"... Feb 18 21:23:10 volumio volumio[8545]: info: Starting Shairport Sync Feb 18 21:23:10 volumio volumio[8545]: info: Loading plugin "last_100"... Feb 18 21:23:10 volumio volumio[8545]: info: Loading plugin "webradio"... Feb 18 21:23:10 volumio volumio[8545]: info: Loading plugin "i2s_dacs"... Feb 18 21:23:10 volumio volumio[8545]: info: Loading plugin "volumiodiscovery"... Feb 18 21:23:10 volumio volumio[8545]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 21:23:10 volumio volumio[8545]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 21:23:10 volumio node[8545]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 21:23:10 volumio volumio[8545]: *** WARNING *** For more information see Feb 18 21:23:10 volumio volumio[8545]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 21:23:10 volumio volumio[8545]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 21:23:10 volumio volumio[8545]: *** WARNING *** For more information see Feb 18 21:23:10 volumio node[8545]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 21:23:10 volumio node[8545]: *** WARNING *** For more information see Feb 18 21:23:10 volumio node[8545]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 21:23:10 volumio node[8545]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 21:23:10 volumio node[8545]: *** WARNING *** For more information see Feb 18 21:23:11 volumio volumio[8545]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 18 21:23:11 volumio volumio[8545]: info: Discovery: Started advertising with name: Volumio Feb 18 21:23:11 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 21:23:11 volumio volumio[8545]: info: Loading plugin "spop"... Feb 18 21:23:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 18 21:23:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:23:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:23:11 volumio go-librespot[8628]: go-librespot daemon starting... Feb 18 21:23:11 volumio go-librespot[8629]: time="2026-02-18T21:23:11+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:23:11 volumio go-librespot[8629]: time="2026-02-18T21:23:11+07:00" level=debug msg="app state loaded" Feb 18 21:23:11 volumio go-librespot[8629]: time="2026-02-18T21:23:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:23:12 volumio go-librespot[8629]: time="2026-02-18T21:23:12+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 21:23:12 volumio go-librespot[8629]: time="2026-02-18T21:23:12+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 21:23:12 volumio go-librespot[8629]: time="2026-02-18T21:23:12+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 21:23:12 volumio go-librespot[8629]: time="2026-02-18T21:23:12+07:00" level=info msg="zeroconf server listening on port 46431" Feb 18 21:23:12 volumio go-librespot[8629]: time="2026-02-18T21:23:12+07:00" level=debug msg="obtained new client token: AADp9zeBytCnh+o1H3l1pu2k1sT6ZhuK8i1JbY1ODWRpC+eGg0c0kCRcbb1uR66sQWUmqb7REXZS+hM76cHBkDfxVuMkNmQhT6MeMqI98bQkCeYL8Xfv0wiYfRuG/5liLM7a1LFNFz82PpnjvLHKJeQWvwfWyPJkfzU2JHy+uSAig3NcQaddaMBPCio1ZgxppTAZi0v3LMG9sVDLTnxN2/E4SmkcDT1eb323xykl6o0TqQSZelEFs81k3w==" Feb 18 21:23:12 volumio go-librespot[8629]: time="2026-02-18T21:23:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:23:12 volumio volumio[8545]: info: Loading plugin "ytcr"... Feb 18 21:23:13 volumio go-librespot[8629]: time="2026-02-18T21:23:13+07:00" level=debug msg="completed keyexchange" Feb 18 21:23:13 volumio go-librespot[8629]: time="2026-02-18T21:23:13+07:00" level=debug msg="completed challenge" Feb 18 21:23:13 volumio go-librespot[8629]: time="2026-02-18T21:23:13+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 21:23:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:23:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:23:15 volumio volumio[8545]: info: Loading plugin "ytmusic"... Feb 18 21:23:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 18 21:23:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:23:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:23:16 volumio go-librespot[8639]: go-librespot daemon starting... Feb 18 21:23:16 volumio go-librespot[8640]: time="2026-02-18T21:23:16+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:23:16 volumio go-librespot[8640]: time="2026-02-18T21:23:16+07:00" level=debug msg="app state loaded" Feb 18 21:23:16 volumio go-librespot[8640]: time="2026-02-18T21:23:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:23:16 volumio volumio-remote-updater[25144]: [2026-02-18 21:23:16] [connect] Successful connection Feb 18 21:23:16 volumio volumio[8545]: info: Loading plugin "outputs"... Feb 18 21:23:16 volumio volumio[8545]: info: Loading plugin "albumart"... Feb 18 21:23:16 volumio volumio[8545]: info: Plugin example_plugin is not enabled Feb 18 21:23:16 volumio volumio[8545]: info: Loading plugin "inputs"... Feb 18 21:23:16 volumio volumio[8545]: info: Loading plugin "updater_comm"... Feb 18 21:23:16 volumio volumio[8545]: info: Plugin mpdemulation is not enabled Feb 18 21:23:16 volumio volumio[8545]: info: Loading plugin "rest_api"... Feb 18 21:23:16 volumio go-librespot[8640]: time="2026-02-18T21:23:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 21:23:16 volumio go-librespot[8640]: time="2026-02-18T21:23:16+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 21:23:16 volumio go-librespot[8640]: time="2026-02-18T21:23:16+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 21:23:17 volumio go-librespot[8640]: time="2026-02-18T21:23:17+07:00" level=info msg="zeroconf server listening on port 46053" Feb 18 21:23:17 volumio volumio[8545]: info: Loading plugin "websocket"... Feb 18 21:23:17 volumio volumio[8545]: info: Starting Socket.io Server version 1.7.4 Feb 18 21:23:17 volumio volumio[8545]: info: Loading plugin "RoonBridge"... Feb 18 21:23:17 volumio go-librespot[8640]: time="2026-02-18T21:23:17+07:00" level=debug msg="obtained new client token: AABwnIlk9TJ3Mpgsk1C/oHvieJYteEJ7gD4aXqREgf3Fd4bGR+T8GwEyEKM3Jsy29smo/ztZSn5ost1BykcfQsmVJysv4gbhWRAPCWIaNr5fnyBAnNyK4e4HaAS6tEQDdH9i//uRXBX9B3J0tw1chuyCt/iwLybKKCBfPf/1coWrZN0odXBlTd5KxAhDP40xfkqTW17E/9gTcgBmX2oNQD/zWmvvhMf2SSxKjuO5Da9klKAV9ccpw2E=" Feb 18 21:23:17 volumio go-librespot[8640]: time="2026-02-18T21:23:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:23:17 volumio go-librespot[8640]: time="2026-02-18T21:23:17+07:00" level=debug msg="completed keyexchange" Feb 18 21:23:17 volumio go-librespot[8640]: time="2026-02-18T21:23:17+07:00" level=debug msg="completed challenge" Feb 18 21:23:17 volumio volumio[8545]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 21:23:17 volumio volumio[8545]: info: Loading i18n strings for locale en Feb 18 21:23:17 volumio volumio[8545]: Updating browse sources language Feb 18 21:23:17 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 21:23:17 volumio go-librespot[8640]: time="2026-02-18T21:23:17+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 21:23:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:23:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:23:17 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 21:23:17 volumio volumio[8545]: info: CoreCommandRouter::initPlayerControls Feb 18 21:23:17 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:23:17 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:23:17 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:23:17 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:23:17 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:23:17 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:23:17 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:23:17 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:23:17 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 21:23:17 volumio volumio[8545]: Express server listening on port 3000 Feb 18 21:23:17 volumio volumio[8545]: [Metrics] WebUI: 16s 45.44ms Feb 18 21:23:17 volumio volumio[8660]: Forking 3 albumart workers Feb 18 21:23:17 volumio volumio[8545]: info: CoreStateMachine::resetVolumioState Feb 18 21:23:17 volumio volumio[8545]: info: CoreStateMachine::getcurrentVolume Feb 18 21:23:17 volumio volumio[8545]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 21:23:18 volumio sudo[8703]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 21:23:18 volumio sudo[8703]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:23:18 volumio sudo[8703]: pam_unix(sudo:session): session closed for user root Feb 18 21:23:18 volumio sudo[8705]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 21:23:18 volumio sudo[8705]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:23:18 volumio sudo[8705]: pam_unix(sudo:session): session closed for user root Feb 18 21:23:18 volumio volumio[8545]: info: Volumio Network Manager: Network status updated: 1 Feb 18 21:23:18 volumio volumio[8545]: info: VolumeController:: Volume=100 Mute =false Feb 18 21:23:18 volumio volumio[8545]: info: CoreStateMachine::pushState Feb 18 21:23:18 volumio volumio[8545]: info: CorePlayQueue::getTrack 0 Feb 18 21:23:18 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 21:23:18 volumio volumio[8545]: info: CoreCommandRouter::volumioPushState Feb 18 21:23:18 volumio volumio[8545]: info: CoreStateMachine::updateTrackBlock Feb 18 21:23:18 volumio volumio[8545]: info: CorePlayQueue::getTrackBlock Feb 18 21:23:18 volumio volumio[8545]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 21:23:18 volumio volumio-remote-updater[25144]: [2026-02-18 21:23:18] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771424596 101 Feb 18 21:23:18 volumio volumio[8545]: 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 21:23:18 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:23:18 volumio volumio[8545]: info: Reloading queue from file Feb 18 21:23:18 volumio volumio[8545]: info: CoreStateMachine::setRepeat null single undefined Feb 18 21:23:18 volumio volumio[8545]: info: CoreStateMachine::pushState Feb 18 21:23:18 volumio volumio[8545]: info: CorePlayQueue::getTrack 0 Feb 18 21:23:18 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 21:23:18 volumio volumio[8545]: info: CoreCommandRouter::volumioPushState Feb 18 21:23:18 volumio volumio[8545]: info: CoreStateMachine::setRandom null Feb 18 21:23:18 volumio volumio[8545]: info: CoreStateMachine::pushState Feb 18 21:23:18 volumio volumio[8545]: info: CorePlayQueue::getTrack 0 Feb 18 21:23:18 volumio volumio[8545]: info: CoreCommandRouter::volumioPushState Feb 18 21:23:18 volumio volumio[8545]: info: Setting Device type: Raspberry PI Feb 18 21:23:18 volumio volumio[8545]: info: Completed loading Core Plugins Feb 18 21:23:18 volumio volumio[8545]: info: Preparing to generate the ALSA configuration file Feb 18 21:23:18 volumio volumio[8545]: info: VolumeController:: Volume=100 Mute =false Feb 18 21:23:18 volumio volumio[8545]: info: CoreStateMachine::pushState Feb 18 21:23:18 volumio volumio[8545]: info: CorePlayQueue::getTrack 0 Feb 18 21:23:18 volumio volumio[8545]: info: CoreCommandRouter::volumioPushState Feb 18 21:23:18 volumio volumio[8545]: info: Asound.conf file unchanged, so no further update is needed Feb 18 21:23:18 volumio volumio[8545]: info: Output device has changed, restarting MPD Feb 18 21:23:18 volumio volumio[8545]: info: Output device has changed, restarting Shairport Sync Feb 18 21:23:18 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:23:18 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:23:19 volumio sudo[8721]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 21:23:19 volumio sudo[8721]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:23:19 volumio volumio[8545]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 21:23:19 volumio volumio[8545]: info: ___________ START PLUGINS ___________ Feb 18 21:23:19 volumio sudo[8723]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 21:23:19 volumio sudo[8723]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:23:19 volumio volumio[8545]: info: ControllerMpd::onStart: Initializing MPD Feb 18 21:23:19 volumio volumio[8545]: info: Creating MPD Configuration file Feb 18 21:23:19 volumio sudo[8723]: pam_unix(sudo:session): session closed for user root Feb 18 21:23:19 volumio sudo[8725]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 21:23:19 volumio sudo[8725]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:23:19 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 21:23:19 volumio volumio[8545]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 21:23:19 volumio volumio[8545]: info: [1771424599154] CoreMusicLibrary::Adding element Media Servers Feb 18 21:23:19 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 21:23:19 volumio sudo[8734]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 21:23:19 volumio volumio[8545]: info: UPNP Browser: Client initialized successfully Feb 18 21:23:19 volumio sudo[8734]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:23:19 volumio sudo[8736]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 21:23:19 volumio sudo[8736]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:23:19 volumio sudo[8734]: pam_unix(sudo:session): session closed for user root Feb 18 21:23:19 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 21:23:19 volumio sudo[8721]: pam_unix(sudo:session): session closed for user root Feb 18 21:23:19 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:23:19 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:23:19 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 21:23:19 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 21:23:19 volumio systemd[1]: mpd.service: Consumed 7.173s CPU time. Feb 18 21:23:19 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 21:23:19 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 21:23:19 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 21:23:19 volumio volumio[8545]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 21:23:19 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:23:19 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:23:19 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 21:23:19 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 21:23:19 volumio volumio[8545]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 21:23:19 volumio volumio[8545]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 21:23:19 volumio volumio[8545]: info: [1771424599584] CoreMusicLibrary::Adding element Last_100 Feb 18 21:23:19 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 21:23:19 volumio volumio[8545]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 21:23:19 volumio volumio[8545]: info: [1771424599614] CoreMusicLibrary::Adding element Webradio Feb 18 21:23:19 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 21:23:19 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 21:23:19 volumio volumio[8545]: info: Initializing BBC Radios Feb 18 21:23:19 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 21:23:19 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:23:19 volumio volumio[8545]: info: Creating Spotify config file Feb 18 21:23:19 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:23:20 volumio sudo[8748]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 21:23:20 volumio sudo[8748]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 21:23:20 volumio sudo[8748]: pam_unix(sudo:session): session closed for user root Feb 18 21:23:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 18 21:23:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:23:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:23:20 volumio go-librespot[8764]: go-librespot daemon starting... Feb 18 21:23:21 volumio volumio[8675]: Starting albumart workers Feb 18 21:23:21 volumio volumio[8545]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 21:23:21 volumio volumio[8545]: info: [1771424601031] CoreMusicLibrary::Adding element YouTube Music Feb 18 21:23:21 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 21:23:21 volumio volumio[8545]: Cannot find translation for source YouTube Music Feb 18 21:23:21 volumio go-librespot[8765]: time="2026-02-18T21:23:21+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:23:21 volumio volumio[8545]: info: Volumio Calling Home Feb 18 21:23:21 volumio sudo[8772]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 21:23:21 volumio sudo[8772]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:23:21 volumio volumio[8674]: Starting albumart workers Feb 18 21:23:21 volumio sudo[8772]: pam_unix(sudo:session): session closed for user root Feb 18 21:23:21 volumio volumio[8676]: Starting albumart workers Feb 18 21:23:21 volumio go-librespot[8765]: time="2026-02-18T21:23:21+07:00" level=info msg="zeroconf server listening on port 42197" Feb 18 21:23:22 volumio volumio[8545]: info: MPD Permissions set Feb 18 21:23:22 volumio volumio[8545]: info: MPD Permissions set Feb 18 21:23:22 volumio volumio[8545]: info: Upmpdcli Daemon Started Feb 18 21:23:22 volumio volumio[8545]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 21:23:22 volumio volumio[8545]: info: Discovery: Found device Volumio Feb 18 21:23:22 volumio volumio[8545]: info: CoreCommandRouter::volumioGetState Feb 18 21:23:22 volumio volumio[8545]: info: CorePlayQueue::getTrack 0 Feb 18 21:23:22 volumio volumio[8545]: info: Volumio called home Feb 18 21:23:22 volumio volumio[8545]: info: Spotify config file written Feb 18 21:23:22 volumio volumio[8545]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 21:23:22 volumio volumio[8545]: info: Discovery: Found device Volumio Feb 18 21:23:22 volumio volumio[8545]: info: CoreCommandRouter::volumioGetState Feb 18 21:23:22 volumio volumio[8545]: info: CorePlayQueue::getTrack 0 Feb 18 21:23:22 volumio volumio[8545]: 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 21:23:22 volumio sudo[8779]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 21:23:22 volumio sudo[8779]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:23:22 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:23:22 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:23:22 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:23:22 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:23:22 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:23:22 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:23:22 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:23:22 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:23:22 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:23:22 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:23:22 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 18 21:23:22 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:23:22 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:23:22 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 18 21:23:22 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:23:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:23:22 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:23:22 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:23:22 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:23:22 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:23:22 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:23:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:23:22 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:23:22 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:23:22 volumio go-librespot[8788]: go-librespot daemon starting... Feb 18 21:23:22 volumio volumio[8545]: info: No need to fix Spotify hosts Feb 18 21:23:22 volumio sudo[8779]: pam_unix(sudo:session): session closed for user root Feb 18 21:23:22 volumio go-librespot[8792]: time="2026-02-18T21:23:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:23:22 volumio go-librespot[8792]: time="2026-02-18T21:23:22+07:00" level=debug msg="app state loaded" Feb 18 21:23:22 volumio go-librespot[8792]: time="2026-02-18T21:23:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:23:23 volumio go-librespot[8792]: time="2026-02-18T21:23:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 21:23:23 volumio go-librespot[8792]: time="2026-02-18T21:23:23+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 21:23:23 volumio go-librespot[8792]: time="2026-02-18T21:23:23+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 21:23:23 volumio go-librespot[8792]: time="2026-02-18T21:23:23+07:00" level=info msg="zeroconf server listening on port 39229" Feb 18 21:23:24 volumio go-librespot[8792]: time="2026-02-18T21:23:24+07:00" level=debug msg="obtained new client token: AADHQpp4JyWDbmnC0v81gJOupXaGi1uuS5z8Ptueb9e4Y5OQBQ6imTlkPjY2J5rYlQNJwgmMGadLwRFkD40mOoFZ68q3r8U68vwlGY0bGm2ByReScdQv04eNBGMa+pCzgWXLghjhqXOP1FSAm4DozfbKFYyVzt7dneX5wpGgOngxfIkEHFdDxzt/dr86n/5JlT/to+n9k7rR4cLL65u1qGV3LAwwiyLZ/JpFK28NlouL0gbuKS14K2uLzw==" Feb 18 21:23:24 volumio volumio[8545]: info: Starting Shairport Sync Feb 18 21:23:24 volumio volumio[8545]: info: Starting Shairport Sync Feb 18 21:23:24 volumio volumio[8545]: info: Starting Shairport Sync Feb 18 21:23:24 volumio go-librespot[8792]: time="2026-02-18T21:23:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:23:24 volumio sudo[8819]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 21:23:24 volumio sudo[8819]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:23:24 volumio sudo[8823]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 21:23:24 volumio sudo[8823]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:23:24 volumio sudo[8821]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 21:23:24 volumio sudo[8821]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:23:24 volumio go-librespot[8792]: time="2026-02-18T21:23:24+07:00" level=debug msg="completed keyexchange" Feb 18 21:23:24 volumio go-librespot[8792]: time="2026-02-18T21:23:24+07:00" level=debug msg="completed challenge" Feb 18 21:23:24 volumio go-librespot[8792]: time="2026-02-18T21:23:24+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 21:23:24 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 21:23:24 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 21:23:24 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 21:23:24 volumio systemd[1]: shairport-sync.service: Consumed 2.363s CPU time. Feb 18 21:23:24 volumio volumio[8545]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 21:23:24 volumio volumio[8545]: SPOTIFY: BQAMscgUAlyBd4mlL08x6GSVe-O0ISimVPU9U3RQuuVXh6QDAlQRMfzQZJ6X1xA8O8NKOl_sNM6Au8WrFuTBd4ebhs6Si8chgrJbC2Tig4xx1D-0Nj8HfEcOB6nFEUWZ2pqWgXB2UnsNW55kyhv6C4ZxDXHtGgxl4ItRlKO-c5nzsyrPC8i_5sSfIFB-GKYZaDxgrh4CCe79q3rSsMM3X_qNDFAHUOUo-Lm-9sMJF7cgbjLKDAndnmKWBGEM3cd_wuiQ6Ci-12DOaKw21x9agzXUtI2P0IzS_w1PrzbBpigOV0wuYx2Y-sMK Feb 18 21:23:24 volumio volumio[8545]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 21:23:24 volumio volumio[8545]: info: New Spotify access token = BQAMscgUAlyBd4mlL08x6GSVe-O0ISimVPU9U3RQuuVXh6QDAlQRMfzQZJ6X1xA8O8NKOl_sNM6Au8WrFuTBd4ebhs6Si8chgrJbC2Tig4xx1D-0Nj8HfEcOB6nFEUWZ2pqWgXB2UnsNW55kyhv6C4ZxDXHtGgxl4ItRlKO-c5nzsyrPC8i_5sSfIFB-GKYZaDxgrh4CCe79q3rSsMM3X_qNDFAHUOUo-Lm-9sMJF7cgbjLKDAndnmKWBGEM3cd_wuiQ6Ci-12DOaKw21x9agzXUtI2P0IzS_w1PrzbBpigOV0wuYx2Y-sMK Feb 18 21:23:24 volumio volumio[8545]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 21:23:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:23:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:23:24 volumio volumio[8545]: info: CoreCommandRouter::volumioGetState Feb 18 21:23:24 volumio volumio[8545]: info: CorePlayQueue::getTrack 0 Feb 18 21:23:24 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 21:23:24 volumio sudo[8823]: pam_unix(sudo:session): session closed for user root Feb 18 21:23:24 volumio sudo[8819]: pam_unix(sudo:session): session closed for user root Feb 18 21:23:24 volumio sudo[8821]: pam_unix(sudo:session): session closed for user root Feb 18 21:23:24 volumio volumio[8545]: info: Shairport-Sync Started Feb 18 21:23:24 volumio volumio[8545]: Error adding Membership: Error: addMembership EINVAL Feb 18 21:23:24 volumio volumio[8545]: info: Shairport-Sync Started Feb 18 21:23:24 volumio volumio[8545]: info: Shairport-Sync Started Feb 18 21:23:24 volumio volumio[8545]: 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 21:23:24 volumio volumio[8545]: info: Spotify Successfully logged in Feb 18 21:23:24 volumio volumio[8545]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 21:23:24 volumio volumio[8545]: info: [1771424604994] CoreMusicLibrary::Adding element Spotify Feb 18 21:23:24 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 21:23:24 volumio volumio[8545]: Cannot find translation for source YouTube Music Feb 18 21:23:24 volumio volumio[8545]: Cannot find translation for source Spotify Feb 18 21:23:25 volumio volumio[8545]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 21:23:25 volumio volumio[8545]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 21:23:25 volumio volumio[8545]: info: VolumeController:: Volume=100 Mute =false Feb 18 21:23:25 volumio volumio[8545]: info: CoreCommandRouter::volumioGetState Feb 18 21:23:25 volumio volumio[8545]: info: CorePlayQueue::getTrack 0 Feb 18 21:23:25 volumio volumio[8545]: info: CoreStateMachine::pushState Feb 18 21:23:25 volumio volumio[8545]: info: CorePlayQueue::getTrack 0 Feb 18 21:23:25 volumio volumio[8545]: info: CoreCommandRouter::volumioPushState Feb 18 21:23:26 volumio volumio[8545]: info: go-librespot daemon successfully initialized Feb 18 21:23:27 volumio mpd[8763]: 2026-02-18T21:23:27 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 21:23:27 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 21:23:27 volumio sudo[8725]: pam_unix(sudo:session): session closed for user root Feb 18 21:23:27 volumio sudo[8736]: pam_unix(sudo:session): session closed for user root Feb 18 21:23:27 volumio volumio[8545]: error: MPD error: The expression evaluated to a falsy value: Feb 18 21:23:27 volumio volumio[8545]: assert.ok(self.idling) Feb 18 21:23:27 volumio volumio[8545]: error: The expression evaluated to a falsy value: Feb 18 21:23:27 volumio volumio[8545]: assert.ok(self.idling) Feb 18 21:23:27 volumio volumio[8545]: error: updateQueue error: null Feb 18 21:23:27 volumio volumio[8545]: info: MPD running with PID8763 Feb 18 21:23:27 volumio volumio[8545]: ,establishing connection Feb 18 21:23:27 volumio volumio[8545]: info: Completed starting Core Plugins Feb 18 21:23:27 volumio volumio[8545]: info: ------------------------------------------- Feb 18 21:23:27 volumio volumio[8545]: info: ----- MyVolumio plugins startup ---- Feb 18 21:23:27 volumio volumio[8545]: info: ------------------------------------------- Feb 18 21:23:27 volumio volumio[8545]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 21:23:27 volumio volumio[8545]: error: updateQueue error: null Feb 18 21:23:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 18 21:23:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:23:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:23:27 volumio go-librespot[8863]: go-librespot daemon starting... Feb 18 21:23:27 volumio go-librespot[8864]: time="2026-02-18T21:23:27+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:23:27 volumio go-librespot[8864]: time="2026-02-18T21:23:27+07:00" level=debug msg="app state loaded" Feb 18 21:23:27 volumio go-librespot[8864]: time="2026-02-18T21:23:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:23:28 volumio go-librespot[8864]: time="2026-02-18T21:23:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 21:23:28 volumio go-librespot[8864]: time="2026-02-18T21:23:28+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 21:23:28 volumio go-librespot[8864]: time="2026-02-18T21:23:28+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 21:23:28 volumio go-librespot[8864]: time="2026-02-18T21:23:28+07:00" level=info msg="zeroconf server listening on port 33857" Feb 18 21:23:28 volumio go-librespot[8864]: time="2026-02-18T21:23:28+07:00" level=debug msg="obtained new client token: AAAPr9JH2LgGumB6bL2rl/INNLU3r2PTMFQsPbzIfXHXeZxPyCcA98+HggnbasfaN/23Ht7GOY6Usm9todHWTtj0p2n+prc/Lh6iCg1UClxCq6Wn6WWhNQdKGHxyO4Ferj9cEGwR4baFp9yxNNwbKlSs5ZAYcg5Q3M+c4Ls07TYiYlRJvyOjCwhFqB5LH6MBNgEgtEL+YQ3GHfe7ZJ6NzQO9sn1r+wNo1cuG7SpuuMogpUZzsr/B2oIDUg==" Feb 18 21:23:28 volumio go-librespot[8864]: time="2026-02-18T21:23:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:23:28 volumio go-librespot[8864]: time="2026-02-18T21:23:28+07:00" level=debug msg="completed keyexchange" Feb 18 21:23:28 volumio go-librespot[8864]: time="2026-02-18T21:23:28+07:00" level=debug msg="completed challenge" Feb 18 21:23:28 volumio go-librespot[8864]: time="2026-02-18T21:23:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 21:23:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:23:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:23:29 volumio volumio[8545]: info: Initializing connection to go-librespot Websocket Feb 18 21:23:30 volumio volumio[8545]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 21:23:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 18 21:23:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:23:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:23:31 volumio go-librespot[8872]: go-librespot daemon starting... Feb 18 21:23:31 volumio go-librespot[8873]: time="2026-02-18T21:23:31+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:23:31 volumio go-librespot[8873]: time="2026-02-18T21:23:31+07:00" level=debug msg="app state loaded" Feb 18 21:23:31 volumio go-librespot[8873]: time="2026-02-18T21:23:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:23:32 volumio volumio[8545]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 21:23:32 volumio go-librespot[8873]: time="2026-02-18T21:23:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 21:23:32 volumio go-librespot[8873]: time="2026-02-18T21:23:32+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 21:23:32 volumio go-librespot[8873]: time="2026-02-18T21:23:32+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 21:23:32 volumio go-librespot[8873]: time="2026-02-18T21:23:32+07:00" level=info msg="zeroconf server listening on port 38825" Feb 18 21:23:32 volumio go-librespot[8873]: time="2026-02-18T21:23:32+07:00" level=debug msg="obtained new client token: AAAWKsGmVkfvSZ0A/o936elw8TlvLE//2r9mcrODY4fBnR/IU304RiWu6bacIV6GvcxIGfWvZdmzIcuaYJyEcsFPe5jEHVpFADDchydWsTJp/32GpfKvnYcXuQEJYfggWKg7vzTvr1h6zSuFNylEnGViG4T3T5FqtChLq/dgzSalUc4g1A6DfEhEbhXOFfUIHOgPz6YHa2azmrXlsW6ZbDaWN5Vk9mqQpZslDaRaNzRWX/RyqaPv57EVZw==" Feb 18 21:23:32 volumio go-librespot[8873]: time="2026-02-18T21:23:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:23:32 volumio go-librespot[8873]: time="2026-02-18T21:23:32+07:00" level=debug msg="completed keyexchange" Feb 18 21:23:32 volumio go-librespot[8873]: time="2026-02-18T21:23:32+07:00" level=debug msg="completed challenge" Feb 18 21:23:32 volumio go-librespot[8873]: time="2026-02-18T21:23:32+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 21:23:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:23:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:23:33 volumio volumio[8545]: info: Initializing connection to go-librespot Websocket Feb 18 21:23:33 volumio volumio[8545]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 21:23:36 volumio volumio[8545]: info: Initializing connection to go-librespot Websocket Feb 18 21:23:36 volumio volumio[8545]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 21:23:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 18 21:23:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:23:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:23:36 volumio go-librespot[8882]: go-librespot daemon starting... Feb 18 21:23:36 volumio go-librespot[8883]: time="2026-02-18T21:23:36+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:23:36 volumio go-librespot[8883]: time="2026-02-18T21:23:36+07:00" level=debug msg="app state loaded" Feb 18 21:23:36 volumio go-librespot[8883]: time="2026-02-18T21:23:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:23:36 volumio volumio[8545]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 21:23:36 volumio volumio[8545]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 21:23:36 volumio volumio[8545]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 21:23:36 volumio volumio[8545]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 21:23:36 volumio volumio[8545]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 21:23:36 volumio volumio[8545]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 21:23:36 volumio volumio[8545]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 21:23:36 volumio volumio[8545]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 21:23:36 volumio volumio[8545]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 21:23:36 volumio volumio[8545]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 21:23:36 volumio volumio[8545]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 21:23:36 volumio volumio[8545]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 21:23:36 volumio volumio[8545]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 21:23:36 volumio volumio[8545]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 21:23:36 volumio volumio[8545]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 21:23:36 volumio volumio[8545]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 21:23:36 volumio volumio[8545]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 21:23:36 volumio volumio[8545]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 21:23:36 volumio volumio[8545]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 21:23:36 volumio volumio[8545]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 21:23:36 volumio volumio[8545]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 21:23:36 volumio volumio[8545]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 21:23:36 volumio volumio[8545]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 21:23:36 volumio volumio[8545]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 21:23:36 volumio volumio[8545]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 21:23:36 volumio volumio[8545]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 21:23:36 volumio volumio[8545]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 21:23:36 volumio volumio[8545]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 21:23:36 volumio volumio[8545]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 21:23:36 volumio volumio[8545]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 21:23:36 volumio volumio[8545]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 21:23:36 volumio volumio[8545]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 21:23:36 volumio volumio[8545]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 21:23:36 volumio volumio[8545]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 21:23:36 volumio volumio[8545]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 21:23:36 volumio volumio[8545]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 21:23:36 volumio go-librespot[8883]: time="2026-02-18T21:23:36+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 21:23:36 volumio go-librespot[8883]: time="2026-02-18T21:23:36+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 21:23:36 volumio go-librespot[8883]: time="2026-02-18T21:23:36+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 21:23:36 volumio go-librespot[8883]: time="2026-02-18T21:23:36+07:00" level=info msg="zeroconf server listening on port 35139" Feb 18 21:23:36 volumio go-librespot[8883]: time="2026-02-18T21:23:36+07:00" level=debug msg="obtained new client token: AABNsp+tOj8rPFZzOAi42b7AhHzn1R9YW0QO1v5NMCv4ORyBgjbalvKQUz2YbznhKC2Fm7fItzBk7VWfz1Q3AIbriyBgqkqVfcXoOkt5tKbHAjyF8UAiV7RDjQrduyBJtTkXWnLO8TYZ0vznTVJ5enQzZxuFSryWN98ZFK8pFFkd1jmx4qiJkA95PG4r6p6r1yTiDCGQtk1EcUfWTy1NsjZb0X0fG2GLm6z0xHnqJkWq6cXn1dwihtd++g==" Feb 18 21:23:36 volumio go-librespot[8883]: time="2026-02-18T21:23:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:23:37 volumio go-librespot[8883]: time="2026-02-18T21:23:37+07:00" level=debug msg="completed keyexchange" Feb 18 21:23:37 volumio go-librespot[8883]: time="2026-02-18T21:23:37+07:00" level=debug msg="completed challenge" Feb 18 21:23:37 volumio go-librespot[8883]: time="2026-02-18T21:23:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 21:23:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:23:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:23:38 volumio volumio[8545]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 21:23:38 volumio volumio[8545]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 21:23:38 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:23:38 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:23:38 volumio volumio[8545]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 21:23:38 volumio volumio[8545]: info: MyVolumio login type: Token Feb 18 21:23:38 volumio volumio[8545]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 21:23:38 volumio volumio[8545]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 21:23:39 volumio volumio[8545]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 21:23:39 volumio volumio[8545]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 21:23:39 volumio volumio[8545]: info: Streaming services startup Feb 18 21:23:39 volumio volumio[8545]: info: Starting Streaming Daemon Feb 18 21:23:39 volumio sudo[8905]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 21:23:39 volumio sudo[8905]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:23:39 volumio volumio[8545]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 21:23:40 volumio sudo[8905]: pam_unix(sudo:session): session closed for user root Feb 18 21:23:40 volumio volumio[8545]: info: Initializing connection to go-librespot Websocket Feb 18 21:23:40 volumio volumio[8545]: error: Cannot start Volumio Streaming Daemon Feb 18 21:23:40 volumio volumio[8545]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 21:23:40 volumio volumio[8545]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 21:23:40 volumio volumio[8545]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 21:23:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 18 21:23:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:23:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:23:40 volumio go-librespot[8912]: go-librespot daemon starting... Feb 18 21:23:40 volumio go-librespot[8913]: time="2026-02-18T21:23:40+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:23:40 volumio go-librespot[8913]: time="2026-02-18T21:23:40+07:00" level=debug msg="app state loaded" Feb 18 21:23:40 volumio go-librespot[8913]: time="2026-02-18T21:23:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:23:40 volumio go-librespot[8913]: time="2026-02-18T21:23:40+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 21:23:40 volumio go-librespot[8913]: time="2026-02-18T21:23:40+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 21:23:40 volumio go-librespot[8913]: time="2026-02-18T21:23:40+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 21:23:40 volumio go-librespot[8913]: time="2026-02-18T21:23:40+07:00" level=info msg="zeroconf server listening on port 42811" Feb 18 21:23:40 volumio volumio[8545]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 18 21:23:41 volumio go-librespot[8913]: time="2026-02-18T21:23:41+07:00" level=debug msg="obtained new client token: AADtMC117leupqB4Tn0CeAcXFmGYCiM6N3YGiwRkOJHxeoroNXs09ZEz0q+/ZBAQFHUaSBUYbvG8GeRAhV+lYXNLvmzWcaz84QHEbiq0a3I5FaMe35xnmitCwFHMpa+ACE7WeujBnwiKCdUTh2BYw+vRK/wybGYBeEqkej5YnG7jBUfo/rBJXjC0NRnblY38JIf2iXU3Oz/iTKy42lXX3boUbiHEpFxUxrYBheSg/O/bVEvOfxcDTks=" Feb 18 21:23:41 volumio go-librespot[8913]: time="2026-02-18T21:23:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:23:41 volumio go-librespot[8913]: time="2026-02-18T21:23:41+07:00" level=debug msg="completed keyexchange" Feb 18 21:23:41 volumio go-librespot[8913]: time="2026-02-18T21:23:41+07:00" level=debug msg="completed challenge" Feb 18 21:23:41 volumio go-librespot[8913]: time="2026-02-18T21:23:41+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 21:23:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:23:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:23:41 volumio volumio[8545]: info: MyVolumio token set successfully Feb 18 21:23:41 volumio volumio[8545]: info: MYVOLUMIO: Adding device Feb 18 21:23:41 volumio volumio[8545]: info: MYVOLUMIO: Evaluating Server Feb 18 21:23:42 volumio volumio[8545]: info: MyVolumio status changed Feb 18 21:23:42 volumio volumio[8545]: info: Streaming services startup Feb 18 21:23:42 volumio volumio[8545]: info: Starting Streaming Daemon Feb 18 21:23:42 volumio volumio[8545]: info: Removing browser output: myVolumio user plan is not superstar Feb 18 21:23:42 volumio volumio[8545]: info: Removing audio output: Feb 18 21:23:42 volumio volumio[8545]: info: Stoppping Tunnel 1 Feb 18 21:23:42 volumio sudo[8941]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 21:23:42 volumio sudo[8941]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:23:42 volumio sudo[8941]: pam_unix(sudo:session): session closed for user root Feb 18 21:23:42 volumio sudo[8944]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 18 21:23:42 volumio sudo[8944]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:23:42 volumio volumio[8545]: error: Cannot start Volumio Streaming Daemon Feb 18 21:23:42 volumio volumio[8545]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 21:23:42 volumio volumio[8545]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 21:23:42 volumio volumio[8545]: info: Setting Geolocation for MyVolumio to as1 Feb 18 21:23:42 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:23:42 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:23:42 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:23:42 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 21:23:42 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 21:23:42 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 21:23:42 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 21:23:42 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 21:23:42 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 21:23:42 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 21:23:42 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 21:23:42 volumio sudo[8944]: pam_unix(sudo:session): session closed for user root Feb 18 21:23:42 volumio volumio[8545]: info: Remote SSH Stopped Feb 18 21:23:42 volumio volumio[8545]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 18 21:23:43 volumio volumio[8545]: info: Initializing connection to go-librespot Websocket Feb 18 21:23:43 volumio volumio[8545]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 21:23:43 volumio volumio[8545]: info: Updating MyVolumio device info Feb 18 21:23:43 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:23:43 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:23:43 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:23:44 volumio volumio[8545]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 18 21:23:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 18 21:23:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:23:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:23:44 volumio go-librespot[8947]: go-librespot daemon starting... Feb 18 21:23:44 volumio go-librespot[8948]: time="2026-02-18T21:23:44+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:23:44 volumio go-librespot[8948]: time="2026-02-18T21:23:44+07:00" level=debug msg="app state loaded" Feb 18 21:23:44 volumio go-librespot[8948]: time="2026-02-18T21:23:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:23:45 volumio go-librespot[8948]: time="2026-02-18T21:23:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 21:23:45 volumio go-librespot[8948]: time="2026-02-18T21:23:45+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 21:23:45 volumio go-librespot[8948]: time="2026-02-18T21:23:45+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 21:23:45 volumio go-librespot[8948]: time="2026-02-18T21:23:45+07:00" level=info msg="zeroconf server listening on port 39725" Feb 18 21:23:45 volumio go-librespot[8948]: time="2026-02-18T21:23:45+07:00" level=debug msg="obtained new client token: AACzlPy33i+rC9yWNqbe6Q7lIq4eQIn63ihKNROaS9BaqFJFjX5Wtg5mfcLvYnw4bN6AbPFexoQY3QVHjAB8NL+hCGWMMEh7l9By3VgPVIO/ND9hbrUZ8GGQSUpwD0H5JA8wdndJbzBQoGXWUmimq5QPPIgo/SuGC36aIP2q1FLfubSuCeBiTSYFu6qjCTxUfIy6d7ht+Ns1fEMyF8RDP0oWUjMCdvoM+NrtMhcEW0BfMsEg5h0S2zQ7Bg==" Feb 18 21:23:45 volumio go-librespot[8948]: time="2026-02-18T21:23:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:23:45 volumio go-librespot[8948]: time="2026-02-18T21:23:45+07:00" level=debug msg="completed keyexchange" Feb 18 21:23:45 volumio go-librespot[8948]: time="2026-02-18T21:23:45+07:00" level=debug msg="completed challenge" Feb 18 21:23:45 volumio go-librespot[8948]: time="2026-02-18T21:23:45+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 21:23:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:23:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:23:46 volumio volumio[8545]: info: Initializing connection to go-librespot Websocket Feb 18 21:23:46 volumio volumio[8545]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 21:23:46 volumio volumio[8545]: info: MYVOLUMIO: Adding device Feb 18 21:23:46 volumio volumio[8545]: info: MYVOLUMIO: Evaluating Server Feb 18 21:23:47 volumio volumio[8545]: info: Setting Geolocation for MyVolumio to as1 Feb 18 21:23:47 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:23:47 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:23:47 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:23:48 volumio volumio[8545]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 18 21:23:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 18 21:23:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:23:48 volumio volumio[8545]: info: Updating MyVolumio device info Feb 18 21:23:48 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:23:48 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:23:48 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:23:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:23:48 volumio go-librespot[8987]: go-librespot daemon starting... Feb 18 21:23:48 volumio go-librespot[8988]: time="2026-02-18T21:23:48+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:23:48 volumio go-librespot[8988]: time="2026-02-18T21:23:48+07:00" level=debug msg="app state loaded" Feb 18 21:23:48 volumio go-librespot[8988]: time="2026-02-18T21:23:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:23:49 volumio volumio[8545]: info: Initializing connection to go-librespot Websocket Feb 18 21:23:49 volumio go-librespot[8988]: time="2026-02-18T21:23:49+07:00" level=debug msg="new websocket client" Feb 18 21:23:49 volumio volumio[8545]: info: Connection to go-librespot Websocket established Feb 18 21:23:49 volumio volumio[8545]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 18 21:23:49 volumio go-librespot[8988]: time="2026-02-18T21:23:49+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 21:23:49 volumio go-librespot[8988]: time="2026-02-18T21:23:49+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 21:23:49 volumio go-librespot[8988]: time="2026-02-18T21:23:49+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 21:23:49 volumio go-librespot[8988]: time="2026-02-18T21:23:49+07:00" level=info msg="zeroconf server listening on port 43829" Feb 18 21:23:49 volumio go-librespot[8988]: time="2026-02-18T21:23:49+07:00" level=debug msg="obtained new client token: AAC7e9nG5pBbTeORrqc6h6sWMRCFfarmCsmKAWJ2MdmDnhgRlrewZqq2/kkMEmQF13AmGxlvjqIa11gLwgvdqkNyJN7xUWpq+MUY4jW5yhdxjmF5WZ0QZfl1TZxul2I9vW29ErWDiZ7HOl2IdItw5E0aZXCyrWndFRmaySwkOnyU3QKEbWn3ZgrOhz9eHhhd5vBmBS56lAToDQlxufSMySitOfx0k3j/oaGwFjIcwt1qwwghsPyXUXYWSA==" Feb 18 21:23:49 volumio go-librespot[8988]: time="2026-02-18T21:23:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:23:49 volumio go-librespot[8988]: time="2026-02-18T21:23:49+07:00" level=debug msg="completed keyexchange" Feb 18 21:23:49 volumio go-librespot[8988]: time="2026-02-18T21:23:49+07:00" level=debug msg="completed challenge" Feb 18 21:23:49 volumio go-librespot[8988]: time="2026-02-18T21:23:49+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 21:23:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:23:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:23:49 volumio volumio[8545]: info: Connection to go-librespot Websocket closed Feb 18 21:23:51 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 21:23:51 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:23:51 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 18 21:23:51 volumio volumio-remote-updater[25144]: Test mode disabled Feb 18 21:23:51 volumio volumio-remote-updater[25144]: Alpha mode disabled Feb 18 21:23:51 volumio volumio-remote-updater[25144]: Alpha legacy test mode disabled Feb 18 21:23:51 volumio volumio[8545]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Feb 18 21:23:52 volumio volumio[8545]: info: Getting Spotify volume Feb 18 21:23:52 volumio volumio[8545]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 21:23:52 volumio volumio[8545]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 21:23:52 volumio volumio[8545]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 18 21:23:52 volumio volumio[8545]: errno: -111, Feb 18 21:23:52 volumio volumio[8545]: code: 'ECONNREFUSED', Feb 18 21:23:52 volumio volumio[8545]: syscall: 'connect', Feb 18 21:23:52 volumio volumio[8545]: address: '127.0.0.1', Feb 18 21:23:52 volumio volumio[8545]: port: 9879, Feb 18 21:23:52 volumio volumio[8545]: response: undefined Feb 18 21:23:52 volumio volumio[8545]: } Feb 18 21:23:52 volumio volumio[8545]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 21:23:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 18 21:23:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:23:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:23:53 volumio go-librespot[9011]: go-librespot daemon starting... Feb 18 21:23:53 volumio go-librespot[9012]: time="2026-02-18T21:23:53+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:23:53 volumio go-librespot[9012]: time="2026-02-18T21:23:53+07:00" level=debug msg="app state loaded" Feb 18 21:23:53 volumio go-librespot[9012]: time="2026-02-18T21:23:53+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:23:53 volumio go-librespot[9012]: time="2026-02-18T21:23:53+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 21:23:53 volumio go-librespot[9012]: time="2026-02-18T21:23:53+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 21:23:53 volumio go-librespot[9012]: time="2026-02-18T21:23:53+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 21:23:53 volumio go-librespot[9012]: time="2026-02-18T21:23:53+07:00" level=info msg="zeroconf server listening on port 36679" Feb 18 21:23:53 volumio sudo[9022]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 21:22' Feb 18 21:23:53 volumio sudo[9022]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) 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"