Feb 25 03:47:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 25 03:47:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:00 volumio go-librespot[4256]: go-librespot daemon starting... Feb 25 03:47:00 volumio go-librespot[4257]: time="2026-02-25T03:47:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:47:00 volumio go-librespot[4257]: time="2026-02-25T03:47:00+07:00" level=debug msg="app state loaded" Feb 25 03:47:00 volumio go-librespot[4257]: time="2026-02-25T03:47:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:47:01 volumio go-librespot[4257]: time="2026-02-25T03:47:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 03:47:01 volumio go-librespot[4257]: time="2026-02-25T03:47:01+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 25 03:47:01 volumio go-librespot[4257]: time="2026-02-25T03:47:01+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 25 03:47:01 volumio go-librespot[4257]: time="2026-02-25T03:47:01+07:00" level=info msg="zeroconf server listening on port 33585" Feb 25 03:47:01 volumio go-librespot[4257]: time="2026-02-25T03:47:01+07:00" level=debug msg="obtained new client token: AACOn0P2/ffX6WhhX9QJT51v5zZyc+vhp4iTmgMWNNGALx4S8ILgUfwNOg8iih4Z1EPXbcSyLpaIeZOm4yTI8gACmYM4nQAK/PVrPgjGOqg+WNUj/rxNtG2Z+o2riZJw+zsoUj5oVn7Csu/zHt30D+w56wGZaIG1ohbueaVTGVKsiZ1FE8rlTpwuOdp9OTPXmhkUScExRvyteOfQHQBbWGjUQlOPudc7J3Ji9BI7atURTV9tYcme92s/MA==" Feb 25 03:47:01 volumio go-librespot[4257]: time="2026-02-25T03:47:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:47:01 volumio go-librespot[4257]: time="2026-02-25T03:47:01+07:00" level=debug msg="completed keyexchange" Feb 25 03:47:01 volumio go-librespot[4257]: time="2026-02-25T03:47:01+07:00" level=debug msg="completed challenge" Feb 25 03:47:01 volumio volumio[3927]: info: Initializing connection to go-librespot Websocket Feb 25 03:47:01 volumio go-librespot[4257]: time="2026-02-25T03:47:01+07:00" level=debug msg="new websocket client" Feb 25 03:47:01 volumio volumio[3927]: info: Connection to go-librespot Websocket established Feb 25 03:47:02 volumio go-librespot[4257]: time="2026-02-25T03:47: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 25 03:47:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:47:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:47:02 volumio volumio[3927]: info: Connection to go-librespot Websocket closed Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 25 03:47:04 volumio volumio[3927]: info: Adding plugin bluetooth to MyMusic Plugins Feb 25 03:47:04 volumio volumio[3927]: info: Adding plugin multiroom to MyMusic Plugins Feb 25 03:47:04 volumio volumio[3927]: info: Adding plugin metavolumio to MyMusic Plugins Feb 25 03:47:04 volumio volumio[3927]: info: Adding plugin cd_controller to MyMusic Plugins Feb 25 03:47:04 volumio volumio[3927]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 25 03:47:04 volumio volumio[3927]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 25 03:47:04 volumio volumio[3927]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 25 03:47:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 25 03:47:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:05 volumio go-librespot[4281]: go-librespot daemon starting... Feb 25 03:47:05 volumio go-librespot[4282]: time="2026-02-25T03:47:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:47:05 volumio go-librespot[4282]: time="2026-02-25T03:47:05+07:00" level=debug msg="app state loaded" Feb 25 03:47:05 volumio go-librespot[4282]: time="2026-02-25T03:47:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:47:05 volumio go-librespot[4282]: time="2026-02-25T03:47:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 03:47:05 volumio go-librespot[4282]: time="2026-02-25T03:47:05+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 25 03:47:05 volumio go-librespot[4282]: time="2026-02-25T03:47:05+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 25 03:47:05 volumio go-librespot[4282]: time="2026-02-25T03:47:05+07:00" level=info msg="zeroconf server listening on port 40341" Feb 25 03:47:06 volumio go-librespot[4282]: time="2026-02-25T03:47:06+07:00" level=debug msg="obtained new client token: AAAQLBIb7FfEXhd1WLzu/6IKc9zbAi3D718M7YHjbMn5pr8TM0pvJjmizQaPsqTlRUYDAXZcMS34IokU4qybUJGb1oOloYcVLWORPTbqPItXN1g5zYq8Am5b8IfOFVmJfGIdSYJbzoukBQ9bVA7383wKrzNmjhAAc17VdGOvkf3TN6USJreUGDzDxVi7bEPhfA+33uQOwpEzwqG7ir71/HZpg+1fXqAcm2ZquSwZuf0nfVqFBk0uZennlg==" Feb 25 03:47:06 volumio go-librespot[4282]: time="2026-02-25T03:47:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:47:06 volumio go-librespot[4282]: time="2026-02-25T03:47:06+07:00" level=debug msg="completed keyexchange" Feb 25 03:47:06 volumio go-librespot[4282]: time="2026-02-25T03:47:06+07:00" level=debug msg="completed challenge" Feb 25 03:47:06 volumio go-librespot[4282]: time="2026-02-25T03:47: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 25 03:47:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:47:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:47:06 volumio volumio[3927]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 25 03:47:06 volumio volumio[3927]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 25 03:47:06 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:47:06 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:47:06 volumio volumio[3927]: info: Starting MyVolumio Remote Streaming Endpoints Feb 25 03:47:06 volumio volumio[3927]: info: MyVolumio login type: Token Feb 25 03:47:06 volumio volumio[3927]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 25 03:47:06 volumio volumio[3927]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 25 03:47:08 volumio volumio[3927]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 25 03:47:08 volumio volumio[3927]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 25 03:47:08 volumio volumio[3927]: info: Streaming services startup Feb 25 03:47:08 volumio volumio[3927]: info: Starting Streaming Daemon Feb 25 03:47:08 volumio sudo[4292]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 25 03:47:08 volumio sudo[4292]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:08 volumio volumio[3927]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 25 03:47:08 volumio sudo[4292]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:08 volumio volumio[3927]: info: Getting Spotify volume Feb 25 03:47:08 volumio volumio[3927]: info: Initializing connection to go-librespot Websocket Feb 25 03:47:08 volumio volumio[3927]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 25 03:47:08 volumio volumio[3927]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 03:47:08 volumio volumio[3927]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 25 03:47:08 volumio volumio[3927]: errno: -111, Feb 25 03:47:08 volumio volumio[3927]: code: 'ECONNREFUSED', Feb 25 03:47:08 volumio volumio[3927]: syscall: 'connect', Feb 25 03:47:08 volumio volumio[3927]: address: '127.0.0.1', Feb 25 03:47:08 volumio volumio[3927]: port: 9879, Feb 25 03:47:08 volumio volumio[3927]: response: undefined Feb 25 03:47:08 volumio volumio[3927]: } Feb 25 03:47:08 volumio volumio[3927]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 25 03:47:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 25 03:47:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:09 volumio go-librespot[4310]: go-librespot daemon starting... Feb 25 03:47:09 volumio go-librespot[4311]: time="2026-02-25T03:47:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:47:09 volumio go-librespot[4311]: time="2026-02-25T03:47:09+07:00" level=debug msg="app state loaded" Feb 25 03:47:09 volumio go-librespot[4311]: time="2026-02-25T03:47:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:47:10 volumio sudo[4320]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-25 03:46' Feb 25 03:47:10 volumio sudo[4320]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:10 volumio go-librespot[4311]: time="2026-02-25T03:47:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 03:47:10 volumio go-librespot[4311]: time="2026-02-25T03:47:10+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 25 03:47:10 volumio go-librespot[4311]: time="2026-02-25T03:47:10+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 25 03:47:10 volumio go-librespot[4311]: time="2026-02-25T03:47:10+07:00" level=info msg="zeroconf server listening on port 46263" Feb 25 03:47:10 volumio sudo[4320]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:10 volumio go-librespot[4311]: time="2026-02-25T03:47:10+07:00" level=debug msg="obtained new client token: AADGKMqkeRyUIiS3l+jFsdGXshQSapy4VkQFTGQ09+2EI+RO/+17HGfGlTO33arGkSayNEyDdyzBaDirHxdBCA1CdzTTaUWWhUL6uf9NiAfsAFNvjxbvFkQI0LHiHQQ6WLdgdBzyafsDGOu0F0JZTbDFyMAF4BFhZDTmOs+apXwAfJzbtQBCndEs90uevsfNFDJmOtvc8YdguxqQzJ/oHwRz59a5CQAqZ5+amuYEDV9jDh5W7ZncewXynQ==" Feb 25 03:47:10 volumio volumio-remote-updater[647]: [2026-02-25 03:47:10] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 25 03:47:10 volumio volumio-remote-updater[647]: [2026-02-25 03:47:10] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 25 03:47:10 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:47:10 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 25 03:47:10 volumio systemd[1]: volumio.service: Consumed 54.054s CPU time. Feb 25 03:47:10 volumio go-librespot[4311]: time="2026-02-25T03:47:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:47:10 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 25 03:47:10 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 25 03:47:10 volumio go-librespot[4311]: time="2026-02-25T03:47:10+07:00" level=debug msg="completed keyexchange" Feb 25 03:47:10 volumio go-librespot[4311]: time="2026-02-25T03:47:10+07:00" level=debug msg="completed challenge" Feb 25 03:47:10 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 7501. Feb 25 03:47:10 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 25 03:47:10 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 25 03:47:10 volumio systemd[1]: volumio.service: Consumed 54.054s CPU time. Feb 25 03:47:10 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 25 03:47:10 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 25 03:47:10 volumio go-librespot[4311]: time="2026-02-25T03:47: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 25 03:47:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:47:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:47:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 25 03:47:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:14 volumio go-librespot[4349]: go-librespot daemon starting... Feb 25 03:47:14 volumio go-librespot[4350]: time="2026-02-25T03:47:14+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:47:14 volumio go-librespot[4350]: time="2026-02-25T03:47:14+07:00" level=debug msg="app state loaded" Feb 25 03:47:14 volumio go-librespot[4350]: time="2026-02-25T03:47:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:47:14 volumio volumio[4333]: info: ------------------------------------------- Feb 25 03:47:14 volumio volumio[4333]: info: ----- Volumio3 ---- Feb 25 03:47:14 volumio volumio[4333]: info: ------------------------------------------- Feb 25 03:47:14 volumio volumio[4333]: info: ----- System startup ---- Feb 25 03:47:14 volumio volumio[4333]: info: ------------------------------------------- Feb 25 03:47:14 volumio go-librespot[4350]: time="2026-02-25T03:47: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 03:47:14 volumio go-librespot[4350]: time="2026-02-25T03:47:14+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 25 03:47:14 volumio go-librespot[4350]: time="2026-02-25T03:47:14+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 25 03:47:14 volumio go-librespot[4350]: time="2026-02-25T03:47:14+07:00" level=info msg="zeroconf server listening on port 44469" Feb 25 03:47:15 volumio go-librespot[4350]: time="2026-02-25T03:47:15+07:00" level=debug msg="obtained new client token: AAABhRDk6lKn8dU/715o7IJwA1+ht8A3xBQ2eESPTectYW8dM+LUJcdoF+Y/iDLtwdFR13Sn4bekNnTUsQjTtzAsWX4mNVoQHkUmgpnDYAlz1Zqt2IK57o7vY6wXxAcok470juhCwHG71X4GmZcCdHuOMyTe6vbRWxVYay54T83x+JrMhTnqaYrJ9I03ZUlxMrJR0A1cT5iWTLDOQMneDSngdubAQVPPsg7YcErM62SVtObhtqhQjlmSaA==" Feb 25 03:47:15 volumio go-librespot[4350]: time="2026-02-25T03:47:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:47:15 volumio go-librespot[4350]: time="2026-02-25T03:47:15+07:00" level=debug msg="completed keyexchange" Feb 25 03:47:15 volumio go-librespot[4350]: time="2026-02-25T03:47:15+07:00" level=debug msg="completed challenge" Feb 25 03:47:15 volumio go-librespot[4350]: time="2026-02-25T03:47: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 25 03:47:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:47:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:47:15 volumio volumio-remote-updater[647]: [2026-02-25 03:47:15] [connect] Successful connection Feb 25 03:47:15 volumio volumio[4333]: info: MYVOLUMIO Environment detected Feb 25 03:47:16 volumio volumio[4333]: info: Plugin folders cleanup Feb 25 03:47:16 volumio volumio[4333]: info: Scanning into folder /volumio/app/plugins/ Feb 25 03:47:16 volumio volumio[4333]: info: Scanning category audio_interface Feb 25 03:47:16 volumio volumio[4333]: info: Scanning category miscellanea Feb 25 03:47:16 volumio volumio[4333]: info: Scanning category music_service Feb 25 03:47:16 volumio volumio[4333]: info: Scanning category plugins.json Feb 25 03:47:16 volumio volumio[4333]: info: Scanning category system_controller Feb 25 03:47:16 volumio volumio[4333]: info: Scanning category user_interface Feb 25 03:47:16 volumio volumio[4333]: info: Scanning into folder /data/plugins/ Feb 25 03:47:16 volumio volumio[4333]: info: Scanning category music_service Feb 25 03:47:16 volumio volumio[4333]: info: Plugin folders cleanup completed Feb 25 03:47:16 volumio volumio[4333]: info: ------------------------------------------- Feb 25 03:47:16 volumio volumio[4333]: info: ----- Core plugins startup ---- Feb 25 03:47:16 volumio volumio[4333]: info: ------------------------------------------- Feb 25 03:47:16 volumio volumio[4333]: info: Loading plugins from folder /volumio/app/plugins/ Feb 25 03:47:16 volumio volumio[4333]: info: Adding plugin upnp to MyMusic Plugins Feb 25 03:47:16 volumio volumio[4333]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 25 03:47:16 volumio volumio[4333]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 25 03:47:16 volumio volumio[4333]: info: Loading plugins from folder /data/plugins/ Feb 25 03:47:16 volumio volumio[4333]: info: Loading plugin "system"... Feb 25 03:47:16 volumio volumio[4333]: info: Loading plugin "appearance"... Feb 25 03:47:18 volumio volumio[4333]: info: Loading plugin "network"... Feb 25 03:47:18 volumio volumio[4333]: info: Refreshing Cached IP Addresses Feb 25 03:47:18 volumio sudo[4370]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 25 03:47:18 volumio sudo[4370]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:18 volumio sudo[4372]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 25 03:47:18 volumio sudo[4372]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:18 volumio sudo[4370]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:18 volumio sudo[4372]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:18 volumio volumio[4333]: info: Loading plugin "services"... Feb 25 03:47:18 volumio volumio[4333]: info: Loading plugin "alsa_controller"... Feb 25 03:47:18 volumio sudo[4380]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 25 03:47:18 volumio sudo[4380]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:18 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 25 03:47:18 volumio volumio[4333]: info: Loading plugin "wizard"... Feb 25 03:47:18 volumio volumio[4333]: info: Loading plugin "networkfs"... Feb 25 03:47:18 volumio volumio[4333]: info: Starting Udev Watcher for removable devices Feb 25 03:47:18 volumio volumio[4333]: info: Ignoring mount for partition: boot Feb 25 03:47:18 volumio volumio[4333]: info: Ignoring mount for partition: volumio Feb 25 03:47:18 volumio volumio[4333]: info: Ignoring mount for partition: volumio_data Feb 25 03:47:18 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 25 03:47:18 volumio volumio[4333]: info: Loading plugin "volumio_command_line_client"... Feb 25 03:47:18 volumio volumio[4333]: info: Loading plugin "upnp"... Feb 25 03:47:18 volumio volumio[4333]: info: [1771966038494] Starting Upmpd Daemon Feb 25 03:47:18 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 25 03:47:18 volumio volumio[4333]: info: Loading plugin "my_music"... Feb 25 03:47:18 volumio volumio[4333]: info: Loading plugin "mpd"... Feb 25 03:47:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 25 03:47:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:18 volumio go-librespot[4403]: go-librespot daemon starting... Feb 25 03:47:18 volumio go-librespot[4404]: time="2026-02-25T03:47:18+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:47:18 volumio go-librespot[4404]: time="2026-02-25T03:47:18+07:00" level=debug msg="app state loaded" Feb 25 03:47:18 volumio go-librespot[4404]: time="2026-02-25T03:47:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:47:19 volumio volumio[4333]: info: Loading plugin "upnp_browser"... Feb 25 03:47:19 volumio go-librespot[4404]: time="2026-02-25T03:47:19+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 03:47:19 volumio go-librespot[4404]: time="2026-02-25T03:47:19+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 25 03:47:19 volumio go-librespot[4404]: time="2026-02-25T03:47:19+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 25 03:47:19 volumio go-librespot[4404]: time="2026-02-25T03:47:19+07:00" level=info msg="zeroconf server listening on port 42253" Feb 25 03:47:19 volumio go-librespot[4404]: time="2026-02-25T03:47:19+07:00" level=debug msg="obtained new client token: AACny18JRlM/BuvzY0SS/z39fZRfohurF3NyuYeULVJYwlg26BHweH6ZxEJJGsjA9826IjYU55DUzXDxCwzyjclTe6jSHu44FN3SWs+zKVYNXOMOIVoalMIjwceTUH7FzEnoJTnf43koPZu3nMSiqoB0/h1gEaz2m6ad/JlYInHbbkSTcDMaTZrde7FAZfLBRSy9lepyNPtkl6lLAIggwuPvl9Jn/NdrcWOV3u+O+zejY0V3BBDLo8LAOg==" Feb 25 03:47:19 volumio go-librespot[4404]: time="2026-02-25T03:47:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:47:19 volumio go-librespot[4404]: time="2026-02-25T03:47:19+07:00" level=debug msg="completed keyexchange" Feb 25 03:47:19 volumio go-librespot[4404]: time="2026-02-25T03:47:19+07:00" level=debug msg="completed challenge" Feb 25 03:47:19 volumio go-librespot[4404]: time="2026-02-25T03:47: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 25 03:47:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:47:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:47:20 volumio sudo[4380]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:22 volumio volumio[4333]: info: Starting UPNP Browser Feb 25 03:47:22 volumio volumio[4333]: info: Loading plugin "alarm-clock"... Feb 25 03:47:22 volumio volumio[4333]: info: Loading plugin "airplay_emulation"... Feb 25 03:47:22 volumio volumio[4333]: info: Starting Shairport Sync Feb 25 03:47:22 volumio volumio[4333]: info: Loading plugin "last_100"... Feb 25 03:47:22 volumio volumio[4333]: info: Loading plugin "webradio"... Feb 25 03:47:22 volumio volumio[4333]: info: Loading plugin "i2s_dacs"... Feb 25 03:47:22 volumio volumio[4333]: info: Loading plugin "volumiodiscovery"... Feb 25 03:47:22 volumio volumio[4333]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 25 03:47:22 volumio volumio[4333]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 25 03:47:22 volumio volumio[4333]: *** WARNING *** For more information see Feb 25 03:47:22 volumio volumio[4333]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 25 03:47:22 volumio volumio[4333]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 25 03:47:22 volumio volumio[4333]: *** WARNING *** For more information see Feb 25 03:47:22 volumio node[4333]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 25 03:47:22 volumio node[4333]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 25 03:47:22 volumio node[4333]: *** WARNING *** For more information see Feb 25 03:47:22 volumio node[4333]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 25 03:47:22 volumio node[4333]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 25 03:47:22 volumio node[4333]: *** WARNING *** For more information see Feb 25 03:47:22 volumio volumio[4333]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 25 03:47:22 volumio volumio[4333]: info: Discovery: Started advertising with name: Volumio Feb 25 03:47:22 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 25 03:47:22 volumio volumio[4333]: info: Loading plugin "spop"... Feb 25 03:47:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 25 03:47:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:23 volumio go-librespot[4413]: go-librespot daemon starting... Feb 25 03:47:23 volumio go-librespot[4414]: time="2026-02-25T03:47:23+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:47:23 volumio go-librespot[4414]: time="2026-02-25T03:47:23+07:00" level=debug msg="app state loaded" Feb 25 03:47:23 volumio go-librespot[4414]: time="2026-02-25T03:47:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:47:23 volumio go-librespot[4414]: time="2026-02-25T03:47: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 25 03:47:23 volumio go-librespot[4414]: time="2026-02-25T03:47: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 25 03:47:23 volumio go-librespot[4414]: time="2026-02-25T03:47: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 25 03:47:23 volumio go-librespot[4414]: time="2026-02-25T03:47:23+07:00" level=info msg="zeroconf server listening on port 43301" Feb 25 03:47:24 volumio go-librespot[4414]: time="2026-02-25T03:47:24+07:00" level=debug msg="obtained new client token: AACm7gVDAlx7vBXkmiZEUo+CUnCOzphu9+ProjUh3S1EoxA+RS6HReP8jLxHpDNaRmP87JdS0bdj5ZiCgo3zvgU++G9iBeVHPUtF0COe2n2X07i1/DVytADQLwBePF7jO6p4evxHz3FpZENJYK5ueHjNNh/G6wHYWkqYPMNPun8aWdtagKn3p4glYpt10TGBIZ0uEh6bSETSjtsTv5B1334bA1Uy2shiWZ92y8JrFVPXjbCt8N0otaY=" Feb 25 03:47:24 volumio go-librespot[4414]: time="2026-02-25T03:47:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:47:24 volumio go-librespot[4414]: time="2026-02-25T03:47:24+07:00" level=debug msg="completed keyexchange" Feb 25 03:47:24 volumio go-librespot[4414]: time="2026-02-25T03:47:24+07:00" level=debug msg="completed challenge" Feb 25 03:47:24 volumio go-librespot[4414]: time="2026-02-25T03:47: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 25 03:47:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:47:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:47:24 volumio volumio[4333]: info: Loading plugin "ytcr"... Feb 25 03:47:27 volumio volumio[4333]: info: Loading plugin "ytmusic"... Feb 25 03:47:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Feb 25 03:47:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:27 volumio go-librespot[4421]: go-librespot daemon starting... Feb 25 03:47:27 volumio go-librespot[4422]: time="2026-02-25T03:47:27+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:47:27 volumio go-librespot[4422]: time="2026-02-25T03:47:27+07:00" level=debug msg="app state loaded" Feb 25 03:47:27 volumio go-librespot[4422]: time="2026-02-25T03:47:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:47:28 volumio volumio-remote-updater[647]: [2026-02-25 03:47:28] [connect] Successful connection Feb 25 03:47:28 volumio go-librespot[4422]: time="2026-02-25T03:47: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 03:47:28 volumio go-librespot[4422]: time="2026-02-25T03:47:28+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 25 03:47:28 volumio go-librespot[4422]: time="2026-02-25T03:47:28+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 25 03:47:28 volumio go-librespot[4422]: time="2026-02-25T03:47:28+07:00" level=info msg="zeroconf server listening on port 33269" Feb 25 03:47:28 volumio go-librespot[4422]: time="2026-02-25T03:47:28+07:00" level=debug msg="obtained new client token: AABzsASRxVxNNgQeTFCFDDa+AjbXEo3Y5CyWnHIjlZsXlkHd3l91mi0hKGIMPB8oQ2SrdTJ5LF54pXJS4StPmz3oEuLJNfHECbUHcLTVJxUuX16/OAI1TnBnAo8k2jaC2p1ueWTZ9gsQvtiWoaP1+T0X8r5h+Js/4RJ5s6AFlRCh3igCMs/REhBlPU4/8k40CPk0YsV23yAVw99e1e/j5r7lAjp+b9EMDnIpXAf+OyvMwCi7/dMUut9xAA==" Feb 25 03:47:28 volumio volumio[4333]: info: Loading plugin "outputs"... Feb 25 03:47:28 volumio go-librespot[4422]: time="2026-02-25T03:47:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:47:28 volumio volumio[4333]: info: Loading plugin "albumart"... Feb 25 03:47:28 volumio volumio[4333]: info: Plugin example_plugin is not enabled Feb 25 03:47:28 volumio volumio[4333]: info: Loading plugin "inputs"... Feb 25 03:47:28 volumio volumio[4333]: info: Loading plugin "updater_comm"... Feb 25 03:47:28 volumio go-librespot[4422]: time="2026-02-25T03:47:28+07:00" level=debug msg="completed keyexchange" Feb 25 03:47:28 volumio go-librespot[4422]: time="2026-02-25T03:47:28+07:00" level=debug msg="completed challenge" Feb 25 03:47:28 volumio go-librespot[4422]: time="2026-02-25T03:47: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 25 03:47:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:47:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:47:28 volumio volumio[4333]: info: Plugin mpdemulation is not enabled Feb 25 03:47:28 volumio volumio[4333]: info: Loading plugin "rest_api"... Feb 25 03:47:28 volumio volumio[4333]: info: Loading plugin "websocket"... Feb 25 03:47:29 volumio volumio[4333]: info: Starting Socket.io Server version 1.7.4 Feb 25 03:47:29 volumio volumio[4333]: info: Loading plugin "RoonBridge"... Feb 25 03:47:29 volumio volumio[4333]: info: Applying required configuration parameters for plugin RoonBridge Feb 25 03:47:29 volumio volumio[4333]: info: Loading i18n strings for locale en Feb 25 03:47:29 volumio volumio[4333]: Updating browse sources language Feb 25 03:47:29 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 03:47:29 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 03:47:29 volumio volumio[4333]: info: CoreCommandRouter::initPlayerControls Feb 25 03:47:29 volumio volumio[4443]: Forking 3 albumart workers Feb 25 03:47:29 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:29 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:29 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:29 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:29 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:29 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:29 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:29 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:29 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 03:47:29 volumio volumio[4333]: Express server listening on port 3000 Feb 25 03:47:29 volumio volumio[4333]: [Metrics] WebUI: 16s 454.21ms Feb 25 03:47:29 volumio volumio[4333]: info: CoreStateMachine::resetVolumioState Feb 25 03:47:29 volumio volumio[4333]: info: CoreStateMachine::getcurrentVolume Feb 25 03:47:30 volumio volumio[4333]: info: CoreCommandRouter::volumioRetrievevolume Feb 25 03:47:30 volumio sudo[4487]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 25 03:47:30 volumio sudo[4485]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 25 03:47:30 volumio sudo[4485]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:30 volumio sudo[4485]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:30 volumio sudo[4487]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:30 volumio sudo[4487]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:30 volumio volumio[4333]: info: Volumio Network Manager: Network status updated: 1 Feb 25 03:47:30 volumio volumio[4333]: info: VolumeController:: Volume=100 Mute =false Feb 25 03:47:30 volumio volumio[4333]: info: CoreStateMachine::pushState Feb 25 03:47:30 volumio volumio[4333]: info: CorePlayQueue::getTrack 0 Feb 25 03:47:30 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 03:47:30 volumio volumio[4333]: info: CoreCommandRouter::volumioPushState Feb 25 03:47:30 volumio volumio[4333]: info: CoreStateMachine::updateTrackBlock Feb 25 03:47:30 volumio volumio[4333]: info: CorePlayQueue::getTrackBlock Feb 25 03:47:30 volumio volumio[4333]: info: CoreCommandRouter::volumioRetrievevolume Feb 25 03:47:30 volumio volumio-remote-updater[647]: [2026-02-25 03:47:30] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771966048 101 Feb 25 03:47:30 volumio volumio[4333]: 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 25 03:47:30 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:47:30 volumio volumio[4333]: info: Reloading queue from file Feb 25 03:47:30 volumio volumio[4333]: info: CoreStateMachine::setRepeat null single undefined Feb 25 03:47:30 volumio volumio[4333]: info: CoreStateMachine::pushState Feb 25 03:47:30 volumio volumio[4333]: info: CorePlayQueue::getTrack 0 Feb 25 03:47:31 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 03:47:31 volumio volumio[4333]: info: CoreCommandRouter::volumioPushState Feb 25 03:47:31 volumio volumio[4333]: info: CoreStateMachine::setRandom null Feb 25 03:47:31 volumio volumio[4333]: info: CoreStateMachine::pushState Feb 25 03:47:31 volumio volumio[4333]: info: CorePlayQueue::getTrack 0 Feb 25 03:47:31 volumio volumio[4333]: info: CoreCommandRouter::volumioPushState Feb 25 03:47:31 volumio volumio[4333]: info: Setting Device type: Raspberry PI Feb 25 03:47:31 volumio volumio[4333]: info: Completed loading Core Plugins Feb 25 03:47:31 volumio volumio[4333]: info: Preparing to generate the ALSA configuration file Feb 25 03:47:31 volumio volumio[4333]: info: VolumeController:: Volume=100 Mute =false Feb 25 03:47:31 volumio volumio[4333]: info: CoreStateMachine::pushState Feb 25 03:47:31 volumio volumio[4333]: info: CorePlayQueue::getTrack 0 Feb 25 03:47:31 volumio volumio[4333]: info: CoreCommandRouter::volumioPushState Feb 25 03:47:31 volumio volumio[4333]: info: Asound.conf file unchanged, so no further update is needed Feb 25 03:47:31 volumio volumio[4333]: info: Output device has changed, restarting MPD Feb 25 03:47:31 volumio volumio[4333]: info: Output device has changed, restarting Shairport Sync Feb 25 03:47:31 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:31 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:47:31 volumio sudo[4505]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 25 03:47:31 volumio sudo[4505]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:31 volumio sudo[4507]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 25 03:47:31 volumio sudo[4507]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:31 volumio sudo[4507]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:31 volumio sudo[4509]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 25 03:47:31 volumio sudo[4509]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:31 volumio volumio[4333]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 25 03:47:31 volumio volumio[4333]: info: ___________ START PLUGINS ___________ Feb 25 03:47:31 volumio volumio[4333]: info: ControllerMpd::onStart: Initializing MPD Feb 25 03:47:31 volumio volumio[4333]: info: Creating MPD Configuration file Feb 25 03:47:31 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 25 03:47:31 volumio sudo[4505]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:31 volumio sudo[4519]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 25 03:47:31 volumio sudo[4519]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:31 volumio sudo[4519]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:31 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 03:47:31 volumio volumio[4333]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 03:47:31 volumio volumio[4333]: info: [1771966051660] CoreMusicLibrary::Adding element Media Servers Feb 25 03:47:31 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 03:47:31 volumio volumio[4333]: info: UPNP Browser: Client initialized successfully Feb 25 03:47:31 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 25 03:47:31 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 25 03:47:31 volumio systemd[1]: mpd.service: Consumed 6.964s CPU time. Feb 25 03:47:31 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 25 03:47:31 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 25 03:47:31 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 25 03:47:31 volumio sudo[4520]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 25 03:47:31 volumio sudo[4520]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:31 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:31 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:47:31 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 25 03:47:31 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 25 03:47:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Feb 25 03:47:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:31 volumio go-librespot[4529]: go-librespot daemon starting... Feb 25 03:47:31 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 25 03:47:31 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 25 03:47:32 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 25 03:47:32 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 25 03:47:32 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 25 03:47:32 volumio volumio[4333]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 25 03:47:32 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:32 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:47:32 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 25 03:47:32 volumio go-librespot[4530]: time="2026-02-25T03:47:32+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:47:32 volumio go-librespot[4530]: time="2026-02-25T03:47:32+07:00" level=debug msg="app state loaded" Feb 25 03:47:32 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 25 03:47:32 volumio go-librespot[4530]: time="2026-02-25T03:47:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:47:32 volumio volumio[4333]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 25 03:47:32 volumio volumio[4333]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 03:47:32 volumio volumio[4333]: info: [1771966052200] CoreMusicLibrary::Adding element Last_100 Feb 25 03:47:32 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 03:47:32 volumio volumio[4333]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 03:47:32 volumio volumio[4333]: info: [1771966052228] CoreMusicLibrary::Adding element Webradio Feb 25 03:47:32 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 03:47:32 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 25 03:47:32 volumio volumio[4333]: info: Initializing BBC Radios Feb 25 03:47:32 volumio sudo[4538]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 25 03:47:32 volumio sudo[4538]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 25 03:47:32 volumio sudo[4538]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:32 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 25 03:47:32 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:47:32 volumio volumio[4333]: info: Creating Spotify config file Feb 25 03:47:32 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:32 volumio go-librespot[4530]: time="2026-02-25T03:47: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 25 03:47:32 volumio go-librespot[4530]: time="2026-02-25T03:47: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 25 03:47:32 volumio go-librespot[4530]: time="2026-02-25T03:47: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 25 03:47:32 volumio go-librespot[4530]: time="2026-02-25T03:47:32+07:00" level=info msg="zeroconf server listening on port 41871" Feb 25 03:47:33 volumio go-librespot[4530]: time="2026-02-25T03:47:33+07:00" level=debug msg="obtained new client token: AACidc/fbNrIhxap3z/XSAVGxh9wDx4OWrOxxKUoppco2Yk4a6lqlP6WXq2Jdz2JqZBhRZQFH9JC8KVnimTtkgMBS92YVxpXV3/2zYwNwbIdTV1pVyGe4LY/Fa/uoj1sCZKelj0exVcB+d77FkOOOz+Ww47soa8Ikpw3B6GklmYPbqaq5cfSNKI+i5Li+VBQwU+GDs4x9Mza71RdNsFaH6XizgDv8Jo/orXE5NGu6mWbFKFpZ6Atze4=" Feb 25 03:47:33 volumio go-librespot[4530]: time="2026-02-25T03:47:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:47:33 volumio go-librespot[4530]: time="2026-02-25T03:47:33+07:00" level=debug msg="completed keyexchange" Feb 25 03:47:33 volumio go-librespot[4530]: time="2026-02-25T03:47:33+07:00" level=debug msg="completed challenge" Feb 25 03:47:33 volumio go-librespot[4530]: time="2026-02-25T03:47:33+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 25 03:47:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:47:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:47:34 volumio volumio[4455]: Starting albumart workers Feb 25 03:47:34 volumio volumio[4333]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 03:47:34 volumio volumio[4333]: info: [1771966054697] CoreMusicLibrary::Adding element YouTube Music Feb 25 03:47:34 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 03:47:34 volumio volumio[4333]: Cannot find translation for source YouTube Music Feb 25 03:47:34 volumio volumio[4333]: info: Volumio Calling Home Feb 25 03:47:34 volumio volumio[4454]: Starting albumart workers Feb 25 03:47:34 volumio sudo[4560]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 25 03:47:34 volumio sudo[4560]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:34 volumio volumio[4453]: Starting albumart workers Feb 25 03:47:35 volumio sudo[4560]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:36 volumio volumio[4333]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 25 03:47:36 volumio volumio[4333]: info: Discovery: Found device Volumio Feb 25 03:47:36 volumio volumio[4333]: info: CoreCommandRouter::volumioGetState Feb 25 03:47:36 volumio volumio[4333]: info: CorePlayQueue::getTrack 0 Feb 25 03:47:36 volumio volumio[4333]: info: MPD Permissions set Feb 25 03:47:36 volumio volumio[4333]: info: MPD Permissions set Feb 25 03:47:36 volumio volumio[4333]: info: Upmpdcli Daemon Started Feb 25 03:47:36 volumio volumio[4333]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 25 03:47:36 volumio volumio[4333]: info: Discovery: Found device Volumio Feb 25 03:47:36 volumio volumio[4333]: info: CoreCommandRouter::volumioGetState Feb 25 03:47:36 volumio volumio[4333]: info: CorePlayQueue::getTrack 0 Feb 25 03:47:36 volumio volumio[4333]: info: Volumio called home Feb 25 03:47:36 volumio volumio[4333]: info: Spotify config file written Feb 25 03:47:36 volumio sudo[4566]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 25 03:47:36 volumio sudo[4566]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Feb 25 03:47:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:36 volumio go-librespot[4568]: go-librespot daemon starting... Feb 25 03:47:36 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 25 03:47:36 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 25 03:47:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:36 volumio go-librespot[4575]: go-librespot daemon starting... Feb 25 03:47:36 volumio sudo[4566]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:37 volumio go-librespot[4577]: time="2026-02-25T03:47:37+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:47:37 volumio go-librespot[4577]: time="2026-02-25T03:47:37+07:00" level=debug msg="app state loaded" Feb 25 03:47:37 volumio go-librespot[4577]: time="2026-02-25T03:47:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:47:37 volumio volumio[4333]: 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 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: No need to fix Spotify hosts Feb 25 03:47:37 volumio go-librespot[4577]: time="2026-02-25T03:47: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-gew1.spotify.com:80]" Feb 25 03:47:37 volumio go-librespot[4577]: time="2026-02-25T03:47:37+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 25 03:47:37 volumio go-librespot[4577]: time="2026-02-25T03:47:37+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 25 03:47:37 volumio go-librespot[4577]: time="2026-02-25T03:47:37+07:00" level=info msg="zeroconf server listening on port 43369" Feb 25 03:47:38 volumio go-librespot[4577]: time="2026-02-25T03:47:38+07:00" level=debug msg="obtained new client token: AAAwsAUTlm1ebCKj7FUtGS4MzZi9SDPjtlwdsTIfd7ZxQkC8X+2XFfY1L8pt6TioHrWIje5h7qZmLqGJkmBq7QhA20hBD0FYhP3+JJ/0t7S/ynE99BWstHBFngwqjyYdnSvDihiJ+Mut0yEqw24MlVgcBuSuopO8OHJ+tJ/coqgn9pXU+JcNblMFK7t2MrHw5YftopynLvLT7sl9QLwpG7nfJxgPorA7mdIXUrQyr2F+GiLN0vqGHc0=" Feb 25 03:47:38 volumio go-librespot[4577]: time="2026-02-25T03:47:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:47:38 volumio go-librespot[4577]: time="2026-02-25T03:47:38+07:00" level=debug msg="completed keyexchange" Feb 25 03:47:38 volumio go-librespot[4577]: time="2026-02-25T03:47:38+07:00" level=debug msg="completed challenge" Feb 25 03:47:38 volumio go-librespot[4577]: time="2026-02-25T03:47: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 25 03:47:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:47:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:47:38 volumio volumio[4333]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 25 03:47:38 volumio volumio[4333]: SPOTIFY: BQD9-EQUI9iYNweNrZ-WRI6z_Gi8d74nrSlg8EBEgjhiu3PyCDhrA-69FI_QecrFSUSYyuZvPTAwYEVkeupimn4BJYe1G47jVO5s_DVuDnzSSvHr3hIUrGv0J1FgWhj5uT9ZgyGsO7uzTS42Zl3Xm5BjQHB0jyEK0s8IW1_MF3s39ibEo1tbOMfxd2pd0xeAi8ePL6JbU9xTUDateEkh_vrwd_Yh8cBM9a2HRCLAl4sTeTVvWcEpVzJ5ckkZV8bXxqeXsehJMCFEAHJcz8MPfcuHohZGS1nRxbowBrbrz_ihVu5ifrKFhgW0 Feb 25 03:47:38 volumio volumio[4333]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 25 03:47:38 volumio volumio[4333]: info: New Spotify access token = BQD9-EQUI9iYNweNrZ-WRI6z_Gi8d74nrSlg8EBEgjhiu3PyCDhrA-69FI_QecrFSUSYyuZvPTAwYEVkeupimn4BJYe1G47jVO5s_DVuDnzSSvHr3hIUrGv0J1FgWhj5uT9ZgyGsO7uzTS42Zl3Xm5BjQHB0jyEK0s8IW1_MF3s39ibEo1tbOMfxd2pd0xeAi8ePL6JbU9xTUDateEkh_vrwd_Yh8cBM9a2HRCLAl4sTeTVvWcEpVzJ5ckkZV8bXxqeXsehJMCFEAHJcz8MPfcuHohZGS1nRxbowBrbrz_ihVu5ifrKFhgW0 Feb 25 03:47:38 volumio volumio[4333]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 25 03:47:38 volumio volumio[4333]: info: Starting Shairport Sync Feb 25 03:47:38 volumio volumio[4333]: info: Starting Shairport Sync Feb 25 03:47:38 volumio volumio[4333]: info: Starting Shairport Sync Feb 25 03:47:38 volumio sudo[4627]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 25 03:47:38 volumio sudo[4627]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:38 volumio sudo[4629]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 25 03:47:38 volumio sudo[4629]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:38 volumio sudo[4631]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 25 03:47:38 volumio sudo[4631]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:38 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 25 03:47:39 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 25 03:47:39 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 25 03:47:39 volumio systemd[1]: shairport-sync.service: Consumed 2.147s CPU time. Feb 25 03:47:39 volumio volumio[4333]: info: CoreCommandRouter::volumioGetState Feb 25 03:47:39 volumio volumio[4333]: info: CorePlayQueue::getTrack 0 Feb 25 03:47:39 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 25 03:47:39 volumio sudo[4627]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:39 volumio sudo[4629]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:39 volumio sudo[4631]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:39 volumio volumio[4333]: info: Shairport-Sync Started Feb 25 03:47:39 volumio volumio[4333]: Error adding Membership: Error: addMembership EINVAL Feb 25 03:47:39 volumio volumio[4333]: info: Shairport-Sync Started Feb 25 03:47:39 volumio volumio[4333]: info: Shairport-Sync Started Feb 25 03:47:39 volumio volumio[4333]: 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 25 03:47:39 volumio volumio[4333]: info: Spotify Successfully logged in Feb 25 03:47:39 volumio volumio[4333]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 03:47:39 volumio volumio[4333]: info: [1771966059666] CoreMusicLibrary::Adding element Spotify Feb 25 03:47:39 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 03:47:39 volumio volumio[4333]: Cannot find translation for source YouTube Music Feb 25 03:47:39 volumio volumio[4333]: Cannot find translation for source Spotify Feb 25 03:47:39 volumio mpd[4556]: 2026-02-25T03:47:39 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 25 03:47:39 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 25 03:47:39 volumio sudo[4520]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:39 volumio sudo[4509]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:40 volumio volumio[4333]: error: MPD error: The expression evaluated to a falsy value: Feb 25 03:47:40 volumio volumio[4333]: assert.ok(self.idling) Feb 25 03:47:40 volumio volumio[4333]: error: The expression evaluated to a falsy value: Feb 25 03:47:40 volumio volumio[4333]: assert.ok(self.idling) Feb 25 03:47:40 volumio volumio[4333]: error: updateQueue error: null Feb 25 03:47:40 volumio volumio[4333]: info: MPD running with PID4556 Feb 25 03:47:40 volumio volumio[4333]: ,establishing connection Feb 25 03:47:40 volumio volumio[4333]: error: updateQueue error: null Feb 25 03:47:40 volumio volumio[4333]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 25 03:47:40 volumio volumio[4333]: info: CoreCommandRouter::volumioRetrievevolume Feb 25 03:47:40 volumio volumio[4333]: info: VolumeController:: Volume=100 Mute =false Feb 25 03:47:40 volumio volumio[4333]: info: CoreCommandRouter::volumioGetState Feb 25 03:47:40 volumio volumio[4333]: info: CorePlayQueue::getTrack 0 Feb 25 03:47:40 volumio volumio[4333]: info: CoreStateMachine::pushState Feb 25 03:47:40 volumio volumio[4333]: info: CorePlayQueue::getTrack 0 Feb 25 03:47:40 volumio volumio[4333]: info: CoreCommandRouter::volumioPushState Feb 25 03:47:40 volumio volumio[4333]: info: Completed starting Core Plugins Feb 25 03:47:40 volumio volumio[4333]: info: ------------------------------------------- Feb 25 03:47:40 volumio volumio[4333]: info: ----- MyVolumio plugins startup ---- Feb 25 03:47:40 volumio volumio[4333]: info: ------------------------------------------- Feb 25 03:47:40 volumio volumio[4333]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 25 03:47:41 volumio volumio[4333]: info: go-librespot daemon successfully initialized Feb 25 03:47:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 25 03:47:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:41 volumio go-librespot[4657]: go-librespot daemon starting... Feb 25 03:47:41 volumio go-librespot[4658]: time="2026-02-25T03:47:41+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:47:41 volumio go-librespot[4658]: time="2026-02-25T03:47:41+07:00" level=debug msg="app state loaded" Feb 25 03:47:41 volumio go-librespot[4658]: time="2026-02-25T03:47:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:47:42 volumio go-librespot[4658]: time="2026-02-25T03:47:42+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 03:47:42 volumio go-librespot[4658]: time="2026-02-25T03:47:42+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 25 03:47:42 volumio go-librespot[4658]: time="2026-02-25T03:47:42+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 25 03:47:42 volumio go-librespot[4658]: time="2026-02-25T03:47:42+07:00" level=info msg="zeroconf server listening on port 40297" Feb 25 03:47:42 volumio go-librespot[4658]: time="2026-02-25T03:47:42+07:00" level=debug msg="obtained new client token: AAAucISYXbEm1KW8iPCPeTOfuP1OrnMIbN6O3ol9erUrCgTd9oyt/smmT7wp7DlCEaVywY2X1jyodLmEWEzYgLbjJYOgibsYaA8igOAy2zw0qpf4fJ1993W+qdQLel+tphKjl4+fjpOc0WtEaPAaZcytrjuFZ+5miTc8sMLrM2rPqI0DpdR34GgliidW8ESRVcKsmbanQyignF2nyVknLVvr+MOQ2HmcICelgMcQecOC5LcFgQ8VI/vrKQ==" Feb 25 03:47:42 volumio go-librespot[4658]: time="2026-02-25T03:47:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:47:42 volumio go-librespot[4658]: time="2026-02-25T03:47:42+07:00" level=debug msg="completed keyexchange" Feb 25 03:47:42 volumio go-librespot[4658]: time="2026-02-25T03:47:42+07:00" level=debug msg="completed challenge" Feb 25 03:47:42 volumio go-librespot[4658]: time="2026-02-25T03:47: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 25 03:47:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:47:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:47:44 volumio volumio[4333]: info: Initializing connection to go-librespot Websocket Feb 25 03:47:44 volumio volumio[4333]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 03:47:44 volumio volumio[4333]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 25 03:47:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 25 03:47:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:45 volumio go-librespot[4666]: go-librespot daemon starting... Feb 25 03:47:45 volumio go-librespot[4667]: time="2026-02-25T03:47:45+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:47:45 volumio go-librespot[4667]: time="2026-02-25T03:47:45+07:00" level=debug msg="app state loaded" Feb 25 03:47:45 volumio go-librespot[4667]: time="2026-02-25T03:47:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:47:46 volumio go-librespot[4667]: time="2026-02-25T03:47: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 25 03:47:46 volumio go-librespot[4667]: time="2026-02-25T03:47: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 25 03:47:46 volumio go-librespot[4667]: time="2026-02-25T03:47: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 25 03:47:46 volumio go-librespot[4667]: time="2026-02-25T03:47:46+07:00" level=info msg="zeroconf server listening on port 35149" Feb 25 03:47:46 volumio go-librespot[4667]: time="2026-02-25T03:47:46+07:00" level=debug msg="obtained new client token: AAAghPOt8O/2GY+4GQFHX3cWUfCnohlyssszYeRSLgcDX+UAE7AccQOx7ldUxoO9Q7Xt08cXP5NDwv9ArRi6ht9nXn+FTcDPf0IeJ/f29tnZ7yQT8y1b1UbEi0QYNBkPADSXWM99AtAlLs1iHshyqodO9xxsUxOvllE0LcFCH6HOZtOyhUnO9LPpsDCHgNxzNce2Ip6QaMyiQg4N2GhNNpomqK2F57dNVa7c8+zLkkX3+6hKu3lWDRIgEA==" Feb 25 03:47:46 volumio go-librespot[4667]: time="2026-02-25T03:47:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:47:46 volumio go-librespot[4667]: time="2026-02-25T03:47:46+07:00" level=debug msg="completed keyexchange" Feb 25 03:47:46 volumio go-librespot[4667]: time="2026-02-25T03:47:46+07:00" level=debug msg="completed challenge" Feb 25 03:47:47 volumio go-librespot[4667]: time="2026-02-25T03:47:47+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 25 03:47:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:47:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:47:47 volumio volumio[4333]: info: Initializing connection to go-librespot Websocket Feb 25 03:47:47 volumio volumio[4333]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 03:47:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 25 03:47:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:50 volumio go-librespot[4688]: go-librespot daemon starting... Feb 25 03:47:50 volumio go-librespot[4689]: time="2026-02-25T03:47:50+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:47:50 volumio go-librespot[4689]: time="2026-02-25T03:47:50+07:00" level=debug msg="app state loaded" Feb 25 03:47:50 volumio go-librespot[4689]: time="2026-02-25T03:47:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:47:50 volumio volumio[4333]: info: Initializing connection to go-librespot Websocket Feb 25 03:47:50 volumio go-librespot[4689]: time="2026-02-25T03:47:50+07:00" level=debug msg="new websocket client" Feb 25 03:47:50 volumio volumio[4333]: info: Connection to go-librespot Websocket established Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 25 03:47:50 volumio volumio[4333]: info: Adding plugin bluetooth to MyMusic Plugins Feb 25 03:47:50 volumio volumio[4333]: info: Adding plugin multiroom to MyMusic Plugins Feb 25 03:47:50 volumio volumio[4333]: info: Adding plugin metavolumio to MyMusic Plugins Feb 25 03:47:50 volumio volumio[4333]: info: Adding plugin cd_controller to MyMusic Plugins Feb 25 03:47:50 volumio volumio[4333]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 25 03:47:50 volumio volumio[4333]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 25 03:47:50 volumio volumio[4333]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 25 03:47:50 volumio go-librespot[4689]: time="2026-02-25T03:47: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 03:47:50 volumio go-librespot[4689]: time="2026-02-25T03:47:50+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 25 03:47:50 volumio go-librespot[4689]: time="2026-02-25T03:47:50+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 25 03:47:50 volumio go-librespot[4689]: time="2026-02-25T03:47:50+07:00" level=info msg="zeroconf server listening on port 37651" Feb 25 03:47:51 volumio go-librespot[4689]: time="2026-02-25T03:47:51+07:00" level=debug msg="obtained new client token: AABA4TpJcZFNb+cKaYp1rJulW/GtqVIq1K30gYMwVXWt2qDqNjOz7HHoE18moZNhQ0Jdyigy64gO0HEWoARFNOtQTjo0YyOUMjuahMGGZObEWbZmaBDJK5Be2MgvMX5ur1UpyCT40BqJAEqiPWccn10UfTGRyZeCP6Yio7Hau1t1CO3g4wWq/2QoRHGJJ+lzuoAorWznx0RkenBJGJyvS4QO0M7368YxMqhCyn+df8v5oxl4QleS7QBOmw==" Feb 25 03:47:51 volumio go-librespot[4689]: time="2026-02-25T03:47:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:47:51 volumio go-librespot[4689]: time="2026-02-25T03:47:51+07:00" level=debug msg="completed keyexchange" Feb 25 03:47:51 volumio go-librespot[4689]: time="2026-02-25T03:47:51+07:00" level=debug msg="completed challenge" Feb 25 03:47:51 volumio go-librespot[4689]: time="2026-02-25T03:47: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 25 03:47:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:47:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:47:52 volumio volumio[4333]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 25 03:47:52 volumio volumio[4333]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 25 03:47:52 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:47:52 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:47:52 volumio volumio[4333]: info: Starting MyVolumio Remote Streaming Endpoints Feb 25 03:47:52 volumio volumio[4333]: info: MyVolumio login type: Token Feb 25 03:47:52 volumio volumio[4333]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 25 03:47:52 volumio volumio[4333]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 25 03:47:54 volumio volumio[4333]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 25 03:47:54 volumio volumio[4333]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 25 03:47:54 volumio volumio[4333]: info: Streaming services startup Feb 25 03:47:54 volumio volumio[4333]: info: Starting Streaming Daemon Feb 25 03:47:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 25 03:47:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:54 volumio volumio[4333]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 25 03:47:54 volumio sudo[4700]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 25 03:47:54 volumio sudo[4700]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:54 volumio go-librespot[4705]: go-librespot daemon starting... Feb 25 03:47:54 volumio sudo[4700]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:54 volumio go-librespot[4707]: time="2026-02-25T03:47:54+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:47:54 volumio go-librespot[4707]: time="2026-02-25T03:47:54+07:00" level=debug msg="app state loaded" Feb 25 03:47:54 volumio go-librespot[4707]: time="2026-02-25T03:47:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:47:54 volumio volumio[4333]: info: Getting Spotify volume Feb 25 03:47:54 volumio volumio[4333]: info: Connection to go-librespot Websocket closed Feb 25 03:47:54 volumio volumio[4333]: error: Cannot start Volumio Streaming Daemon Feb 25 03:47:54 volumio volumio[4333]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 25 03:47:54 volumio volumio[4333]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 25 03:47:54 volumio volumio[4333]: 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 25 03:47:55 volumio volumio[4333]: info: CoreCommandRouter::volumioGetState Feb 25 03:47:55 volumio volumio[4333]: info: CorePlayQueue::getTrack 0 Feb 25 03:47:55 volumio volumio[4333]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 25 03:47:55 volumio volumio[4333]: SPOTIFY: SPOTIFY VOLUME undefined Feb 25 03:47:55 volumio volumio[4333]: SPOTIFY: VOLUMIO VOLUME 100 Feb 25 03:47:55 volumio volumio[4333]: info: Aligning Spotify Volume to Volumio Volume Feb 25 03:47:55 volumio volumio[4333]: info: CoreCommandRouter::volumioGetState Feb 25 03:47:55 volumio volumio[4333]: info: CorePlayQueue::getTrack 0 Feb 25 03:47:55 volumio volumio[4333]: info: Setting Spotify Volume from Volumio: 100 Feb 25 03:47:55 volumio go-librespot[4707]: time="2026-02-25T03:47: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 03:47:55 volumio go-librespot[4707]: time="2026-02-25T03:47:55+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 25 03:47:55 volumio go-librespot[4707]: time="2026-02-25T03:47:55+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 25 03:47:55 volumio go-librespot[4707]: time="2026-02-25T03:47:55+07:00" level=info msg="zeroconf server listening on port 40597" Feb 25 03:47:55 volumio go-librespot[4707]: time="2026-02-25T03:47:55+07:00" level=debug msg="obtained new client token: AADP85DI1WZfAOqZ4kL2LyHPFnkSkmt7XJcdRAeBhVQ5kvGRI39tDYLJYeNXsKXtSVSvYzWagQYZabgYX+1LOBZwGPJUOWQantG9iz/D7BrUw1W2nLgHLpTvJxAqZvNKQqLD1HLavgkBD4Bq+ThQxw8g9pXKqtuInjI3fPXvJeMhGDA3yTIUJtc0nPq9yTCEE6iYwbaIb9L1Swnr/99XVnjSBvcTQHhyq5LyeDNJ8KdA+mnR7BtxOh7nlw==" Feb 25 03:47:55 volumio go-librespot[4707]: time="2026-02-25T03:47:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:47:55 volumio go-librespot[4707]: time="2026-02-25T03:47:55+07:00" level=debug msg="completed keyexchange" Feb 25 03:47:55 volumio go-librespot[4707]: time="2026-02-25T03:47:55+07:00" level=debug msg="completed challenge" Feb 25 03:47:55 volumio go-librespot[4707]: time="2026-02-25T03:47: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 25 03:47:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:47:55 volumio volumio[4333]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 25 03:47:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:47:55 volumio volumio[4333]: Error: socket hang up Feb 25 03:47:55 volumio volumio[4333]: at connResetException (node:internal/errors:720:14) Feb 25 03:47:55 volumio volumio[4333]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 25 03:47:55 volumio volumio[4333]: at Socket.emit (node:events:526:35) Feb 25 03:47:55 volumio volumio[4333]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 25 03:47:55 volumio volumio[4333]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 25 03:47:55 volumio volumio[4333]: code: 'ECONNRESET', Feb 25 03:47:55 volumio volumio[4333]: response: undefined Feb 25 03:47:55 volumio volumio[4333]: } Feb 25 03:47:55 volumio volumio[4333]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 25 03:47:57 volumio sudo[4729]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-25 03:46' Feb 25 03:47:57 volumio sudo[4729]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:57 volumio sudo[4729]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 25 03:47:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:59 volumio go-librespot[4751]: go-librespot daemon starting... Feb 25 03:47:59 volumio go-librespot[4752]: time="2026-02-25T03:47:59+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:47:59 volumio go-librespot[4752]: time="2026-02-25T03:47:59+07:00" level=debug msg="app state loaded" Feb 25 03:47:59 volumio go-librespot[4752]: time="2026-02-25T03:47:59+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:47:59 volumio volumio-remote-updater[647]: [2026-02-25 03:47:59] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 25 03:47:59 volumio volumio-remote-updater[647]: [2026-02-25 03:47:59] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 25 03:47:59 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:47:59 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 25 03:47:59 volumio systemd[1]: volumio.service: Consumed 55.317s CPU time. Feb 25 03:47:59 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 25 03:47:59 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 25 03:47:59 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 7502. Feb 25 03:47:59 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 25 03:47:59 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 25 03:47:59 volumio systemd[1]: volumio.service: Consumed 55.317s CPU time. Feb 25 03:47:59 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 25 03:47:59 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 25 03:47:59 volumio go-librespot[4752]: time="2026-02-25T03:47: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 25 03:47:59 volumio go-librespot[4752]: time="2026-02-25T03:47:59+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 25 03:47:59 volumio go-librespot[4752]: time="2026-02-25T03:47:59+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 25 03:47:59 volumio go-librespot[4752]: time="2026-02-25T03:47:59+07:00" level=info msg="zeroconf server listening on port 42069" Feb 25 03:48:00 volumio go-librespot[4752]: time="2026-02-25T03:48:00+07:00" level=debug msg="obtained new client token: AADjHHIU0uXIdNQQdoLVh+1rncM8dYtbmk5VP1yj8yVaJeITvYRFVT276F7draSwXR5iCChJfiBYSItSEx8pUokp6XuqORbZ0hRkBtP+EeW5+7H07Kn/Ji78RhchKsANUesU+dnhvn/l2MIE2oj0HzLxZI9kC+N7Mdx41Tp4i+yQZBF58NXMfUFMxM9doiftRiIuuMhRiljTgUwqy0yNl9Z60WQVLlJlj8X410tVJ9HEV8XxVi71dmM=" Feb 25 03:48:00 volumio go-librespot[4752]: time="2026-02-25T03:48:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:48:00 volumio go-librespot[4752]: time="2026-02-25T03:48:00+07:00" level=debug msg="completed keyexchange" Feb 25 03:48:00 volumio go-librespot[4752]: time="2026-02-25T03:48:00+07:00" level=debug msg="completed challenge" Feb 25 03:48:00 volumio go-librespot[4752]: time="2026-02-25T03:48: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 25 03:48:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:48:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:48:03 volumio volumio[4768]: info: ------------------------------------------- Feb 25 03:48:03 volumio volumio[4768]: info: ----- Volumio3 ---- Feb 25 03:48:03 volumio volumio[4768]: info: ------------------------------------------- Feb 25 03:48:03 volumio volumio[4768]: info: ----- System startup ---- Feb 25 03:48:03 volumio volumio[4768]: info: ------------------------------------------- Feb 25 03:48:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 25 03:48:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:48:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:48:03 volumio go-librespot[4787]: go-librespot daemon starting... Feb 25 03:48:03 volumio go-librespot[4788]: time="2026-02-25T03:48:03+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:48:03 volumio go-librespot[4788]: time="2026-02-25T03:48:03+07:00" level=debug msg="app state loaded" Feb 25 03:48:03 volumio go-librespot[4788]: time="2026-02-25T03:48:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:48:04 volumio volumio-remote-updater[647]: [2026-02-25 03:48:04] [connect] Successful connection Feb 25 03:48:04 volumio go-librespot[4788]: time="2026-02-25T03:48:04+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 03:48:04 volumio go-librespot[4788]: time="2026-02-25T03:48:04+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 25 03:48:04 volumio go-librespot[4788]: time="2026-02-25T03:48:04+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 25 03:48:04 volumio go-librespot[4788]: time="2026-02-25T03:48:04+07:00" level=info msg="zeroconf server listening on port 46035" Feb 25 03:48:04 volumio go-librespot[4788]: time="2026-02-25T03:48:04+07:00" level=debug msg="obtained new client token: AADjOmOtmAB9YxgMumhCf6XoRF5Wb6bfP16z3Ub1QQhZodwS4fFIWiWgJyKdfxSiSr2OuLUJ/ZJ4NBveLgd+DiObbUrXD8Qm4Dx3GAly9oG/W+xhdAtNkaTPMRNnTB24ldMG8lqpQ+TM6ee15RWgfPpPeWtNCF0FjE4h8oF8+N/ALP005B0xT09SAFn9gY1ig2hhFYqqPCG7PbRtz0TWB66I/+Tt3TrPOmuhpCRUouhYlt6tzp1dSNoFzA==" Feb 25 03:48:04 volumio go-librespot[4788]: time="2026-02-25T03:48:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:48:04 volumio volumio[4768]: info: MYVOLUMIO Environment detected Feb 25 03:48:04 volumio go-librespot[4788]: time="2026-02-25T03:48:04+07:00" level=debug msg="completed keyexchange" Feb 25 03:48:04 volumio go-librespot[4788]: time="2026-02-25T03:48:04+07:00" level=debug msg="completed challenge" Feb 25 03:48:04 volumio volumio[4768]: info: Plugin folders cleanup Feb 25 03:48:04 volumio volumio[4768]: info: Scanning into folder /volumio/app/plugins/ Feb 25 03:48:04 volumio volumio[4768]: info: Scanning category audio_interface Feb 25 03:48:04 volumio volumio[4768]: info: Scanning category miscellanea Feb 25 03:48:04 volumio volumio[4768]: info: Scanning category music_service Feb 25 03:48:04 volumio volumio[4768]: info: Scanning category plugins.json Feb 25 03:48:04 volumio volumio[4768]: info: Scanning category system_controller Feb 25 03:48:04 volumio go-librespot[4788]: time="2026-02-25T03:48: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 25 03:48:04 volumio volumio[4768]: info: Scanning category user_interface Feb 25 03:48:04 volumio volumio[4768]: info: Scanning into folder /data/plugins/ Feb 25 03:48:04 volumio volumio[4768]: info: Scanning category music_service Feb 25 03:48:04 volumio volumio[4768]: info: Plugin folders cleanup completed Feb 25 03:48:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:48:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:48:04 volumio volumio[4768]: info: ------------------------------------------- Feb 25 03:48:04 volumio volumio[4768]: info: ----- Core plugins startup ---- Feb 25 03:48:04 volumio volumio[4768]: info: ------------------------------------------- Feb 25 03:48:04 volumio volumio[4768]: info: Loading plugins from folder /volumio/app/plugins/ Feb 25 03:48:04 volumio volumio[4768]: info: Adding plugin upnp to MyMusic Plugins Feb 25 03:48:04 volumio volumio[4768]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 25 03:48:04 volumio volumio[4768]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 25 03:48:04 volumio volumio[4768]: info: Loading plugins from folder /data/plugins/ Feb 25 03:48:04 volumio volumio[4768]: info: Loading plugin "system"... Feb 25 03:48:05 volumio volumio[4768]: info: Loading plugin "appearance"... Feb 25 03:48:06 volumio volumio[4768]: info: Loading plugin "network"... Feb 25 03:48:06 volumio volumio[4768]: info: Refreshing Cached IP Addresses Feb 25 03:48:06 volumio sudo[4802]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 25 03:48:06 volumio sudo[4802]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:48:06 volumio sudo[4804]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 25 03:48:06 volumio sudo[4804]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:48:06 volumio sudo[4802]: pam_unix(sudo:session): session closed for user root Feb 25 03:48:06 volumio volumio[4768]: info: Loading plugin "services"... Feb 25 03:48:07 volumio volumio[4768]: info: Loading plugin "alsa_controller"... Feb 25 03:48:07 volumio sudo[4804]: pam_unix(sudo:session): session closed for user root Feb 25 03:48:07 volumio sudo[4812]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 25 03:48:07 volumio sudo[4812]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:48:07 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 25 03:48:07 volumio volumio[4768]: info: Loading plugin "wizard"... Feb 25 03:48:07 volumio volumio[4768]: info: Loading plugin "networkfs"... Feb 25 03:48:07 volumio volumio[4768]: info: Starting Udev Watcher for removable devices Feb 25 03:48:07 volumio volumio[4768]: info: Ignoring mount for partition: boot Feb 25 03:48:07 volumio volumio[4768]: info: Ignoring mount for partition: volumio Feb 25 03:48:07 volumio volumio[4768]: info: Ignoring mount for partition: volumio_data Feb 25 03:48:07 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 25 03:48:07 volumio volumio[4768]: info: Loading plugin "volumio_command_line_client"... Feb 25 03:48:07 volumio volumio[4768]: info: Loading plugin "upnp"... Feb 25 03:48:07 volumio volumio[4768]: info: [1771966087314] Starting Upmpd Daemon Feb 25 03:48:07 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 25 03:48:07 volumio volumio[4768]: info: Loading plugin "my_music"... Feb 25 03:48:07 volumio volumio[4768]: info: Loading plugin "mpd"... Feb 25 03:48:07 volumio volumio[4768]: info: Loading plugin "upnp_browser"... Feb 25 03:48:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 25 03:48:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:48:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:48:08 volumio go-librespot[4835]: go-librespot daemon starting... Feb 25 03:48:08 volumio go-librespot[4836]: time="2026-02-25T03:48:08+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:48:08 volumio go-librespot[4836]: time="2026-02-25T03:48:08+07:00" level=debug msg="app state loaded" Feb 25 03:48:08 volumio go-librespot[4836]: time="2026-02-25T03:48:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:48:08 volumio go-librespot[4836]: time="2026-02-25T03:48: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 03:48:08 volumio go-librespot[4836]: time="2026-02-25T03:48:08+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 25 03:48:08 volumio go-librespot[4836]: time="2026-02-25T03:48:08+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 25 03:48:08 volumio go-librespot[4836]: time="2026-02-25T03:48:08+07:00" level=info msg="zeroconf server listening on port 41565" Feb 25 03:48:09 volumio go-librespot[4836]: time="2026-02-25T03:48:09+07:00" level=debug msg="obtained new client token: AAAlRMHtBKlj/rayYka3mC6j43r1PTB6DQ1JE9MAornOmBozv79oNhV8ElkahappwbPY8yOdwFism+U/Fkzx2Z2qz50UiUnLpk9qF+Hy3GN+0XfnR5CrYBlwjOuVSc5EvnpHH/Smp+x+UzmC/SGgB7BEte9Et+0F7Uei8e8oyY8qWIdeS6yCDll0wX6udNcDs2/F+RNhu5TjhB5VxLfp2pJigAzOXVlsEWmi2KLQrrmfyGhM6DOP6SM=" Feb 25 03:48:09 volumio go-librespot[4836]: time="2026-02-25T03:48:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:48:09 volumio go-librespot[4836]: time="2026-02-25T03:48:09+07:00" level=debug msg="completed keyexchange" Feb 25 03:48:09 volumio go-librespot[4836]: time="2026-02-25T03:48:09+07:00" level=debug msg="completed challenge" Feb 25 03:48:09 volumio go-librespot[4836]: time="2026-02-25T03:48:09+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 25 03:48:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:48:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:48:09 volumio sudo[4812]: pam_unix(sudo:session): session closed for user root Feb 25 03:48:10 volumio volumio[4768]: info: Starting UPNP Browser Feb 25 03:48:10 volumio volumio[4768]: info: Loading plugin "alarm-clock"... Feb 25 03:48:11 volumio volumio[4768]: info: Loading plugin "airplay_emulation"... Feb 25 03:48:11 volumio volumio[4768]: info: Starting Shairport Sync Feb 25 03:48:11 volumio volumio[4768]: info: Loading plugin "last_100"... Feb 25 03:48:11 volumio volumio[4768]: info: Loading plugin "webradio"... Feb 25 03:48:11 volumio volumio[4768]: info: Loading plugin "i2s_dacs"... Feb 25 03:48:11 volumio volumio[4768]: info: Loading plugin "volumiodiscovery"... Feb 25 03:48:11 volumio volumio[4768]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 25 03:48:11 volumio volumio[4768]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 25 03:48:11 volumio volumio[4768]: *** WARNING *** For more information see Feb 25 03:48:11 volumio volumio[4768]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 25 03:48:11 volumio volumio[4768]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 25 03:48:11 volumio volumio[4768]: *** WARNING *** For more information see Feb 25 03:48:11 volumio node[4768]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 25 03:48:11 volumio node[4768]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 25 03:48:11 volumio node[4768]: *** WARNING *** For more information see Feb 25 03:48:11 volumio node[4768]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 25 03:48:11 volumio node[4768]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 25 03:48:11 volumio node[4768]: *** WARNING *** For more information see Feb 25 03:48:11 volumio volumio[4768]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 25 03:48:11 volumio volumio[4768]: info: Discovery: Started advertising with name: Volumio Feb 25 03:48:11 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 25 03:48:11 volumio volumio[4768]: info: Loading plugin "spop"... Feb 25 03:48:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 25 03:48:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:48:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:48:12 volumio go-librespot[4847]: go-librespot daemon starting... Feb 25 03:48:12 volumio go-librespot[4848]: time="2026-02-25T03:48:12+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:48:12 volumio go-librespot[4848]: time="2026-02-25T03:48:12+07:00" level=debug msg="app state loaded" Feb 25 03:48:12 volumio go-librespot[4848]: time="2026-02-25T03:48:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:48:13 volumio go-librespot[4848]: time="2026-02-25T03:48:13+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 03:48:13 volumio go-librespot[4848]: time="2026-02-25T03:48:13+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 25 03:48:13 volumio go-librespot[4848]: time="2026-02-25T03:48:13+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 25 03:48:13 volumio go-librespot[4848]: time="2026-02-25T03:48:13+07:00" level=info msg="zeroconf server listening on port 45809" Feb 25 03:48:13 volumio volumio[4768]: info: Loading plugin "ytcr"... Feb 25 03:48:13 volumio go-librespot[4848]: time="2026-02-25T03:48:13+07:00" level=debug msg="obtained new client token: AAA7ukm4Mm+UZk6xcTWs4GdlwUvoNyZFWYsbhj0y5JMPB72dRFD/VN+kr+iQnWZ7IHUdArFBbUqiW1KuSe8MuhXeKeIDisVdpmUyzzPNo34jOHRoThY4rJyVGldBbmC3TLrCKBLfyxnWoY0ST04ORIqWqvbScZ1+gdz9MX01VvbVvL6Bqd1itnf/TZx6jaoGvjQPnjfV9s/+Bv4v7PFaVc4XGiUK4jZgZkOtMlekr4w7X2BS7ZDS7UboqA==" Feb 25 03:48:13 volumio go-librespot[4848]: time="2026-02-25T03:48:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:48:13 volumio go-librespot[4848]: time="2026-02-25T03:48:13+07:00" level=debug msg="completed keyexchange" Feb 25 03:48:13 volumio go-librespot[4848]: time="2026-02-25T03:48:13+07:00" level=debug msg="completed challenge" Feb 25 03:48:13 volumio go-librespot[4848]: time="2026-02-25T03:48: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 25 03:48:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:48:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:48:16 volumio volumio[4768]: info: Loading plugin "ytmusic"... Feb 25 03:48:16 volumio volumio-remote-updater[647]: [2026-02-25 03:48:16] [connect] Successful connection Feb 25 03:48:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 25 03:48:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:48:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:48:17 volumio go-librespot[4868]: go-librespot daemon starting... Feb 25 03:48:17 volumio go-librespot[4875]: time="2026-02-25T03:48:17+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:48:17 volumio go-librespot[4875]: time="2026-02-25T03:48:17+07:00" level=debug msg="app state loaded" Feb 25 03:48:17 volumio go-librespot[4875]: time="2026-02-25T03:48:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:48:17 volumio volumio[4768]: info: Loading plugin "outputs"... Feb 25 03:48:17 volumio volumio[4768]: info: Loading plugin "albumart"... Feb 25 03:48:17 volumio volumio[4768]: info: Plugin example_plugin is not enabled Feb 25 03:48:17 volumio volumio[4768]: info: Loading plugin "inputs"... Feb 25 03:48:17 volumio volumio[4768]: info: Loading plugin "updater_comm"... Feb 25 03:48:17 volumio volumio[4768]: info: Plugin mpdemulation is not enabled Feb 25 03:48:17 volumio volumio[4768]: info: Loading plugin "rest_api"... Feb 25 03:48:17 volumio volumio[4768]: info: Loading plugin "websocket"... Feb 25 03:48:17 volumio volumio[4768]: info: Starting Socket.io Server version 1.7.4 Feb 25 03:48:17 volumio volumio[4768]: info: Loading plugin "RoonBridge"... Feb 25 03:48:17 volumio go-librespot[4875]: time="2026-02-25T03:48:17+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 03:48:17 volumio go-librespot[4875]: time="2026-02-25T03:48:17+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 25 03:48:17 volumio go-librespot[4875]: time="2026-02-25T03:48:17+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 25 03:48:17 volumio go-librespot[4875]: time="2026-02-25T03:48:17+07:00" level=info msg="zeroconf server listening on port 38049" Feb 25 03:48:18 volumio go-librespot[4875]: time="2026-02-25T03:48:18+07:00" level=debug msg="obtained new client token: AAAA9SBIhlgKZRt8Pl6clMNDGFruFshKk6n/ArxSW73cthk18glibMSA1sR7lLLRCDXz6CFylZw8IQnDqrRJTzj6Y9PD5MagW5U6BoPaO95rOdXXzoqDeD0bGyngqhbjQN90Hm8TzosB08fdbPUfqIOIuwFhjoN9T7f0GzSgJiOJHXIG/zDPmGgCQIvHRPQbTSUSFMvK2uxZcILBT56EnlKGspRinKfu6McsRyD3JPboxv+V2ByRbuM=" Feb 25 03:48:18 volumio go-librespot[4875]: time="2026-02-25T03:48:18+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 25 03:48:18 volumio go-librespot[4875]: time="2026-02-25T03:48:18+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Feb 25 03:48:18 volumio volumio[4768]: info: Applying required configuration parameters for plugin RoonBridge Feb 25 03:48:18 volumio go-librespot[4875]: time="2026-02-25T03:48:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 25 03:48:18 volumio volumio[4768]: info: Loading i18n strings for locale en Feb 25 03:48:18 volumio volumio[4768]: Updating browse sources language Feb 25 03:48:18 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 03:48:18 volumio go-librespot[4875]: time="2026-02-25T03:48:18+07:00" level=debug msg="completed keyexchange" Feb 25 03:48:18 volumio go-librespot[4875]: time="2026-02-25T03:48:18+07:00" level=debug msg="completed challenge" Feb 25 03:48:18 volumio go-librespot[4875]: time="2026-02-25T03:48:18+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 25 03:48:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:48:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:48:18 volumio volumio[4881]: Forking 3 albumart workers Feb 25 03:48:18 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 03:48:18 volumio volumio[4768]: info: CoreCommandRouter::initPlayerControls Feb 25 03:48:18 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:48:18 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:48:18 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:48:18 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:48:18 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:48:18 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:48:18 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:48:18 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:48:18 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 03:48:18 volumio volumio[4768]: Express server listening on port 3000 Feb 25 03:48:18 volumio volumio[4768]: [Metrics] WebUI: 16s 577.13ms Feb 25 03:48:18 volumio volumio[4768]: info: CoreStateMachine::resetVolumioState Feb 25 03:48:18 volumio volumio[4768]: info: CoreStateMachine::getcurrentVolume Feb 25 03:48:18 volumio volumio[4768]: info: CoreCommandRouter::volumioRetrievevolume Feb 25 03:48:19 volumio sudo[4924]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 25 03:48:19 volumio sudo[4924]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:48:19 volumio sudo[4926]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 25 03:48:19 volumio sudo[4924]: pam_unix(sudo:session): session closed for user root Feb 25 03:48:19 volumio sudo[4926]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:48:19 volumio sudo[4926]: pam_unix(sudo:session): session closed for user root Feb 25 03:48:19 volumio volumio[4768]: info: Volumio Network Manager: Network status updated: 1 Feb 25 03:48:19 volumio volumio[4768]: info: VolumeController:: Volume=100 Mute =false Feb 25 03:48:19 volumio volumio[4768]: info: CoreStateMachine::pushState Feb 25 03:48:19 volumio volumio[4768]: info: CorePlayQueue::getTrack 0 Feb 25 03:48:19 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 03:48:19 volumio volumio[4768]: info: CoreCommandRouter::volumioPushState Feb 25 03:48:19 volumio volumio[4768]: info: CoreStateMachine::updateTrackBlock Feb 25 03:48:19 volumio volumio[4768]: info: CorePlayQueue::getTrackBlock Feb 25 03:48:19 volumio volumio[4768]: info: CoreCommandRouter::volumioRetrievevolume Feb 25 03:48:19 volumio volumio-remote-updater[647]: [2026-02-25 03:48:19] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771966096 101 Feb 25 03:48:19 volumio volumio[4768]: 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 25 03:48:19 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:48:19 volumio volumio[4768]: info: Reloading queue from file Feb 25 03:48:19 volumio volumio[4768]: info: CoreStateMachine::setRepeat null single undefined Feb 25 03:48:19 volumio volumio[4768]: info: CoreStateMachine::pushState Feb 25 03:48:19 volumio volumio[4768]: info: CorePlayQueue::getTrack 0 Feb 25 03:48:19 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 03:48:19 volumio volumio[4768]: info: CoreCommandRouter::volumioPushState Feb 25 03:48:19 volumio volumio[4768]: info: CoreStateMachine::setRandom null Feb 25 03:48:19 volumio volumio[4768]: info: CoreStateMachine::pushState Feb 25 03:48:19 volumio volumio[4768]: info: CorePlayQueue::getTrack 0 Feb 25 03:48:19 volumio volumio[4768]: info: CoreCommandRouter::volumioPushState Feb 25 03:48:19 volumio volumio[4768]: info: Setting Device type: Raspberry PI Feb 25 03:48:20 volumio volumio[4768]: info: Completed loading Core Plugins Feb 25 03:48:20 volumio volumio[4768]: info: Preparing to generate the ALSA configuration file Feb 25 03:48:20 volumio volumio[4768]: info: VolumeController:: Volume=100 Mute =false Feb 25 03:48:20 volumio volumio[4768]: info: CoreStateMachine::pushState Feb 25 03:48:20 volumio volumio[4768]: info: CorePlayQueue::getTrack 0 Feb 25 03:48:20 volumio volumio[4768]: info: CoreCommandRouter::volumioPushState Feb 25 03:48:20 volumio volumio[4768]: info: Asound.conf file unchanged, so no further update is needed Feb 25 03:48:20 volumio volumio[4768]: info: Output device has changed, restarting MPD Feb 25 03:48:20 volumio sudo[4942]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 25 03:48:20 volumio volumio[4768]: info: Output device has changed, restarting Shairport Sync Feb 25 03:48:20 volumio sudo[4942]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:48:20 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:48:20 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:48:20 volumio sudo[4944]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 25 03:48:20 volumio sudo[4944]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:48:20 volumio sudo[4944]: pam_unix(sudo:session): session closed for user root Feb 25 03:48:20 volumio volumio[4768]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 25 03:48:20 volumio volumio[4768]: info: ___________ START PLUGINS ___________ Feb 25 03:48:20 volumio sudo[4942]: pam_unix(sudo:session): session closed for user root Feb 25 03:48:20 volumio volumio[4768]: info: ControllerMpd::onStart: Initializing MPD Feb 25 03:48:20 volumio sudo[4946]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 25 03:48:20 volumio volumio[4768]: info: Creating MPD Configuration file Feb 25 03:48:20 volumio sudo[4946]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:48:20 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 03:48:20 volumio volumio[4768]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 03:48:20 volumio volumio[4768]: info: [1771966100679] CoreMusicLibrary::Adding element Media Servers Feb 25 03:48:20 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 03:48:20 volumio volumio[4768]: info: UPNP Browser: Client initialized successfully Feb 25 03:48:20 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 25 03:48:20 volumio sudo[4955]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 25 03:48:20 volumio sudo[4955]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:48:20 volumio sudo[4955]: pam_unix(sudo:session): session closed for user root Feb 25 03:48:20 volumio sudo[4957]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 25 03:48:20 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:48:20 volumio sudo[4957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:48:20 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:48:20 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 25 03:48:20 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 25 03:48:20 volumio systemd[1]: mpd.service: Consumed 6.884s CPU time. Feb 25 03:48:20 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 25 03:48:20 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 25 03:48:20 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 25 03:48:20 volumio volumio[4768]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 25 03:48:20 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:48:20 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:48:20 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 25 03:48:21 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 25 03:48:21 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 25 03:48:21 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 25 03:48:21 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 25 03:48:21 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 25 03:48:21 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 25 03:48:21 volumio volumio[4768]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 25 03:48:21 volumio volumio[4768]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 03:48:21 volumio volumio[4768]: info: [1771966101135] CoreMusicLibrary::Adding element Last_100 Feb 25 03:48:21 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 03:48:21 volumio volumio[4768]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 03:48:21 volumio volumio[4768]: info: [1771966101154] CoreMusicLibrary::Adding element Webradio Feb 25 03:48:21 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 03:48:21 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 25 03:48:21 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 25 03:48:21 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 25 03:48:21 volumio volumio[4768]: info: Initializing BBC Radios Feb 25 03:48:21 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 25 03:48:21 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:48:21 volumio volumio[4768]: info: Creating Spotify config file Feb 25 03:48:21 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:48:21 volumio sudo[4971]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 25 03:48:21 volumio sudo[4971]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 25 03:48:21 volumio sudo[4971]: pam_unix(sudo:session): session closed for user root Feb 25 03:48:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 25 03:48:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:48:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:48:21 volumio go-librespot[4987]: go-librespot daemon starting... Feb 25 03:48:22 volumio go-librespot[4988]: time="2026-02-25T03:48:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:48:22 volumio volumio[4893]: Starting albumart workers Feb 25 03:48:22 volumio go-librespot[4988]: time="2026-02-25T03:48:22+07:00" level=info msg="zeroconf server listening on port 33025" Feb 25 03:48:23 volumio volumio[4768]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 03:48:23 volumio volumio[4768]: info: [1771966103462] CoreMusicLibrary::Adding element YouTube Music Feb 25 03:48:23 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 03:48:23 volumio volumio[4768]: Cannot find translation for source YouTube Music Feb 25 03:48:23 volumio volumio[4892]: Starting albumart workers Feb 25 03:48:23 volumio volumio[4768]: info: Volumio Calling Home Feb 25 03:48:23 volumio sudo[4997]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 25 03:48:23 volumio sudo[4997]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:48:23 volumio sudo[4997]: pam_unix(sudo:session): session closed for user root Feb 25 03:48:23 volumio volumio[4894]: Starting albumart workers Feb 25 03:48:24 volumio volumio[4768]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 25 03:48:25 volumio volumio[4768]: info: Discovery: Found device Volumio Feb 25 03:48:25 volumio volumio[4768]: info: CoreCommandRouter::volumioGetState Feb 25 03:48:25 volumio volumio[4768]: info: CorePlayQueue::getTrack 0 Feb 25 03:48:25 volumio volumio[4768]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 25 03:48:25 volumio volumio[4768]: info: Discovery: Found device Volumio Feb 25 03:48:25 volumio volumio[4768]: info: CoreCommandRouter::volumioGetState Feb 25 03:48:25 volumio volumio[4768]: info: CorePlayQueue::getTrack 0 Feb 25 03:48:25 volumio volumio[4768]: info: MPD Permissions set Feb 25 03:48:25 volumio volumio[4768]: info: MPD Permissions set Feb 25 03:48:25 volumio volumio[4768]: info: Upmpdcli Daemon Started Feb 25 03:48:25 volumio volumio[4768]: info: Volumio called home Feb 25 03:48:25 volumio volumio[4768]: info: Spotify config file written Feb 25 03:48:25 volumio volumio[4768]: 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 25 03:48:25 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:48:25 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:48:25 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:48:25 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:48:25 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:48:25 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:48:25 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:48:25 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:48:25 volumio sudo[5004]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 25 03:48:25 volumio sudo[5004]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:48:25 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:48:25 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:48:25 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:48:25 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:48:25 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:48:25 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:48:25 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:48:25 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:48:25 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:48:25 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:48:25 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 25 03:48:25 volumio systemd[1]: go-librespot-daemon.service: Killing process 4993 (go-librespot) with signal SIGKILL. Feb 25 03:48:25 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 25 03:48:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:48:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:48:25 volumio go-librespot[5021]: go-librespot daemon starting... Feb 25 03:48:25 volumio sudo[5004]: pam_unix(sudo:session): session closed for user root Feb 25 03:48:25 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:48:25 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:48:25 volumio go-librespot[5024]: time="2026-02-25T03:48:25+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:48:25 volumio go-librespot[5024]: time="2026-02-25T03:48:25+07:00" level=debug msg="app state loaded" Feb 25 03:48:25 volumio volumio[4768]: info: No need to fix Spotify hosts Feb 25 03:48:25 volumio go-librespot[5024]: time="2026-02-25T03:48:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:48:26 volumio go-librespot[5024]: time="2026-02-25T03:48:26+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 25 03:48:26 volumio go-librespot[5024]: time="2026-02-25T03:48:26+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 25 03:48:26 volumio go-librespot[5024]: time="2026-02-25T03:48:26+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 25 03:48:26 volumio go-librespot[5024]: time="2026-02-25T03:48:26+07:00" level=info msg="zeroconf server listening on port 36757" Feb 25 03:48:26 volumio go-librespot[5024]: time="2026-02-25T03:48:26+07:00" level=debug msg="obtained new client token: AACEvHGJr9TLwgH1VSY2cp4P5UtttmP5z8HNIwBLc9O4HVxWkFRv6uCQQJ9k3oJ+Fb0ilXyh0j/nHXG9jkzENb7hMMpfN4yTVPIAZXVLJH+8/w6Eaoptj8VvOv4lq1bSis8KE4A9Z7tnFPeK0aGu18rAHBkQkeEVbLMknEuz31frCLdXsEYg33WQlWvYtFuHCjQ/aofN8J1+/2QAqijsEiHNHmKI2Q4xTlWg0vHJBZ0ZAA2ckVe+wdWoOw==" Feb 25 03:48:27 volumio volumio[4768]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 25 03:48:27 volumio volumio[4768]: SPOTIFY: BQBj4XEEAM5PMnNGcqcx5IbqqksWrauJwfhlVpZhcWY1SYaYYpouPQyzPQjN_EKDIEr5fCJ9aOdIqxAtMzl-vw5XfbNgLTpIkzbKr_feZlFg5OMSkbDCTP3tiHUgfQFQG1K0zVvenxW9F2HvNPYiPl1MSv3lSsitP6EqjQkQfbpO1h4Cwz6QFbUo3o5jXJ2CWG5vnHSdg2PWbZ6Iad3JO8NK1JLv0ZCjc6N3NzeQeV0fhGBqZxnHAWyANBc38STsZnDqmZFuYm5Oi3XMsnbufTTXjPLwF9_pO7m2OLEjgE-GFDCUxw9FWBh9 Feb 25 03:48:27 volumio volumio[4768]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 25 03:48:27 volumio volumio[4768]: info: New Spotify access token = BQBj4XEEAM5PMnNGcqcx5IbqqksWrauJwfhlVpZhcWY1SYaYYpouPQyzPQjN_EKDIEr5fCJ9aOdIqxAtMzl-vw5XfbNgLTpIkzbKr_feZlFg5OMSkbDCTP3tiHUgfQFQG1K0zVvenxW9F2HvNPYiPl1MSv3lSsitP6EqjQkQfbpO1h4Cwz6QFbUo3o5jXJ2CWG5vnHSdg2PWbZ6Iad3JO8NK1JLv0ZCjc6N3NzeQeV0fhGBqZxnHAWyANBc38STsZnDqmZFuYm5Oi3XMsnbufTTXjPLwF9_pO7m2OLEjgE-GFDCUxw9FWBh9 Feb 25 03:48:27 volumio volumio[4768]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 25 03:48:27 volumio go-librespot[5024]: time="2026-02-25T03:48:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:48:27 volumio volumio[4768]: info: Starting Shairport Sync Feb 25 03:48:27 volumio volumio[4768]: info: Starting Shairport Sync Feb 25 03:48:27 volumio volumio[4768]: info: Starting Shairport Sync Feb 25 03:48:27 volumio go-librespot[5024]: time="2026-02-25T03:48:27+07:00" level=debug msg="completed keyexchange" Feb 25 03:48:27 volumio go-librespot[5024]: time="2026-02-25T03:48:27+07:00" level=debug msg="completed challenge" Feb 25 03:48:27 volumio sudo[5043]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 25 03:48:27 volumio sudo[5043]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:48:27 volumio go-librespot[5024]: time="2026-02-25T03:48:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 25 03:48:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:48:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:48:27 volumio sudo[5049]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 25 03:48:27 volumio sudo[5049]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:48:27 volumio sudo[5056]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 25 03:48:27 volumio sudo[5056]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:48:27 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 25 03:48:27 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 25 03:48:27 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 25 03:48:27 volumio systemd[1]: shairport-sync.service: Consumed 2.245s CPU time. Feb 25 03:48:27 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 25 03:48:27 volumio sudo[5043]: pam_unix(sudo:session): session closed for user root Feb 25 03:48:27 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 25 03:48:27 volumio volumio[4768]: info: Shairport-Sync Started Feb 25 03:48:27 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 25 03:48:27 volumio volumio[4768]: Error adding Membership: Error: addMembership EINVAL Feb 25 03:48:27 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 25 03:48:27 volumio volumio[4768]: info: CoreCommandRouter::volumioGetState Feb 25 03:48:27 volumio volumio[4768]: info: CorePlayQueue::getTrack 0 Feb 25 03:48:27 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 25 03:48:27 volumio sudo[5049]: pam_unix(sudo:session): session closed for user root Feb 25 03:48:27 volumio sudo[5056]: pam_unix(sudo:session): session closed for user root Feb 25 03:48:28 volumio volumio[4768]: info: Shairport-Sync Started Feb 25 03:48:28 volumio volumio[4768]: info: Shairport-Sync Started Feb 25 03:48:28 volumio volumio[4768]: 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 25 03:48:28 volumio volumio[4768]: info: Spotify Successfully logged in Feb 25 03:48:28 volumio volumio[4768]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 03:48:28 volumio volumio[4768]: info: [1771966108270] CoreMusicLibrary::Adding element Spotify Feb 25 03:48:28 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 03:48:28 volumio volumio[4768]: Cannot find translation for source YouTube Music Feb 25 03:48:28 volumio volumio[4768]: Cannot find translation for source Spotify Feb 25 03:48:28 volumio mpd[4986]: 2026-02-25T03:48:28 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 25 03:48:28 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 25 03:48:28 volumio sudo[4946]: pam_unix(sudo:session): session closed for user root Feb 25 03:48:28 volumio sudo[4957]: pam_unix(sudo:session): session closed for user root Feb 25 03:48:28 volumio volumio[4768]: error: MPD error: The expression evaluated to a falsy value: Feb 25 03:48:28 volumio volumio[4768]: assert.ok(self.idling) Feb 25 03:48:28 volumio volumio[4768]: error: The expression evaluated to a falsy value: Feb 25 03:48:28 volumio volumio[4768]: assert.ok(self.idling) Feb 25 03:48:28 volumio volumio[4768]: info: MPD running with PID4986 Feb 25 03:48:28 volumio volumio[4768]: ,establishing connection Feb 25 03:48:28 volumio volumio[4768]: error: updateQueue error: null Feb 25 03:48:28 volumio volumio[4768]: error: updateQueue error: null Feb 25 03:48:29 volumio volumio[4768]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 25 03:48:29 volumio volumio[4768]: info: CoreCommandRouter::volumioRetrievevolume Feb 25 03:48:29 volumio volumio[4768]: info: VolumeController:: Volume=100 Mute =false Feb 25 03:48:29 volumio volumio[4768]: info: CoreCommandRouter::volumioGetState Feb 25 03:48:29 volumio volumio[4768]: info: CorePlayQueue::getTrack 0 Feb 25 03:48:29 volumio volumio[4768]: info: CoreStateMachine::pushState Feb 25 03:48:29 volumio volumio[4768]: info: CorePlayQueue::getTrack 0 Feb 25 03:48:29 volumio volumio[4768]: info: CoreCommandRouter::volumioPushState Feb 25 03:48:29 volumio volumio[4768]: info: Completed starting Core Plugins Feb 25 03:48:29 volumio volumio[4768]: info: ------------------------------------------- Feb 25 03:48:29 volumio volumio[4768]: info: ----- MyVolumio plugins startup ---- Feb 25 03:48:29 volumio volumio[4768]: info: ------------------------------------------- Feb 25 03:48:29 volumio volumio[4768]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 25 03:48:29 volumio volumio[4768]: info: go-librespot daemon successfully initialized Feb 25 03:48:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 25 03:48:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:48:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:48:30 volumio go-librespot[5101]: go-librespot daemon starting... Feb 25 03:48:30 volumio go-librespot[5102]: time="2026-02-25T03:48:30+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:48:30 volumio go-librespot[5102]: time="2026-02-25T03:48:30+07:00" level=debug msg="app state loaded" Feb 25 03:48:30 volumio go-librespot[5102]: time="2026-02-25T03:48:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:48:31 volumio go-librespot[5102]: time="2026-02-25T03:48:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 25 03:48:31 volumio go-librespot[5102]: time="2026-02-25T03:48:31+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 25 03:48:31 volumio go-librespot[5102]: time="2026-02-25T03:48:31+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 25 03:48:31 volumio go-librespot[5102]: time="2026-02-25T03:48:31+07:00" level=info msg="zeroconf server listening on port 34971" Feb 25 03:48:31 volumio go-librespot[5102]: time="2026-02-25T03:48:31+07:00" level=debug msg="obtained new client token: AAAfE/SwNKK9pvX+U2UrBWgvWYg/wA8UjGX1OmVyZD76jj/ONBDlO8C6XoxSymv8pamY3dShwnA9zQoq4lNttnxeEFHSaD0OMwY+Mi4G0Gl9FiCU00CUN496b269ujJ2LGQ1tHim7iR3/YVhwwa8jXXXW+4LC3hArgpNg2unU+o9CX53F2gkDT8RLThvWVD1K7BT4QnvdmxpKh1MVqFstZfa1AdUKfFLBeXa8WZZMMnT59J9jYjruQHPgA==" Feb 25 03:48:31 volumio go-librespot[5102]: time="2026-02-25T03:48:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:48:31 volumio go-librespot[5102]: time="2026-02-25T03:48:31+07:00" level=debug msg="completed keyexchange" Feb 25 03:48:31 volumio go-librespot[5102]: time="2026-02-25T03:48:31+07:00" level=debug msg="completed challenge" Feb 25 03:48:31 volumio go-librespot[5102]: time="2026-02-25T03:48:31+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 25 03:48:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:48:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:48:32 volumio volumio[4768]: info: Initializing connection to go-librespot Websocket Feb 25 03:48:33 volumio volumio[4768]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 03:48:33 volumio volumio[4768]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 25 03:48:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 25 03:48:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:48:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:48:35 volumio go-librespot[5110]: go-librespot daemon starting... Feb 25 03:48:35 volumio go-librespot[5111]: time="2026-02-25T03:48:35+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:48:35 volumio go-librespot[5111]: time="2026-02-25T03:48:35+07:00" level=debug msg="app state loaded" Feb 25 03:48:35 volumio go-librespot[5111]: time="2026-02-25T03:48:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:48:35 volumio go-librespot[5111]: time="2026-02-25T03:48:35+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 03:48:35 volumio go-librespot[5111]: time="2026-02-25T03:48:35+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 25 03:48:35 volumio go-librespot[5111]: time="2026-02-25T03:48:35+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 25 03:48:35 volumio go-librespot[5111]: time="2026-02-25T03:48:35+07:00" level=info msg="zeroconf server listening on port 41137" Feb 25 03:48:36 volumio volumio[4768]: info: Initializing connection to go-librespot Websocket Feb 25 03:48:36 volumio go-librespot[5111]: time="2026-02-25T03:48:36+07:00" level=debug msg="new websocket client" Feb 25 03:48:36 volumio go-librespot[5111]: time="2026-02-25T03:48:36+07:00" level=debug msg="obtained new client token: AABzUIhFSJgikOePjIT2CUX1oZQWc+SIcy5ednTB7fwdb95EELyRNf9mo4E798zovKE8wP/hOqbCUQ+YnBPTTvMpIPdgGkhgCxcCDRoioDwuNw+HOrlhkHVC2/nK1ec3QLZPkO+MDKtxaOQLv31TgILC0ViDTr5CRDpOPH69+nXmFBPl6K/amznXzbeop06BJBiHD0pOAtoxVwkP7JGs35nJXPGVz3iYEMCYANHQ6UfswFk5OPJdPaKmww==" Feb 25 03:48:36 volumio volumio[4768]: info: Connection to go-librespot Websocket established Feb 25 03:48:36 volumio go-librespot[5111]: time="2026-02-25T03:48:36+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 25 03:48:36 volumio go-librespot[5111]: time="2026-02-25T03:48:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 25 03:48:36 volumio go-librespot[5111]: time="2026-02-25T03:48:36+07:00" level=debug msg="completed keyexchange" Feb 25 03:48:36 volumio go-librespot[5111]: time="2026-02-25T03:48:36+07:00" level=debug msg="completed challenge" Feb 25 03:48:36 volumio go-librespot[5111]: time="2026-02-25T03:48:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 25 03:48:36 volumio volumio[4768]: info: Connection to go-librespot Websocket closed Feb 25 03:48:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:48:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:48:38 volumio volumio[4768]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 25 03:48:38 volumio volumio[4768]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 25 03:48:38 volumio volumio[4768]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 25 03:48:38 volumio volumio[4768]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 25 03:48:38 volumio volumio[4768]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 25 03:48:38 volumio volumio[4768]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 25 03:48:38 volumio volumio[4768]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 25 03:48:38 volumio volumio[4768]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 25 03:48:38 volumio volumio[4768]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 25 03:48:38 volumio volumio[4768]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 25 03:48:38 volumio volumio[4768]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 25 03:48:38 volumio volumio[4768]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 25 03:48:38 volumio volumio[4768]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 25 03:48:38 volumio volumio[4768]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 25 03:48:38 volumio volumio[4768]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 25 03:48:38 volumio volumio[4768]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 25 03:48:38 volumio volumio[4768]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 25 03:48:38 volumio volumio[4768]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 25 03:48:38 volumio volumio[4768]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 25 03:48:38 volumio volumio[4768]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 25 03:48:38 volumio volumio[4768]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 25 03:48:38 volumio volumio[4768]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 25 03:48:38 volumio volumio[4768]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 25 03:48:38 volumio volumio[4768]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 25 03:48:38 volumio volumio[4768]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 25 03:48:38 volumio volumio[4768]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 25 03:48:38 volumio volumio[4768]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 25 03:48:38 volumio volumio[4768]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 25 03:48:38 volumio volumio[4768]: info: Adding plugin bluetooth to MyMusic Plugins Feb 25 03:48:38 volumio volumio[4768]: info: Adding plugin multiroom to MyMusic Plugins Feb 25 03:48:38 volumio volumio[4768]: info: Adding plugin metavolumio to MyMusic Plugins Feb 25 03:48:38 volumio volumio[4768]: info: Adding plugin cd_controller to MyMusic Plugins Feb 25 03:48:38 volumio volumio[4768]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 25 03:48:38 volumio volumio[4768]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 25 03:48:38 volumio volumio[4768]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 25 03:48:38 volumio volumio[4768]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 25 03:48:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 25 03:48:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:48:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:48:39 volumio go-librespot[5132]: go-librespot daemon starting... Feb 25 03:48:39 volumio go-librespot[5133]: time="2026-02-25T03:48:39+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:48:39 volumio go-librespot[5133]: time="2026-02-25T03:48:39+07:00" level=debug msg="app state loaded" Feb 25 03:48:39 volumio go-librespot[5133]: time="2026-02-25T03:48:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:48:40 volumio go-librespot[5133]: time="2026-02-25T03:48: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 25 03:48:40 volumio go-librespot[5133]: time="2026-02-25T03:48: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 25 03:48:40 volumio go-librespot[5133]: time="2026-02-25T03:48: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 25 03:48:40 volumio go-librespot[5133]: time="2026-02-25T03:48:40+07:00" level=info msg="zeroconf server listening on port 34389" Feb 25 03:48:40 volumio volumio[4768]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 25 03:48:40 volumio volumio[4768]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 25 03:48:40 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:48:40 volumio volumio[4768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:48:40 volumio volumio[4768]: info: Starting MyVolumio Remote Streaming Endpoints Feb 25 03:48:40 volumio volumio[4768]: info: MyVolumio login type: Token Feb 25 03:48:40 volumio go-librespot[5133]: time="2026-02-25T03:48:40+07:00" level=debug msg="obtained new client token: AADfc4yZE2Zo9fU5TPGqzKm+e6J2X+ECgyV1CPJ4WNimcV5+FATYKvtc313wLCQKXjHQsRyDMuHH4TH5nN/M1tMKhtZM/hA0rbwQVX6g9Cj/y9JHdb7TWc674l9eoTwfJHIQ6VG76Ow0/iEri7iQuvk+UB36RxhUqg6UDbnt8zx4xKmWMLaGVG4qlsLoOKb/6FeJcbcTvF1IiB8qxl2LYcmFatjYLhHeJyWiuZ9Owoy37elzOVDrTCzNhQ==" Feb 25 03:48:40 volumio volumio[4768]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 25 03:48:40 volumio volumio[4768]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 25 03:48:40 volumio go-librespot[5133]: time="2026-02-25T03:48:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:48:40 volumio go-librespot[5133]: time="2026-02-25T03:48:40+07:00" level=debug msg="completed keyexchange" Feb 25 03:48:40 volumio go-librespot[5133]: time="2026-02-25T03:48:40+07:00" level=debug msg="completed challenge" Feb 25 03:48:40 volumio go-librespot[5133]: time="2026-02-25T03:48:40+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 25 03:48:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:48:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:48:42 volumio volumio[4768]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 25 03:48:42 volumio volumio[4768]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 25 03:48:42 volumio volumio[4768]: info: Streaming services startup Feb 25 03:48:42 volumio volumio[4768]: info: Starting Streaming Daemon Feb 25 03:48:42 volumio sudo[5143]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 25 03:48:42 volumio sudo[5143]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:48:42 volumio volumio[4768]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 25 03:48:42 volumio sudo[5143]: pam_unix(sudo:session): session closed for user root Feb 25 03:48:42 volumio volumio[4768]: info: Getting Spotify volume Feb 25 03:48:42 volumio volumio[4768]: info: Initializing connection to go-librespot Websocket Feb 25 03:48:42 volumio volumio[4768]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 25 03:48:42 volumio volumio[4768]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 03:48:42 volumio volumio[4768]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 25 03:48:42 volumio volumio[4768]: errno: -111, Feb 25 03:48:42 volumio volumio[4768]: code: 'ECONNREFUSED', Feb 25 03:48:42 volumio volumio[4768]: syscall: 'connect', Feb 25 03:48:42 volumio volumio[4768]: address: '127.0.0.1', Feb 25 03:48:42 volumio volumio[4768]: port: 9879, Feb 25 03:48:42 volumio volumio[4768]: response: undefined Feb 25 03:48:42 volumio volumio[4768]: } Feb 25 03:48:42 volumio volumio[4768]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 25 03:48:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 25 03:48:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:48:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:48:44 volumio go-librespot[5163]: go-librespot daemon starting... Feb 25 03:48:44 volumio go-librespot[5164]: time="2026-02-25T03:48:44+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:48:44 volumio go-librespot[5164]: time="2026-02-25T03:48:44+07:00" level=debug msg="app state loaded" Feb 25 03:48:44 volumio go-librespot[5164]: time="2026-02-25T03:48:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:48:44 volumio sudo[5172]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-25 03:47' Feb 25 03:48:44 volumio sudo[5172]: 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"