Feb 11 19:53:00 volumio volumio[20218]: info: VolumeController:: Volume=100 Mute =false Feb 11 19:53:00 volumio volumio[20218]: info: CoreCommandRouter::volumioGetState Feb 11 19:53:00 volumio volumio[20218]: info: CorePlayQueue::getTrack 0 Feb 11 19:53:00 volumio volumio[20218]: info: CoreStateMachine::pushState Feb 11 19:53:00 volumio volumio[20218]: info: CorePlayQueue::getTrack 0 Feb 11 19:53:00 volumio volumio[20218]: info: CoreCommandRouter::volumioPushState Feb 11 19:53:01 volumio volumio[20218]: info: go-librespot daemon successfully initialized Feb 11 19:53:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 11 19:53:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:53:01 volumio mpd[20442]: 2026-02-11T19:53:01 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 11 19:53:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:53:01 volumio go-librespot[20541]: go-librespot daemon starting... Feb 11 19:53:01 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 11 19:53:01 volumio sudo[20413]: pam_unix(sudo:session): session closed for user root Feb 11 19:53:01 volumio sudo[20402]: pam_unix(sudo:session): session closed for user root Feb 11 19:53:01 volumio go-librespot[20544]: time="2026-02-11T19:53:01+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 19:53:01 volumio go-librespot[20544]: time="2026-02-11T19:53:01+07:00" level=debug msg="app state loaded" Feb 11 19:53:01 volumio go-librespot[20544]: time="2026-02-11T19:53:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 19:53:02 volumio volumio[20218]: error: MPD error: The expression evaluated to a falsy value: Feb 11 19:53:02 volumio volumio[20218]: assert.ok(self.idling) Feb 11 19:53:02 volumio volumio[20218]: error: The expression evaluated to a falsy value: Feb 11 19:53:02 volumio volumio[20218]: assert.ok(self.idling) Feb 11 19:53:02 volumio volumio[20218]: info: MPD running with PID20442 Feb 11 19:53:02 volumio volumio[20218]: ,establishing connection Feb 11 19:53:02 volumio volumio[20218]: error: updateQueue error: null Feb 11 19:53:02 volumio volumio[20218]: info: Completed starting Core Plugins Feb 11 19:53:02 volumio volumio[20218]: info: ------------------------------------------- Feb 11 19:53:02 volumio volumio[20218]: info: ----- MyVolumio plugins startup ---- Feb 11 19:53:02 volumio volumio[20218]: info: ------------------------------------------- Feb 11 19:53:02 volumio volumio[20218]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 11 19:53:02 volumio volumio[20218]: error: updateQueue error: null Feb 11 19:53:02 volumio go-librespot[20544]: time="2026-02-11T19:53:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 19:53:02 volumio go-librespot[20544]: time="2026-02-11T19:53:02+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 11 19:53:02 volumio go-librespot[20544]: time="2026-02-11T19:53:02+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 11 19:53:02 volumio go-librespot[20544]: time="2026-02-11T19:53:02+07:00" level=info msg="zeroconf server listening on port 44497" Feb 11 19:53:02 volumio go-librespot[20544]: time="2026-02-11T19:53:02+07:00" level=debug msg="obtained new client token: AAAb0mcZaHtXGcaKHyGSJGfifG3rPEicHe1W2zwgrg1zn09AgVX/tyVDvfnNDo+s22dl2plVHLeBuEfpyCmD7fdvvnCX7W9h71PwmCmbb6Tp0WLVhvdzXPl7EoVu+A8ZBt+qnftjMTmtw3lGtq8sAvk1GrolwpvYuTZnRy1D1P/+WRpFPvD9wvyL3L27GX6FmWI8FnOOF+604gyAjlfwwpl6oYgY7hJEvry3mE7Hlk0WHLvCkXZHsx+OTw==" Feb 11 19:53:02 volumio go-librespot[20544]: time="2026-02-11T19:53:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 19:53:02 volumio go-librespot[20544]: time="2026-02-11T19:53:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 19:53:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 19:53:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 19:53:04 volumio volumio[20218]: info: Initializing connection to go-librespot Websocket Feb 11 19:53:04 volumio volumio[20218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 19:53:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 11 19:53:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:53:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:53:06 volumio go-librespot[20553]: go-librespot daemon starting... Feb 11 19:53:06 volumio go-librespot[20554]: time="2026-02-11T19:53:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 19:53:06 volumio go-librespot[20554]: time="2026-02-11T19:53:06+07:00" level=debug msg="app state loaded" Feb 11 19:53:06 volumio go-librespot[20554]: time="2026-02-11T19:53:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 19:53:06 volumio go-librespot[20554]: time="2026-02-11T19:53:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 11 19:53:06 volumio go-librespot[20554]: time="2026-02-11T19:53:06+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 11 19:53:06 volumio go-librespot[20554]: time="2026-02-11T19:53:06+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 11 19:53:06 volumio go-librespot[20554]: time="2026-02-11T19:53:06+07:00" level=info msg="zeroconf server listening on port 44993" Feb 11 19:53:06 volumio go-librespot[20554]: time="2026-02-11T19:53:06+07:00" level=debug msg="obtained new client token: AABveJt/NrmuwFOwrjye8+hKkXb2fnfb0ylJ1QUf/wqFuQt3IUlZhsu89Bn/Sj08WE0D9IQ/n4FgG5ZXybbtiecYI6foFt7X4mdmieKgbJeRLtNoN8LVHNBxWqiru1QohHA+ZAhra9HEc18FveUFkw3zeAa7uvuhrGvskIpz1DregMbT2Z45sh0185kCMPxtBt63YKJ61H3oW4Y0y937123d6C059QCIuuWSiVEyXbnga8ng3Gq3vKT9qA==" Feb 11 19:53:06 volumio go-librespot[20554]: time="2026-02-11T19:53:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 19:53:06 volumio volumio[20218]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 11 19:53:07 volumio go-librespot[20554]: time="2026-02-11T19:53:07+07:00" level=debug msg="completed keyexchange" Feb 11 19:53:07 volumio go-librespot[20554]: time="2026-02-11T19:53:07+07:00" level=debug msg="completed challenge" Feb 11 19:53:07 volumio go-librespot[20554]: time="2026-02-11T19:53:07+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 11 19:53:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 19:53:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 19:53:07 volumio volumio[20218]: info: Initializing connection to go-librespot Websocket Feb 11 19:53:07 volumio volumio[20218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 19:53:10 volumio volumio[20218]: info: Initializing connection to go-librespot Websocket Feb 11 19:53:10 volumio volumio[20218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 19:53:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 11 19:53:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:53:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:53:10 volumio go-librespot[20561]: go-librespot daemon starting... Feb 11 19:53:10 volumio go-librespot[20562]: time="2026-02-11T19:53:10+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 19:53:10 volumio go-librespot[20562]: time="2026-02-11T19:53:10+07:00" level=debug msg="app state loaded" Feb 11 19:53:10 volumio go-librespot[20562]: time="2026-02-11T19:53:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 19:53:10 volumio go-librespot[20562]: time="2026-02-11T19:53:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 11 19:53:10 volumio go-librespot[20562]: time="2026-02-11T19:53:10+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 11 19:53:10 volumio go-librespot[20562]: time="2026-02-11T19:53:10+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 11 19:53:10 volumio go-librespot[20562]: time="2026-02-11T19:53:10+07:00" level=info msg="zeroconf server listening on port 37349" Feb 11 19:53:10 volumio volumio[20218]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 11 19:53:10 volumio volumio[20218]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 11 19:53:10 volumio volumio[20218]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 11 19:53:10 volumio volumio[20218]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 11 19:53:10 volumio volumio[20218]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 11 19:53:10 volumio volumio[20218]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 11 19:53:10 volumio volumio[20218]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 11 19:53:10 volumio volumio[20218]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 11 19:53:10 volumio volumio[20218]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 11 19:53:10 volumio volumio[20218]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 11 19:53:10 volumio volumio[20218]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 11 19:53:10 volumio volumio[20218]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 11 19:53:10 volumio volumio[20218]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 11 19:53:10 volumio volumio[20218]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 11 19:53:10 volumio volumio[20218]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 11 19:53:10 volumio volumio[20218]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 11 19:53:10 volumio volumio[20218]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 11 19:53:10 volumio volumio[20218]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 11 19:53:10 volumio volumio[20218]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 11 19:53:10 volumio volumio[20218]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 11 19:53:10 volumio volumio[20218]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 11 19:53:10 volumio volumio[20218]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 11 19:53:10 volumio volumio[20218]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 11 19:53:10 volumio volumio[20218]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 11 19:53:10 volumio volumio[20218]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 11 19:53:10 volumio volumio[20218]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 11 19:53:10 volumio volumio[20218]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 11 19:53:10 volumio volumio[20218]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 11 19:53:10 volumio volumio[20218]: info: Adding plugin bluetooth to MyMusic Plugins Feb 11 19:53:10 volumio volumio[20218]: info: Adding plugin multiroom to MyMusic Plugins Feb 11 19:53:10 volumio volumio[20218]: info: Adding plugin metavolumio to MyMusic Plugins Feb 11 19:53:10 volumio volumio[20218]: info: Adding plugin cd_controller to MyMusic Plugins Feb 11 19:53:10 volumio volumio[20218]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 11 19:53:10 volumio volumio[20218]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 11 19:53:10 volumio volumio[20218]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 11 19:53:10 volumio volumio[20218]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 11 19:53:11 volumio go-librespot[20562]: time="2026-02-11T19:53:11+07:00" level=debug msg="obtained new client token: AAD7kH3tZiP1ivwwyOhQkxtuTMzq0vADEPUeh7ZK/LZExV1+dAV2stjMsF59fQBY4wAGJsUDxyxLrmCMCH0TMTuPQNQvSciHM9V88vJzPMnFtc6XecEoygycL2hZzCHpTeq530FfoYpTtoVy7Lyu5irI7rz8u2S9hW1DQb5/UF04/zyECboAs82bW/3WqSNmnYCqtBuA9fR+iSd9iGzBLmanX6o8b59RGtubQMzb7BxnEasDMatqUCQ=" Feb 11 19:53:11 volumio go-librespot[20562]: time="2026-02-11T19:53:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 19:53:11 volumio go-librespot[20562]: time="2026-02-11T19:53:11+07:00" level=debug msg="completed keyexchange" Feb 11 19:53:11 volumio go-librespot[20562]: time="2026-02-11T19:53:11+07:00" level=debug msg="completed challenge" Feb 11 19:53:11 volumio go-librespot[20562]: time="2026-02-11T19:53:11+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 11 19:53:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 19:53:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 19:53:12 volumio volumio[20218]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 11 19:53:12 volumio volumio[20218]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 11 19:53:12 volumio volumio[20218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 19:53:12 volumio volumio[20218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 19:53:12 volumio volumio[20218]: info: Starting MyVolumio Remote Streaming Endpoints Feb 11 19:53:12 volumio volumio[20218]: info: MyVolumio login type: Token Feb 11 19:53:12 volumio volumio[20218]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 11 19:53:12 volumio volumio[20218]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 11 19:53:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 11 19:53:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:53:14 volumio volumio[20218]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 11 19:53:14 volumio volumio[20218]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 11 19:53:14 volumio volumio[20218]: info: Streaming services startup Feb 11 19:53:14 volumio volumio[20218]: info: Starting Streaming Daemon Feb 11 19:53:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:53:14 volumio go-librespot[20583]: go-librespot daemon starting... Feb 11 19:53:14 volumio sudo[20585]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 11 19:53:14 volumio sudo[20585]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:53:14 volumio volumio[20218]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 11 19:53:14 volumio go-librespot[20588]: time="2026-02-11T19:53:14+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 19:53:14 volumio go-librespot[20588]: time="2026-02-11T19:53:14+07:00" level=debug msg="app state loaded" Feb 11 19:53:14 volumio go-librespot[20588]: time="2026-02-11T19:53:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 19:53:14 volumio sudo[20585]: pam_unix(sudo:session): session closed for user root Feb 11 19:53:14 volumio volumio[20218]: info: Initializing connection to go-librespot Websocket Feb 11 19:53:14 volumio volumio[20218]: error: Cannot start Volumio Streaming Daemon Feb 11 19:53:14 volumio volumio[20218]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 11 19:53:14 volumio volumio[20218]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 11 19:53:14 volumio go-librespot[20588]: time="2026-02-11T19:53:14+07:00" level=debug msg="new websocket client" Feb 11 19:53:14 volumio volumio[20218]: info: Connection to go-librespot Websocket established Feb 11 19:53:15 volumio go-librespot[20588]: time="2026-02-11T19:53:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 19:53:15 volumio go-librespot[20588]: time="2026-02-11T19:53:15+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 19:53:15 volumio go-librespot[20588]: time="2026-02-11T19:53:15+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 19:53:15 volumio go-librespot[20588]: time="2026-02-11T19:53:15+07:00" level=info msg="zeroconf server listening on port 45351" Feb 11 19:53:15 volumio go-librespot[20588]: time="2026-02-11T19:53:15+07:00" level=debug msg="obtained new client token: AABPZfaTiEq1AnlENqySUu+dkRmhbCsFzDzLoh+Pr2PwP1Ilsruw+ZpJwHnZIojnateF7qM+PjYvsSxLP8k77VGWVWJKf0tZMKIACcqoYxULJLCtacOzk2ktCU/anNkcY11qhA5ndVK/LWyvIz8bo2ErtwHnJJJM3yaovh1lATLMQ1augJU0LY0/l1WetjvtYBoNs0dykyZZdtJ1OXbxmHtf8bsM6plDW1AtUCre2P8/xi/5Y0qGFjjHDA==" Feb 11 19:53:15 volumio go-librespot[20588]: time="2026-02-11T19:53:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 19:53:15 volumio go-librespot[20588]: time="2026-02-11T19:53:15+07:00" level=debug msg="completed keyexchange" Feb 11 19:53:15 volumio go-librespot[20588]: time="2026-02-11T19:53:15+07:00" level=debug msg="completed challenge" Feb 11 19:53:15 volumio volumio[20218]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 11 19:53:15 volumio go-librespot[20588]: time="2026-02-11T19:53: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 11 19:53:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 19:53:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 19:53:15 volumio volumio[20218]: info: Connection to go-librespot Websocket closed Feb 11 19:53:16 volumio volumio[20218]: info: MyVolumio token set successfully Feb 11 19:53:16 volumio volumio[20218]: info: MYVOLUMIO: Adding device Feb 11 19:53:16 volumio volumio[20218]: info: MYVOLUMIO: Evaluating Server Feb 11 19:53:17 volumio volumio[20218]: info: MyVolumio status changed Feb 11 19:53:17 volumio volumio[20218]: info: Streaming services startup Feb 11 19:53:17 volumio volumio[20218]: info: Starting Streaming Daemon Feb 11 19:53:17 volumio volumio[20218]: info: Removing browser output: myVolumio user plan is not superstar Feb 11 19:53:17 volumio volumio[20218]: info: Removing audio output: Feb 11 19:53:17 volumio volumio[20218]: info: Stoppping Tunnel 1 Feb 11 19:53:17 volumio sudo[20620]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 11 19:53:17 volumio sudo[20620]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:53:17 volumio sudo[20620]: pam_unix(sudo:session): session closed for user root Feb 11 19:53:17 volumio sudo[20623]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 11 19:53:17 volumio sudo[20623]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:53:17 volumio volumio[20218]: error: Cannot start Volumio Streaming Daemon Feb 11 19:53:17 volumio volumio[20218]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 11 19:53:17 volumio volumio[20218]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 11 19:53:17 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 11 19:53:17 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 11 19:53:17 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 11 19:53:17 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 11 19:53:17 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 11 19:53:17 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 11 19:53:17 volumio volumio[20218]: info: Setting Geolocation for MyVolumio to as1 Feb 11 19:53:17 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 11 19:53:17 volumio volumio[20218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 19:53:17 volumio volumio[20218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 19:53:17 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 11 19:53:17 volumio volumio[20218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 19:53:17 volumio sudo[20623]: pam_unix(sudo:session): session closed for user root Feb 11 19:53:17 volumio volumio[20218]: info: Remote SSH Stopped Feb 11 19:53:17 volumio volumio[20218]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 11 19:53:17 volumio volumio[20218]: info: Getting Spotify volume Feb 11 19:53:17 volumio volumio[20218]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 19:53:17 volumio volumio[20218]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 19:53:17 volumio volumio[20218]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 11 19:53:17 volumio volumio[20218]: errno: -111, Feb 11 19:53:17 volumio volumio[20218]: code: 'ECONNREFUSED', Feb 11 19:53:17 volumio volumio[20218]: syscall: 'connect', Feb 11 19:53:17 volumio volumio[20218]: address: '127.0.0.1', Feb 11 19:53:17 volumio volumio[20218]: port: 9879, Feb 11 19:53:17 volumio volumio[20218]: response: undefined Feb 11 19:53:17 volumio volumio[20218]: } Feb 11 19:53:17 volumio volumio[20218]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 19:53:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 11 19:53:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:53:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:53:18 volumio go-librespot[20637]: go-librespot daemon starting... Feb 11 19:53:18 volumio go-librespot[20638]: time="2026-02-11T19:53:18+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 19:53:18 volumio go-librespot[20638]: time="2026-02-11T19:53:18+07:00" level=debug msg="app state loaded" Feb 11 19:53:18 volumio go-librespot[20638]: time="2026-02-11T19:53:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 19:53:19 volumio sudo[20647]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-11 19:52' Feb 11 19:53:19 volumio sudo[20647]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:53:19 volumio go-librespot[20638]: time="2026-02-11T19:53:19+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 19:53:19 volumio go-librespot[20638]: time="2026-02-11T19:53:19+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 19:53:19 volumio go-librespot[20638]: time="2026-02-11T19:53:19+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 19:53:19 volumio go-librespot[20638]: time="2026-02-11T19:53:19+07:00" level=info msg="zeroconf server listening on port 42807" Feb 11 19:53:19 volumio go-librespot[20638]: time="2026-02-11T19:53:19+07:00" level=debug msg="obtained new client token: AABR3Jo3T4YUoxhYKM7WZ9eZITUpJQViaYc32P2UCnmOSqDVJjAWiGNLmVcjN7vbj2i1rodL23lvkIrXXWUNPp/3ZohWJBjGN98FJMt5fbxaZDKjc0kzQ3Bm3n2Vlfbo9nvlLH2Pkv8s79+kZ8SFDUbus6eIawZVlJNhAMWLUzaAex/o9H7SVzF1uQRX+KhqWZBNce0UzbJJA6dCDm+1XFiHt3hXgbYVunuq+yn34/ku+adZDLQMZUblIw==" Feb 11 19:53:19 volumio sudo[20647]: pam_unix(sudo:session): session closed for user root Feb 11 19:53:19 volumio go-librespot[20638]: time="2026-02-11T19:53:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 19:53:19 volumio volumio-remote-updater[643]: [2026-02-11 19:53:19] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Feb 11 19:53:19 volumio volumio-remote-updater[643]: [2026-02-11 19:53:19] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Feb 11 19:53:19 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 11 19:53:19 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 11 19:53:19 volumio systemd[1]: volumio.service: Consumed 56.915s CPU time. Feb 11 19:53:19 volumio go-librespot[20638]: time="2026-02-11T19:53:19+07:00" level=debug msg="completed keyexchange" Feb 11 19:53:19 volumio go-librespot[20638]: time="2026-02-11T19:53:19+07:00" level=debug msg="completed challenge" Feb 11 19:53:19 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 11 19:53:19 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 11 19:53:19 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 12110. Feb 11 19:53:19 volumio go-librespot[20638]: time="2026-02-11T19:53: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 11 19:53:20 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 11 19:53:20 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 11 19:53:20 volumio systemd[1]: volumio.service: Consumed 56.915s CPU time. Feb 11 19:53:20 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 11 19:53:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 19:53:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 19:53:20 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 11 19:53:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 11 19:53:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:53:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:53:23 volumio go-librespot[20674]: go-librespot daemon starting... Feb 11 19:53:23 volumio go-librespot[20675]: time="2026-02-11T19:53:23+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 19:53:23 volumio go-librespot[20675]: time="2026-02-11T19:53:23+07:00" level=debug msg="app state loaded" Feb 11 19:53:23 volumio go-librespot[20675]: time="2026-02-11T19:53:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 19:53:23 volumio volumio[20659]: info: ------------------------------------------- Feb 11 19:53:23 volumio volumio[20659]: info: ----- Volumio3 ---- Feb 11 19:53:23 volumio volumio[20659]: info: ------------------------------------------- Feb 11 19:53:23 volumio volumio[20659]: info: ----- System startup ---- Feb 11 19:53:23 volumio volumio[20659]: info: ------------------------------------------- Feb 11 19:53:23 volumio go-librespot[20675]: time="2026-02-11T19:53:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 19:53:23 volumio go-librespot[20675]: time="2026-02-11T19:53:23+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 19:53:23 volumio go-librespot[20675]: time="2026-02-11T19:53:23+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 19:53:23 volumio go-librespot[20675]: time="2026-02-11T19:53:23+07:00" level=info msg="zeroconf server listening on port 43463" Feb 11 19:53:24 volumio go-librespot[20675]: time="2026-02-11T19:53:24+07:00" level=debug msg="obtained new client token: AACbUYRvsrdRjviqCRUzQpJm0WOPNuj253uRbSTBz+kDwFXvOjXsiLSziqqXS42MHnqod0P+pQzW2BXNVXMqQ58imEjfdiChcg2Tnl5JygUV/ygrYuZBxlUgWUQJFw4i+XesxGkKyOHWVQKOeT4g2g76AZAGBBmLWJAer0m/O6uukK5ZYe8h/n93/EEwX9Wq4CMBf2N33VBEYl67cmHx3gGwkUS8qbhJEGYs3yNLSOy3eNsrKGUJDDS3qQ==" Feb 11 19:53:24 volumio go-librespot[20675]: time="2026-02-11T19:53:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 19:53:24 volumio go-librespot[20675]: time="2026-02-11T19:53:24+07:00" level=debug msg="completed keyexchange" Feb 11 19:53:24 volumio go-librespot[20675]: time="2026-02-11T19:53:24+07:00" level=debug msg="completed challenge" Feb 11 19:53:24 volumio go-librespot[20675]: time="2026-02-11T19:53: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 11 19:53:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 19:53:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 19:53:24 volumio volumio-remote-updater[643]: [2026-02-11 19:53:24] [connect] Successful connection Feb 11 19:53:25 volumio volumio[20659]: info: MYVOLUMIO Environment detected Feb 11 19:53:25 volumio volumio[20659]: info: Plugin folders cleanup Feb 11 19:53:25 volumio volumio[20659]: info: Scanning into folder /volumio/app/plugins/ Feb 11 19:53:25 volumio volumio[20659]: info: Scanning category audio_interface Feb 11 19:53:25 volumio volumio[20659]: info: Scanning category miscellanea Feb 11 19:53:25 volumio volumio[20659]: info: Scanning category music_service Feb 11 19:53:25 volumio volumio[20659]: info: Scanning category plugins.json Feb 11 19:53:25 volumio volumio[20659]: info: Scanning category system_controller Feb 11 19:53:25 volumio volumio[20659]: info: Scanning category user_interface Feb 11 19:53:25 volumio volumio[20659]: info: Scanning into folder /data/plugins/ Feb 11 19:53:25 volumio volumio[20659]: info: Scanning category music_service Feb 11 19:53:25 volumio volumio[20659]: info: Plugin folders cleanup completed Feb 11 19:53:25 volumio volumio[20659]: info: ------------------------------------------- Feb 11 19:53:25 volumio volumio[20659]: info: ----- Core plugins startup ---- Feb 11 19:53:25 volumio volumio[20659]: info: ------------------------------------------- Feb 11 19:53:25 volumio volumio[20659]: info: Loading plugins from folder /volumio/app/plugins/ Feb 11 19:53:25 volumio volumio[20659]: info: Adding plugin upnp to MyMusic Plugins Feb 11 19:53:25 volumio volumio[20659]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 11 19:53:25 volumio volumio[20659]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 11 19:53:25 volumio volumio[20659]: info: Loading plugins from folder /data/plugins/ Feb 11 19:53:25 volumio volumio[20659]: info: Loading plugin "system"... Feb 11 19:53:25 volumio volumio[20659]: info: Loading plugin "appearance"... Feb 11 19:53:27 volumio volumio[20659]: info: Loading plugin "network"... Feb 11 19:53:27 volumio volumio[20659]: info: Refreshing Cached IP Addresses Feb 11 19:53:27 volumio sudo[20695]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 19:53:27 volumio sudo[20695]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:53:27 volumio volumio[20659]: info: Loading plugin "services"... Feb 11 19:53:27 volumio sudo[20695]: pam_unix(sudo:session): session closed for user root Feb 11 19:53:27 volumio volumio[20659]: info: Loading plugin "alsa_controller"... Feb 11 19:53:27 volumio sudo[20697]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 19:53:27 volumio sudo[20697]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:53:27 volumio sudo[20697]: pam_unix(sudo:session): session closed for user root Feb 11 19:53:27 volumio sudo[20705]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 11 19:53:27 volumio sudo[20705]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:53:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 11 19:53:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:53:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:53:27 volumio go-librespot[20725]: go-librespot daemon starting... Feb 11 19:53:27 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 19:53:27 volumio volumio[20659]: info: Loading plugin "wizard"... Feb 11 19:53:27 volumio volumio[20659]: info: Loading plugin "networkfs"... Feb 11 19:53:27 volumio go-librespot[20729]: time="2026-02-11T19:53:27+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 19:53:27 volumio go-librespot[20729]: time="2026-02-11T19:53:27+07:00" level=debug msg="app state loaded" Feb 11 19:53:27 volumio go-librespot[20729]: time="2026-02-11T19:53:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 19:53:27 volumio volumio[20659]: info: Starting Udev Watcher for removable devices Feb 11 19:53:27 volumio volumio[20659]: info: Ignoring mount for partition: boot Feb 11 19:53:27 volumio volumio[20659]: info: Ignoring mount for partition: volumio Feb 11 19:53:27 volumio volumio[20659]: info: Ignoring mount for partition: volumio_data Feb 11 19:53:27 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 19:53:27 volumio volumio[20659]: info: Loading plugin "volumio_command_line_client"... Feb 11 19:53:27 volumio volumio[20659]: info: Loading plugin "upnp"... Feb 11 19:53:27 volumio volumio[20659]: info: [1770814407555] Starting Upmpd Daemon Feb 11 19:53:27 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 19:53:27 volumio volumio[20659]: info: Loading plugin "my_music"... Feb 11 19:53:27 volumio volumio[20659]: info: Loading plugin "mpd"... Feb 11 19:53:27 volumio go-librespot[20729]: time="2026-02-11T19:53:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 19:53:27 volumio go-librespot[20729]: time="2026-02-11T19:53:27+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 11 19:53:27 volumio go-librespot[20729]: time="2026-02-11T19:53:27+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 11 19:53:27 volumio go-librespot[20729]: time="2026-02-11T19:53:27+07:00" level=info msg="zeroconf server listening on port 43045" Feb 11 19:53:28 volumio go-librespot[20729]: time="2026-02-11T19:53:28+07:00" level=debug msg="obtained new client token: AADxEX0mUxl0DPKOidMyFvVJAoC6LY0vz59vt33hwUsBC3TYv1r5slgYoqpUdHlETbCMYnGz4ZeUlPjr86YTU5dPLJJ1sXbcjJ6RCXv3bJeLyJ2pfyKSMFYJWMpyvQzzgg7oyZK9vXvrAOk8Ew0bWQmEDrNQGX5n09kapoW84OFy6ISpfjOPuRbGomV0qsLFxNwRx2ixtEh59EKHtNJLzfZ8gLJyT0ZkiiG5mDQFACQ1D19LQo9vf/A=" Feb 11 19:53:28 volumio volumio[20659]: info: Loading plugin "upnp_browser"... Feb 11 19:53:28 volumio go-librespot[20729]: time="2026-02-11T19:53:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 19:53:28 volumio go-librespot[20729]: time="2026-02-11T19:53:28+07:00" level=debug msg="completed keyexchange" Feb 11 19:53:28 volumio go-librespot[20729]: time="2026-02-11T19:53:28+07:00" level=debug msg="completed challenge" Feb 11 19:53:28 volumio go-librespot[20729]: time="2026-02-11T19:53: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 11 19:53:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 19:53:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 19:53:29 volumio sudo[20705]: pam_unix(sudo:session): session closed for user root Feb 11 19:53:31 volumio volumio[20659]: info: Starting UPNP Browser Feb 11 19:53:31 volumio volumio[20659]: info: Loading plugin "alarm-clock"... Feb 11 19:53:31 volumio volumio[20659]: info: Loading plugin "airplay_emulation"... Feb 11 19:53:31 volumio volumio[20659]: info: Starting Shairport Sync Feb 11 19:53:31 volumio volumio[20659]: info: Loading plugin "last_100"... Feb 11 19:53:31 volumio volumio[20659]: info: Loading plugin "webradio"... Feb 11 19:53:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 11 19:53:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:53:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:53:31 volumio go-librespot[20736]: go-librespot daemon starting... Feb 11 19:53:31 volumio go-librespot[20737]: time="2026-02-11T19:53:31+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 19:53:31 volumio go-librespot[20737]: time="2026-02-11T19:53:31+07:00" level=debug msg="app state loaded" Feb 11 19:53:31 volumio go-librespot[20737]: time="2026-02-11T19:53:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 19:53:31 volumio volumio[20659]: info: Loading plugin "i2s_dacs"... Feb 11 19:53:31 volumio volumio[20659]: info: Loading plugin "volumiodiscovery"... Feb 11 19:53:31 volumio volumio[20659]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 11 19:53:31 volumio volumio[20659]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 19:53:31 volumio volumio[20659]: *** WARNING *** For more information see Feb 11 19:53:31 volumio volumio[20659]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 11 19:53:31 volumio volumio[20659]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 19:53:31 volumio volumio[20659]: *** WARNING *** For more information see Feb 11 19:53:31 volumio node[20659]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 11 19:53:31 volumio node[20659]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 19:53:31 volumio node[20659]: *** WARNING *** For more information see Feb 11 19:53:31 volumio node[20659]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 11 19:53:31 volumio node[20659]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 19:53:31 volumio node[20659]: *** WARNING *** For more information see Feb 11 19:53:31 volumio volumio[20659]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 11 19:53:31 volumio volumio[20659]: info: Discovery: Started advertising with name: Volumio Feb 11 19:53:31 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 19:53:31 volumio volumio[20659]: info: Loading plugin "spop"... Feb 11 19:53:32 volumio go-librespot[20737]: time="2026-02-11T19:53: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 11 19:53:32 volumio go-librespot[20737]: time="2026-02-11T19:53: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 11 19:53:32 volumio go-librespot[20737]: time="2026-02-11T19:53: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 11 19:53:32 volumio go-librespot[20737]: time="2026-02-11T19:53:32+07:00" level=info msg="zeroconf server listening on port 39377" Feb 11 19:53:32 volumio go-librespot[20737]: time="2026-02-11T19:53:32+07:00" level=debug msg="obtained new client token: AABUGY3V8Mb1NnamO0WdB7Nk8QzAU5LptCl/gKOcLzYDWab16t5lcfpS7EjjhUoRJfxZaL3FIY2JWonHucn0Ze160gVM+OONSQD+n8doUHVyl+R8UjvZ6u6Rk+UQMQDY1EnOOezz7sUR9zLWN+XjIkSfoJJeW5SlAY7H011tgEZJF9obGOl02Rt0QVjlLXaC4Nxc8MgbpzlaJyuzlg0yeKk5n/xWCiOeFcICNWHNccHpWi8XHav11qTKVg==" Feb 11 19:53:32 volumio go-librespot[20737]: time="2026-02-11T19:53:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 19:53:32 volumio go-librespot[20737]: time="2026-02-11T19:53:32+07:00" level=debug msg="completed keyexchange" Feb 11 19:53:32 volumio go-librespot[20737]: time="2026-02-11T19:53:32+07:00" level=debug msg="completed challenge" Feb 11 19:53:32 volumio go-librespot[20737]: time="2026-02-11T19:53:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 19:53:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 19:53:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 19:53:33 volumio volumio[20659]: info: Loading plugin "ytcr"... Feb 11 19:53:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 11 19:53:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:53:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:53:35 volumio go-librespot[20750]: go-librespot daemon starting... Feb 11 19:53:35 volumio go-librespot[20751]: time="2026-02-11T19:53:35+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 19:53:35 volumio go-librespot[20751]: time="2026-02-11T19:53:35+07:00" level=debug msg="app state loaded" Feb 11 19:53:35 volumio go-librespot[20751]: time="2026-02-11T19:53:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 19:53:36 volumio go-librespot[20751]: time="2026-02-11T19:53:36+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 11 19:53:36 volumio go-librespot[20751]: time="2026-02-11T19:53:36+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 11 19:53:36 volumio go-librespot[20751]: time="2026-02-11T19:53:36+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 11 19:53:36 volumio go-librespot[20751]: time="2026-02-11T19:53:36+07:00" level=info msg="zeroconf server listening on port 37455" Feb 11 19:53:36 volumio volumio[20659]: info: Loading plugin "ytmusic"... Feb 11 19:53:36 volumio go-librespot[20751]: time="2026-02-11T19:53:36+07:00" level=debug msg="obtained new client token: AAA4vrA2VxP2FPiBLRRs3IEyqIUg+iZzL39YOnJKtbVYQwnLQdKC+p5nw+vOBAexRKf/S3iYQxXRcdB+0Ow8qilZ8/jIBhQo731oDUfA9tKI/RczBZ9UUJrBMHWsy3WcUZec3sHsj8dtYq1439hMPyqt8jE+zjnJodhBjNDqiF5JsT1tMEO3ccoEssi/+NBN6OqBZLR3NefPZw4GtJg5cNLCuid0ffcdUT4BJLwManFqQyZGbXk0JecKEw==" Feb 11 19:53:36 volumio go-librespot[20751]: time="2026-02-11T19:53:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 19:53:36 volumio go-librespot[20751]: time="2026-02-11T19:53:36+07:00" level=debug msg="completed keyexchange" Feb 11 19:53:36 volumio go-librespot[20751]: time="2026-02-11T19:53:36+07:00" level=debug msg="completed challenge" Feb 11 19:53:36 volumio go-librespot[20751]: time="2026-02-11T19:53: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 11 19:53:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 19:53:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 19:53:37 volumio volumio-remote-updater[643]: [2026-02-11 19:53:37] [connect] Successful connection Feb 11 19:53:37 volumio volumio[20659]: info: Loading plugin "outputs"... Feb 11 19:53:37 volumio volumio[20659]: info: Loading plugin "albumart"... Feb 11 19:53:37 volumio volumio[20659]: info: Plugin example_plugin is not enabled Feb 11 19:53:37 volumio volumio[20659]: info: Loading plugin "inputs"... Feb 11 19:53:37 volumio volumio[20659]: info: Loading plugin "updater_comm"... Feb 11 19:53:37 volumio volumio[20659]: info: Plugin mpdemulation is not enabled Feb 11 19:53:37 volumio volumio[20659]: info: Loading plugin "rest_api"... Feb 11 19:53:37 volumio volumio[20659]: info: Loading plugin "websocket"... Feb 11 19:53:37 volumio volumio[20659]: info: Starting Socket.io Server version 1.7.4 Feb 11 19:53:37 volumio volumio[20659]: info: Loading plugin "RoonBridge"... Feb 11 19:53:38 volumio volumio[20659]: info: Applying required configuration parameters for plugin RoonBridge Feb 11 19:53:38 volumio volumio[20659]: info: Loading i18n strings for locale en Feb 11 19:53:38 volumio volumio[20659]: Updating browse sources language Feb 11 19:53:38 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 19:53:38 volumio volumio[20773]: Forking 3 albumart workers Feb 11 19:53:38 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 19:53:38 volumio volumio[20659]: info: CoreCommandRouter::initPlayerControls Feb 11 19:53:38 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:53:38 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:53:38 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:53:38 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:53:38 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:53:38 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:53:38 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:53:38 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:53:38 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 19:53:38 volumio volumio[20659]: Express server listening on port 3000 Feb 11 19:53:38 volumio volumio[20659]: [Metrics] WebUI: 16s 152.64ms Feb 11 19:53:38 volumio volumio[20659]: info: CoreStateMachine::resetVolumioState Feb 11 19:53:38 volumio volumio[20659]: info: CoreStateMachine::getcurrentVolume Feb 11 19:53:38 volumio volumio[20659]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 19:53:39 volumio sudo[20818]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 19:53:39 volumio sudo[20818]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:53:39 volumio sudo[20818]: pam_unix(sudo:session): session closed for user root Feb 11 19:53:39 volumio sudo[20820]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 19:53:39 volumio sudo[20820]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:53:39 volumio sudo[20820]: pam_unix(sudo:session): session closed for user root Feb 11 19:53:39 volumio volumio[20659]: info: Volumio Network Manager: Network status updated: 1 Feb 11 19:53:39 volumio volumio[20659]: info: VolumeController:: Volume=100 Mute =false Feb 11 19:53:39 volumio volumio[20659]: info: CoreStateMachine::pushState Feb 11 19:53:39 volumio volumio[20659]: info: CorePlayQueue::getTrack 0 Feb 11 19:53:39 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 19:53:39 volumio volumio[20659]: info: CoreCommandRouter::volumioPushState Feb 11 19:53:39 volumio volumio[20659]: info: CoreStateMachine::updateTrackBlock Feb 11 19:53:39 volumio volumio[20659]: info: CorePlayQueue::getTrackBlock Feb 11 19:53:39 volumio volumio[20659]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 19:53:39 volumio volumio-remote-updater[643]: [2026-02-11 19:53:39] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770814417 101 Feb 11 19:53:39 volumio volumio[20659]: 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 11 19:53:39 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 19:53:39 volumio volumio[20659]: info: Reloading queue from file Feb 11 19:53:39 volumio volumio[20659]: info: CoreStateMachine::setRepeat null single undefined Feb 11 19:53:39 volumio volumio[20659]: info: CoreStateMachine::pushState Feb 11 19:53:39 volumio volumio[20659]: info: CorePlayQueue::getTrack 0 Feb 11 19:53:39 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 19:53:39 volumio volumio[20659]: info: CoreCommandRouter::volumioPushState Feb 11 19:53:39 volumio volumio[20659]: info: CoreStateMachine::setRandom null Feb 11 19:53:39 volumio volumio[20659]: info: CoreStateMachine::pushState Feb 11 19:53:39 volumio volumio[20659]: info: CorePlayQueue::getTrack 0 Feb 11 19:53:39 volumio volumio[20659]: info: CoreCommandRouter::volumioPushState Feb 11 19:53:39 volumio volumio[20659]: info: Setting Device type: Raspberry PI Feb 11 19:53:39 volumio volumio[20659]: info: Completed loading Core Plugins Feb 11 19:53:39 volumio volumio[20659]: info: Preparing to generate the ALSA configuration file Feb 11 19:53:39 volumio volumio[20659]: info: VolumeController:: Volume=100 Mute =false Feb 11 19:53:39 volumio volumio[20659]: info: CoreStateMachine::pushState Feb 11 19:53:39 volumio volumio[20659]: info: CorePlayQueue::getTrack 0 Feb 11 19:53:39 volumio volumio[20659]: info: CoreCommandRouter::volumioPushState Feb 11 19:53:39 volumio volumio[20659]: info: Asound.conf file unchanged, so no further update is needed Feb 11 19:53:39 volumio volumio[20659]: info: Output device has changed, restarting MPD Feb 11 19:53:39 volumio sudo[20834]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 11 19:53:39 volumio volumio[20659]: info: Output device has changed, restarting Shairport Sync Feb 11 19:53:39 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:53:39 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 19:53:39 volumio sudo[20834]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:53:40 volumio volumio[20659]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 19:53:40 volumio sudo[20836]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 19:53:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 11 19:53:40 volumio volumio[20659]: info: ___________ START PLUGINS ___________ Feb 11 19:53:40 volumio sudo[20836]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:53:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:53:40 volumio sudo[20836]: pam_unix(sudo:session): session closed for user root Feb 11 19:53:40 volumio volumio[20659]: info: ControllerMpd::onStart: Initializing MPD Feb 11 19:53:40 volumio volumio[20659]: info: Creating MPD Configuration file Feb 11 19:53:40 volumio sudo[20838]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 19:53:40 volumio sudo[20838]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:53:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:53:40 volumio go-librespot[20845]: go-librespot daemon starting... Feb 11 19:53:40 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 19:53:40 volumio volumio[20659]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 19:53:40 volumio volumio[20659]: info: [1770814420163] CoreMusicLibrary::Adding element Media Servers Feb 11 19:53:40 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 19:53:40 volumio volumio[20659]: info: UPNP Browser: Client initialized successfully Feb 11 19:53:40 volumio go-librespot[20850]: time="2026-02-11T19:53:40+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 19:53:40 volumio go-librespot[20850]: time="2026-02-11T19:53:40+07:00" level=debug msg="app state loaded" Feb 11 19:53:40 volumio sudo[20848]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 19:53:40 volumio go-librespot[20850]: time="2026-02-11T19:53:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 19:53:40 volumio sudo[20848]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:53:40 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 11 19:53:40 volumio sudo[20834]: pam_unix(sudo:session): session closed for user root Feb 11 19:53:40 volumio sudo[20848]: pam_unix(sudo:session): session closed for user root Feb 11 19:53:40 volumio sudo[20851]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 19:53:40 volumio sudo[20851]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:53:40 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:53:40 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 19:53:40 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 11 19:53:40 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 11 19:53:40 volumio systemd[1]: mpd.service: Consumed 7.151s CPU time. Feb 11 19:53:40 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 11 19:53:40 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 11 19:53:40 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 11 19:53:40 volumio volumio[20659]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 19:53:40 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:53:40 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 19:53:40 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 11 19:53:40 volumio volumio[20659]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 19:53:40 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 11 19:53:40 volumio volumio[20659]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 19:53:40 volumio volumio[20659]: info: [1770814420577] CoreMusicLibrary::Adding element Last_100 Feb 11 19:53:40 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 19:53:40 volumio volumio[20659]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 19:53:40 volumio volumio[20659]: info: [1770814420639] CoreMusicLibrary::Adding element Webradio Feb 11 19:53:40 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 19:53:40 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 11 19:53:40 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 11 19:53:40 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 11 19:53:40 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 11 19:53:40 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 11 19:53:40 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 19:53:40 volumio volumio[20659]: info: Initializing BBC Radios Feb 11 19:53:40 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 11 19:53:40 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 11 19:53:40 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 19:53:40 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 19:53:40 volumio volumio[20659]: info: Creating Spotify config file Feb 11 19:53:40 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:53:40 volumio go-librespot[20850]: time="2026-02-11T19:53:40+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 19:53:41 volumio go-librespot[20850]: time="2026-02-11T19:53:40+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 19:53:41 volumio go-librespot[20850]: time="2026-02-11T19:53:41+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 19:53:41 volumio go-librespot[20850]: time="2026-02-11T19:53:41+07:00" level=info msg="zeroconf server listening on port 39671" Feb 11 19:53:41 volumio go-librespot[20850]: time="2026-02-11T19:53:41+07:00" level=debug msg="obtained new client token: AAAIZkCHhHWfcRQTQKylcberys2/7A0Coy1ntApDmST/isN233t/y4RE/8Hodm45YwLBulBHka9/PDKalGHIJ/waGsgJRaj8p3ntZjwXgxj0KlT/MRBhycrSbm3DFMexMFFTDig8qG+Np4V7R7wl57jC0mA4aldx6MWA6E/lcFXSHkAKNMeyG1/BNf5PVlJf3slD/rgz3olPa4pKw5XfrE+O2sxn71kwesC8FZ7WZHc0eoTbwD2ojI0=" Feb 11 19:53:41 volumio sudo[20873]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 11 19:53:41 volumio sudo[20873]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 11 19:53:41 volumio sudo[20873]: pam_unix(sudo:session): session closed for user root Feb 11 19:53:41 volumio go-librespot[20850]: time="2026-02-11T19:53:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 19:53:41 volumio go-librespot[20850]: time="2026-02-11T19:53:41+07:00" level=debug msg="completed keyexchange" Feb 11 19:53:41 volumio go-librespot[20850]: time="2026-02-11T19:53:41+07:00" level=debug msg="completed challenge" Feb 11 19:53:41 volumio go-librespot[20850]: time="2026-02-11T19:53:41+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 19:53:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 19:53:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 19:53:42 volumio volumio[20783]: Starting albumart workers Feb 11 19:53:42 volumio volumio[20785]: Starting albumart workers Feb 11 19:53:42 volumio volumio[20659]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 19:53:42 volumio volumio[20659]: info: [1770814422142] CoreMusicLibrary::Adding element YouTube Music Feb 11 19:53:42 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 19:53:42 volumio volumio[20659]: Cannot find translation for source YouTube Music Feb 11 19:53:42 volumio volumio[20659]: info: Volumio Calling Home Feb 11 19:53:42 volumio sudo[20888]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 11 19:53:42 volumio sudo[20888]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:53:42 volumio sudo[20888]: pam_unix(sudo:session): session closed for user root Feb 11 19:53:42 volumio volumio[20784]: Starting albumart workers Feb 11 19:53:43 volumio volumio[20659]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 11 19:53:43 volumio volumio[20659]: info: Discovery: Found device Volumio Feb 11 19:53:43 volumio volumio[20659]: info: CoreCommandRouter::volumioGetState Feb 11 19:53:43 volumio volumio[20659]: info: CorePlayQueue::getTrack 0 Feb 11 19:53:43 volumio volumio[20659]: info: MPD Permissions set Feb 11 19:53:43 volumio volumio[20659]: info: MPD Permissions set Feb 11 19:53:43 volumio volumio[20659]: info: Upmpdcli Daemon Started Feb 11 19:53:43 volumio volumio[20659]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 11 19:53:43 volumio volumio[20659]: info: Discovery: Found device Volumio Feb 11 19:53:43 volumio volumio[20659]: info: CoreCommandRouter::volumioGetState Feb 11 19:53:43 volumio volumio[20659]: info: CorePlayQueue::getTrack 0 Feb 11 19:53:43 volumio volumio[20659]: info: Spotify config file written Feb 11 19:53:43 volumio volumio[20659]: 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 11 19:53:43 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:53:43 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:53:43 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:53:43 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:53:43 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:53:43 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:53:43 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:53:43 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:53:43 volumio sudo[20894]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 11 19:53:43 volumio sudo[20894]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:53:43 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 19:53:43 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:53:43 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:53:43 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:53:43 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:53:43 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:53:43 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:53:43 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:53:43 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:53:43 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:53:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:53:43 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 19:53:43 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:53:43 volumio volumio[20659]: info: No need to fix Spotify hosts Feb 11 19:53:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:53:43 volumio go-librespot[20906]: go-librespot daemon starting... Feb 11 19:53:43 volumio sudo[20894]: pam_unix(sudo:session): session closed for user root Feb 11 19:53:44 volumio go-librespot[20907]: time="2026-02-11T19:53:44+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 19:53:44 volumio go-librespot[20907]: time="2026-02-11T19:53:44+07:00" level=debug msg="app state loaded" Feb 11 19:53:44 volumio go-librespot[20907]: time="2026-02-11T19:53:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 19:53:44 volumio volumio[20659]: info: Volumio called home Feb 11 19:53:44 volumio go-librespot[20907]: time="2026-02-11T19:53:44+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 19:53:44 volumio go-librespot[20907]: time="2026-02-11T19:53:44+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 19:53:44 volumio go-librespot[20907]: time="2026-02-11T19:53:44+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 19:53:44 volumio go-librespot[20907]: time="2026-02-11T19:53:44+07:00" level=info msg="zeroconf server listening on port 37419" Feb 11 19:53:44 volumio volumio[20659]: info: Starting Shairport Sync Feb 11 19:53:44 volumio volumio[20659]: info: Starting Shairport Sync Feb 11 19:53:44 volumio volumio[20659]: info: Starting Shairport Sync Feb 11 19:53:44 volumio go-librespot[20907]: time="2026-02-11T19:53:44+07:00" level=debug msg="obtained new client token: AAAmnw4iqHOz3K0Isk7J1ayWZfoW6HSpzyA5gdsamkSIjJBTruBOk2z8cHqHAgElDCiv6uvUAAX0c1iPDAyrih0qf7ekJ/qRj8dGkoPDAMt5xItMfZyOTj14R9jRG/roCzsE/uVYr/Pn/KbEMom7wHpapBhvrO1h8gONGlK5tgHoM0/g2r0RZRpHRlRE1HVMN6lAiEcaooBKC/t5E0KeS4pkultXASi91gJxHCpghuxGCVcNoaG8KDqCJQ==" Feb 11 19:53:44 volumio sudo[20933]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 19:53:44 volumio sudo[20933]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:53:44 volumio sudo[20935]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 19:53:45 volumio sudo[20935]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:53:45 volumio sudo[20937]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 19:53:45 volumio sudo[20937]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:53:45 volumio go-librespot[20907]: time="2026-02-11T19:53:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 19:53:45 volumio volumio[20659]: info: CoreCommandRouter::volumioGetState Feb 11 19:53:45 volumio volumio[20659]: info: CorePlayQueue::getTrack 0 Feb 11 19:53:45 volumio volumio[20659]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 11 19:53:45 volumio volumio[20659]: SPOTIFY: BQCTfl01E9s-AErz2RWUpbskPvllyf3nk6gVnGzT1btH6HCwE4nB0ox4Nzsbt6iTrrKeMlOJKjwXTz0Id2LrV7Q2X5HS4B7aRtJrO9sWTFftBBgn9gVy2nj_irR93iiUao0siB-vzKLGys09z8DVHai9Uiog0FJ-5993bprx-oHlKscvcZMR6wWuT36B84yV2kLYAbnhePT0EWm62EmF1KHbi_F_R-_pDRUgeFQVVfah5j-_pKY-ED-UweHtcvVdlPR6toOqfk68EWVeeRtf6Vqt5NYDAfV6t6V3yGLQ7Ih7gU0LTZlZLjj5 Feb 11 19:53:45 volumio volumio[20659]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 11 19:53:45 volumio volumio[20659]: info: New Spotify access token = BQCTfl01E9s-AErz2RWUpbskPvllyf3nk6gVnGzT1btH6HCwE4nB0ox4Nzsbt6iTrrKeMlOJKjwXTz0Id2LrV7Q2X5HS4B7aRtJrO9sWTFftBBgn9gVy2nj_irR93iiUao0siB-vzKLGys09z8DVHai9Uiog0FJ-5993bprx-oHlKscvcZMR6wWuT36B84yV2kLYAbnhePT0EWm62EmF1KHbi_F_R-_pDRUgeFQVVfah5j-_pKY-ED-UweHtcvVdlPR6toOqfk68EWVeeRtf6Vqt5NYDAfV6t6V3yGLQ7Ih7gU0LTZlZLjj5 Feb 11 19:53:45 volumio volumio[20659]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 11 19:53:45 volumio go-librespot[20907]: time="2026-02-11T19:53:45+07:00" level=debug msg="completed keyexchange" Feb 11 19:53:45 volumio go-librespot[20907]: time="2026-02-11T19:53:45+07:00" level=debug msg="completed challenge" Feb 11 19:53:45 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 11 19:53:45 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 11 19:53:45 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 19:53:45 volumio systemd[1]: shairport-sync.service: Consumed 2.340s CPU time. Feb 11 19:53:45 volumio go-librespot[20907]: time="2026-02-11T19:53:45+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 19:53:45 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 19:53:45 volumio sudo[20933]: pam_unix(sudo:session): session closed for user root Feb 11 19:53:45 volumio sudo[20935]: pam_unix(sudo:session): session closed for user root Feb 11 19:53:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 19:53:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 19:53:45 volumio sudo[20937]: pam_unix(sudo:session): session closed for user root Feb 11 19:53:45 volumio volumio[20659]: info: Shairport-Sync Started Feb 11 19:53:45 volumio volumio[20659]: Error adding Membership: Error: addMembership EINVAL Feb 11 19:53:45 volumio volumio[20659]: info: Shairport-Sync Started Feb 11 19:53:45 volumio volumio[20659]: info: Shairport-Sync Started Feb 11 19:53:45 volumio volumio[20659]: 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 11 19:53:45 volumio volumio[20659]: info: Spotify Successfully logged in Feb 11 19:53:45 volumio volumio[20659]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 19:53:45 volumio volumio[20659]: info: [1770814425726] CoreMusicLibrary::Adding element Spotify Feb 11 19:53:45 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 19:53:45 volumio volumio[20659]: Cannot find translation for source YouTube Music Feb 11 19:53:45 volumio volumio[20659]: Cannot find translation for source Spotify Feb 11 19:53:46 volumio volumio[20659]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 11 19:53:46 volumio volumio[20659]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 19:53:46 volumio volumio[20659]: info: VolumeController:: Volume=100 Mute =false Feb 11 19:53:46 volumio volumio[20659]: info: CoreCommandRouter::volumioGetState Feb 11 19:53:46 volumio volumio[20659]: info: CorePlayQueue::getTrack 0 Feb 11 19:53:46 volumio volumio[20659]: info: CoreStateMachine::pushState Feb 11 19:53:46 volumio volumio[20659]: info: CorePlayQueue::getTrack 0 Feb 11 19:53:46 volumio volumio[20659]: info: CoreCommandRouter::volumioPushState Feb 11 19:53:47 volumio volumio[20659]: info: go-librespot daemon successfully initialized Feb 11 19:53:48 volumio mpd[20886]: 2026-02-11T19:53:48 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 11 19:53:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 11 19:53:48 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 11 19:53:48 volumio sudo[20838]: pam_unix(sudo:session): session closed for user root Feb 11 19:53:48 volumio sudo[20851]: pam_unix(sudo:session): session closed for user root Feb 11 19:53:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:53:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:53:48 volumio go-librespot[20975]: go-librespot daemon starting... Feb 11 19:53:48 volumio go-librespot[20978]: time="2026-02-11T19:53:48+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 19:53:48 volumio go-librespot[20978]: time="2026-02-11T19:53:48+07:00" level=debug msg="app state loaded" Feb 11 19:53:48 volumio go-librespot[20978]: time="2026-02-11T19:53:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 19:53:48 volumio volumio[20659]: error: MPD error: The expression evaluated to a falsy value: Feb 11 19:53:48 volumio volumio[20659]: assert.ok(self.idling) Feb 11 19:53:48 volumio volumio[20659]: error: The expression evaluated to a falsy value: Feb 11 19:53:48 volumio volumio[20659]: assert.ok(self.idling) Feb 11 19:53:48 volumio volumio[20659]: info: MPD running with PID20886 Feb 11 19:53:48 volumio volumio[20659]: ,establishing connection Feb 11 19:53:48 volumio volumio[20659]: error: updateQueue error: null Feb 11 19:53:48 volumio volumio[20659]: info: Completed starting Core Plugins Feb 11 19:53:48 volumio volumio[20659]: info: ------------------------------------------- Feb 11 19:53:48 volumio volumio[20659]: info: ----- MyVolumio plugins startup ---- Feb 11 19:53:48 volumio volumio[20659]: info: ------------------------------------------- Feb 11 19:53:48 volumio volumio[20659]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 11 19:53:48 volumio volumio[20659]: error: updateQueue error: null Feb 11 19:53:49 volumio go-librespot[20978]: time="2026-02-11T19:53:49+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 11 19:53:49 volumio go-librespot[20978]: time="2026-02-11T19:53:49+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 11 19:53:49 volumio go-librespot[20978]: time="2026-02-11T19:53:49+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 11 19:53:49 volumio go-librespot[20978]: time="2026-02-11T19:53:49+07:00" level=info msg="zeroconf server listening on port 35501" Feb 11 19:53:49 volumio go-librespot[20978]: time="2026-02-11T19:53:49+07:00" level=debug msg="obtained new client token: AAATGs7PctmPD6p866MPesqdDppdAlk5my8biBxyFhodcOv86C6OGHbYK8CU4hKYqzaU6SWD78r+18sZ6XYg8tSL+jNoArTuZQ+Scp62iUyZbBk8XQdgzxqjx8O5nwCvjO9SDYDoVEK5iXp/O+KkSroZuucE/wI81JxI14eY79MIzQyaGzefOK1EokO4fSrST3dvsqa5iPRZVAGXDVDQj0aAVfdxnBudJPNP/axBXogHwyxv8VCNKRE=" Feb 11 19:53:49 volumio go-librespot[20978]: time="2026-02-11T19:53:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 19:53:49 volumio go-librespot[20978]: time="2026-02-11T19:53:49+07:00" level=debug msg="completed keyexchange" Feb 11 19:53:49 volumio go-librespot[20978]: time="2026-02-11T19:53:49+07:00" level=debug msg="completed challenge" Feb 11 19:53:49 volumio go-librespot[20978]: time="2026-02-11T19:53:49+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 19:53:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 19:53:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 19:53:50 volumio volumio[20659]: info: Initializing connection to go-librespot Websocket Feb 11 19:53:50 volumio volumio[20659]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 19:53:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 11 19:53:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:53:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:53:52 volumio go-librespot[20985]: go-librespot daemon starting... Feb 11 19:53:52 volumio go-librespot[20986]: time="2026-02-11T19:53:52+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 19:53:52 volumio go-librespot[20986]: time="2026-02-11T19:53:52+07:00" level=debug msg="app state loaded" Feb 11 19:53:52 volumio go-librespot[20986]: time="2026-02-11T19:53:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 19:53:53 volumio go-librespot[20986]: time="2026-02-11T19:53:53+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 19:53:53 volumio go-librespot[20986]: time="2026-02-11T19:53:53+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 11 19:53:53 volumio go-librespot[20986]: time="2026-02-11T19:53:53+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 11 19:53:53 volumio go-librespot[20986]: time="2026-02-11T19:53:53+07:00" level=info msg="zeroconf server listening on port 36463" Feb 11 19:53:53 volumio go-librespot[20986]: time="2026-02-11T19:53:53+07:00" level=debug msg="obtained new client token: AADmmWmPN9YhCT/F5+skpOXv0MeqekOKxnTaUXTl62ZdAwhVIqK/v9SUlXzzdKK9kU7/4/4p++mEzyqlG+KJPrhac2bWLJF0VX1dnMPStg3YuUWg7Tfn6jfKppBb7BzKpCXKXxQXLJXP2fgUV2WlwCkSO1kpZb5cKswDwwMCElfLYFw6Vq5iEQKW3aemEkjyIv/Q4g2wARU+dN1tnCuxOGXZbGep4ZHj+pWzy+WkaKh1+04KMRwffvB/BQ==" Feb 11 19:53:53 volumio volumio[20659]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 11 19:53:53 volumio go-librespot[20986]: time="2026-02-11T19:53:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 19:53:53 volumio go-librespot[20986]: time="2026-02-11T19:53:53+07:00" level=debug msg="completed keyexchange" Feb 11 19:53:53 volumio go-librespot[20986]: time="2026-02-11T19:53:53+07:00" level=debug msg="completed challenge" Feb 11 19:53:53 volumio go-librespot[20986]: time="2026-02-11T19:53:53+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 19:53:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 19:53:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 19:53:53 volumio volumio[20659]: info: Initializing connection to go-librespot Websocket Feb 11 19:53:53 volumio volumio[20659]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 19:53:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 11 19:53:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:53:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:53:56 volumio go-librespot[20995]: go-librespot daemon starting... Feb 11 19:53:56 volumio volumio[20659]: info: Initializing connection to go-librespot Websocket Feb 11 19:53:56 volumio volumio[20659]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 19:53:56 volumio go-librespot[20996]: time="2026-02-11T19:53:56+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 19:53:56 volumio go-librespot[20996]: time="2026-02-11T19:53:56+07:00" level=debug msg="app state loaded" Feb 11 19:53:56 volumio go-librespot[20996]: time="2026-02-11T19:53:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 19:53:57 volumio volumio[20659]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 11 19:53:57 volumio volumio[20659]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 11 19:53:57 volumio volumio[20659]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 11 19:53:57 volumio volumio[20659]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 11 19:53:57 volumio volumio[20659]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 11 19:53:57 volumio volumio[20659]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 11 19:53:57 volumio volumio[20659]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 11 19:53:57 volumio volumio[20659]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 11 19:53:57 volumio volumio[20659]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 11 19:53:57 volumio volumio[20659]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 11 19:53:57 volumio volumio[20659]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 11 19:53:57 volumio volumio[20659]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 11 19:53:57 volumio volumio[20659]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 11 19:53:57 volumio volumio[20659]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 11 19:53:57 volumio volumio[20659]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 11 19:53:57 volumio volumio[20659]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 11 19:53:57 volumio volumio[20659]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 11 19:53:57 volumio volumio[20659]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 11 19:53:57 volumio volumio[20659]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 11 19:53:57 volumio volumio[20659]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 11 19:53:57 volumio volumio[20659]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 11 19:53:57 volumio volumio[20659]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 11 19:53:57 volumio volumio[20659]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 11 19:53:57 volumio volumio[20659]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 11 19:53:57 volumio volumio[20659]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 11 19:53:57 volumio volumio[20659]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 11 19:53:57 volumio volumio[20659]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 11 19:53:57 volumio volumio[20659]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 11 19:53:57 volumio go-librespot[20996]: time="2026-02-11T19:53:57+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 19:53:57 volumio go-librespot[20996]: time="2026-02-11T19:53:57+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 11 19:53:57 volumio go-librespot[20996]: time="2026-02-11T19:53:57+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 11 19:53:57 volumio volumio[20659]: info: Adding plugin bluetooth to MyMusic Plugins Feb 11 19:53:57 volumio volumio[20659]: info: Adding plugin multiroom to MyMusic Plugins Feb 11 19:53:57 volumio volumio[20659]: info: Adding plugin metavolumio to MyMusic Plugins Feb 11 19:53:57 volumio volumio[20659]: info: Adding plugin cd_controller to MyMusic Plugins Feb 11 19:53:57 volumio volumio[20659]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 11 19:53:57 volumio volumio[20659]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 11 19:53:57 volumio volumio[20659]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 11 19:53:57 volumio volumio[20659]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 11 19:53:57 volumio go-librespot[20996]: time="2026-02-11T19:53:57+07:00" level=info msg="zeroconf server listening on port 42783" Feb 11 19:53:57 volumio go-librespot[20996]: time="2026-02-11T19:53:57+07:00" level=debug msg="obtained new client token: AABf96JO+8TnRxGQZ+nZeyA9uGsnBDhaqQrMHF13oBSusL8ynujMAhOMKwRb8zm5iV+fTzFCnu5LI/S4voBtMe2+nKr/ql/v1B+TvoyopTjcVN/GyZky9NItBd402XXAY5kpGkp5piya/XU+9w8eo7BVHbqijhxLx/x4ZvNiZZrrIvY6ktZEx7dGREEcyh4oyA2HPeVS9w78JRcIsI4/7HSi1yErNfYflkNjluoYwwibFrbIiDz3tSIC7Q==" Feb 11 19:53:57 volumio go-librespot[20996]: time="2026-02-11T19:53:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 19:53:57 volumio go-librespot[20996]: time="2026-02-11T19:53:57+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 19:53:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 19:53:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 19:53:59 volumio volumio[20659]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 11 19:53:59 volumio volumio[20659]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 11 19:53:59 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 19:53:59 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 19:53:59 volumio volumio[20659]: info: Starting MyVolumio Remote Streaming Endpoints Feb 11 19:53:59 volumio volumio[20659]: info: MyVolumio login type: Token Feb 11 19:53:59 volumio volumio[20659]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 11 19:53:59 volumio volumio[20659]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 11 19:54:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 11 19:54:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:54:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:54:01 volumio go-librespot[21017]: go-librespot daemon starting... Feb 11 19:54:01 volumio volumio[20659]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 11 19:54:01 volumio volumio[20659]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 11 19:54:01 volumio volumio[20659]: info: Streaming services startup Feb 11 19:54:01 volumio volumio[20659]: info: Starting Streaming Daemon Feb 11 19:54:01 volumio go-librespot[21018]: time="2026-02-11T19:54:01+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 19:54:01 volumio go-librespot[21018]: time="2026-02-11T19:54:01+07:00" level=debug msg="app state loaded" Feb 11 19:54:01 volumio go-librespot[21018]: time="2026-02-11T19:54:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 19:54:01 volumio sudo[21025]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 11 19:54:01 volumio sudo[21025]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:54:01 volumio volumio[20659]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 11 19:54:01 volumio sudo[21025]: pam_unix(sudo:session): session closed for user root Feb 11 19:54:01 volumio volumio[20659]: info: Initializing connection to go-librespot Websocket Feb 11 19:54:01 volumio volumio[20659]: error: Cannot start Volumio Streaming Daemon Feb 11 19:54:01 volumio volumio[20659]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 11 19:54:01 volumio volumio[20659]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 11 19:54:01 volumio go-librespot[21018]: time="2026-02-11T19:54:01+07:00" level=debug msg="new websocket client" Feb 11 19:54:01 volumio volumio[20659]: info: Connection to go-librespot Websocket established Feb 11 19:54:01 volumio go-librespot[21018]: time="2026-02-11T19:54: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 11 19:54:01 volumio go-librespot[21018]: time="2026-02-11T19:54:01+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 11 19:54:01 volumio go-librespot[21018]: time="2026-02-11T19:54:01+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 11 19:54:01 volumio go-librespot[21018]: time="2026-02-11T19:54:01+07:00" level=info msg="zeroconf server listening on port 42821" Feb 11 19:54:01 volumio go-librespot[21018]: time="2026-02-11T19:54:01+07:00" level=debug msg="obtained new client token: AACnK2yJpQxlb39wxkuoimSVJXYbGOtxjUZ4wo4wek/AwOz7Z/YKDBwzdP9hxrEKWlm5IdpCcFxfgLpbuttSPxmguJobY9jKdVMWU3gwG7dwJA5NbFNzZh/5AazMkT2PoqTTlc97iRxfhmLtVX8ke6OwmEVv609PVEIjpG6SQ7GyCssXYAxMyVovv5Gjl3JfSDVNasbzjRyMOUYVdoEYg4dMccoHcauNqX867byZb51RqSYma9RxoyxDLA==" Feb 11 19:54:02 volumio go-librespot[21018]: time="2026-02-11T19:54:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 19:54:02 volumio go-librespot[21018]: time="2026-02-11T19:54:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 19:54:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 19:54:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 19:54:02 volumio volumio[20659]: info: Connection to go-librespot Websocket closed Feb 11 19:54:02 volumio volumio[20659]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 11 19:54:03 volumio volumio[20659]: info: MyVolumio token set successfully Feb 11 19:54:03 volumio volumio[20659]: info: MYVOLUMIO: Adding device Feb 11 19:54:03 volumio volumio[20659]: info: MYVOLUMIO: Evaluating Server Feb 11 19:54:03 volumio volumio[20659]: info: MyVolumio status changed Feb 11 19:54:03 volumio volumio[20659]: info: Streaming services startup Feb 11 19:54:03 volumio volumio[20659]: info: Starting Streaming Daemon Feb 11 19:54:03 volumio volumio[20659]: info: Removing browser output: myVolumio user plan is not superstar Feb 11 19:54:03 volumio volumio[20659]: info: Removing audio output: Feb 11 19:54:03 volumio volumio[20659]: info: Stoppping Tunnel 1 Feb 11 19:54:03 volumio sudo[21055]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 11 19:54:03 volumio sudo[21055]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:54:03 volumio sudo[21055]: pam_unix(sudo:session): session closed for user root Feb 11 19:54:03 volumio volumio[20659]: error: Cannot start Volumio Streaming Daemon Feb 11 19:54:03 volumio volumio[20659]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 11 19:54:03 volumio volumio[20659]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 11 19:54:03 volumio sudo[21058]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 11 19:54:03 volumio sudo[21058]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:54:03 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 11 19:54:03 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 11 19:54:03 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 11 19:54:03 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 11 19:54:03 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 11 19:54:03 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 11 19:54:03 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 11 19:54:03 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 11 19:54:03 volumio sudo[21058]: pam_unix(sudo:session): session closed for user root Feb 11 19:54:03 volumio volumio[20659]: info: Remote SSH Stopped Feb 11 19:54:04 volumio volumio[20659]: info: Setting Geolocation for MyVolumio to as1 Feb 11 19:54:04 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 19:54:04 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 19:54:04 volumio volumio[20659]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 19:54:04 volumio volumio[20659]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 11 19:54:04 volumio volumio[20659]: info: Getting Spotify volume Feb 11 19:54:04 volumio volumio[20659]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 19:54:04 volumio volumio[20659]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 19:54:04 volumio volumio[20659]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 11 19:54:04 volumio volumio[20659]: errno: -111, Feb 11 19:54:04 volumio volumio[20659]: code: 'ECONNREFUSED', Feb 11 19:54:04 volumio volumio[20659]: syscall: 'connect', Feb 11 19:54:04 volumio volumio[20659]: address: '127.0.0.1', Feb 11 19:54:04 volumio volumio[20659]: port: 9879, Feb 11 19:54:04 volumio volumio[20659]: response: undefined Feb 11 19:54:04 volumio volumio[20659]: } Feb 11 19:54:04 volumio volumio[20659]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 19:54:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 11 19:54:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:54:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:54:05 volumio go-librespot[21072]: go-librespot daemon starting... Feb 11 19:54:05 volumio go-librespot[21073]: time="2026-02-11T19:54:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 19:54:05 volumio go-librespot[21073]: time="2026-02-11T19:54:05+07:00" level=debug msg="app state loaded" Feb 11 19:54:05 volumio go-librespot[21073]: time="2026-02-11T19:54:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 19:54:05 volumio go-librespot[21073]: time="2026-02-11T19:54: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 11 19:54:05 volumio go-librespot[21073]: time="2026-02-11T19:54: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 11 19:54:05 volumio go-librespot[21073]: time="2026-02-11T19:54: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 11 19:54:05 volumio sudo[21082]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-11 19:53' Feb 11 19:54:05 volumio sudo[21082]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:54:05 volumio go-librespot[21073]: time="2026-02-11T19:54:05+07:00" level=info msg="zeroconf server listening on port 45249" Feb 11 19:54:06 volumio sudo[21082]: pam_unix(sudo:session): session closed for user root Feb 11 19:54:06 volumio go-librespot[21073]: time="2026-02-11T19:54:06+07:00" level=debug msg="obtained new client token: AADBDH0Y44p13iHgXAUPPgHvXn4VqTdcB0+WniVTE5kucW5xNL37NYQF2pDl6bf3OrHUtu56qdWqLaZYAY97AMDP97O5zR5y+omOq/aPnLqDjkyPDmM/aS8NoUsCg25IIDzAmIgu+w2/RgB6pNZ/s3veyeD+YB0/OS3MqAdsfQAA4IPngBZZHW74u8nN2B9YHB+S8OXMkaAxUzK+EW9G8JVIV7LB/NjWNG2bE+VgzMD9GPXDzeYLm3U=" Feb 11 19:54:06 volumio go-librespot[21073]: time="2026-02-11T19:54:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 19:54:06 volumio volumio-remote-updater[643]: [2026-02-11 19:54:06] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Feb 11 19:54:06 volumio volumio-remote-updater[643]: [2026-02-11 19:54:06] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Feb 11 19:54:06 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 11 19:54:06 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 11 19:54:06 volumio systemd[1]: volumio.service: Consumed 56.709s CPU time. Feb 11 19:54:06 volumio go-librespot[21073]: time="2026-02-11T19:54:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 19:54:06 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 11 19:54:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 19:54:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 19:54:06 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 11 19:54:06 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 12111. Feb 11 19:54:06 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 11 19:54:06 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 11 19:54:06 volumio systemd[1]: volumio.service: Consumed 56.709s CPU time. Feb 11 19:54:06 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 11 19:54:06 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 11 19:54:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 11 19:54:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:54:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:54:09 volumio go-librespot[21110]: go-librespot daemon starting... Feb 11 19:54:09 volumio go-librespot[21111]: time="2026-02-11T19:54:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 19:54:09 volumio go-librespot[21111]: time="2026-02-11T19:54:09+07:00" level=debug msg="app state loaded" Feb 11 19:54:09 volumio go-librespot[21111]: time="2026-02-11T19:54:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 19:54:10 volumio volumio[21094]: info: ------------------------------------------- Feb 11 19:54:10 volumio volumio[21094]: info: ----- Volumio3 ---- Feb 11 19:54:10 volumio volumio[21094]: info: ------------------------------------------- Feb 11 19:54:10 volumio volumio[21094]: info: ----- System startup ---- Feb 11 19:54:10 volumio volumio[21094]: info: ------------------------------------------- Feb 11 19:54:10 volumio go-librespot[21111]: time="2026-02-11T19:54:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 19:54:10 volumio go-librespot[21111]: time="2026-02-11T19:54:10+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 11 19:54:10 volumio go-librespot[21111]: time="2026-02-11T19:54:10+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 11 19:54:10 volumio go-librespot[21111]: time="2026-02-11T19:54:10+07:00" level=info msg="zeroconf server listening on port 35597" Feb 11 19:54:10 volumio go-librespot[21111]: time="2026-02-11T19:54:10+07:00" level=debug msg="obtained new client token: AACYxpN/OVRSWRlivU1DTBvcDR760XaHUaR2lh3et1RWOTd6fA6esI/UhSd4qxXq2xUNmmcL9p2r2LhyGbgmKToFs9e5FDElcfV5zmSJ0qYGOMe77S+ILHYXinUp13s8XxOK6xhnuii/b98NRN4dsiGuifvSBDzpJKZ/FXPKKAcS/UyF2YsFX+lPTjxKZrWOmWWCAVm0EUyJHNbtnFPSRj+nMNIqwQrJhFhYGl1e0CHFUo5dO5gPROSSNA==" Feb 11 19:54:10 volumio go-librespot[21111]: time="2026-02-11T19:54:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 19:54:10 volumio go-librespot[21111]: time="2026-02-11T19:54:10+07:00" level=debug msg="completed keyexchange" Feb 11 19:54:10 volumio go-librespot[21111]: time="2026-02-11T19:54:10+07:00" level=debug msg="completed challenge" Feb 11 19:54:10 volumio go-librespot[21111]: time="2026-02-11T19:54: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 11 19:54:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 19:54:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 19:54:11 volumio volumio-remote-updater[643]: [2026-02-11 19:54:11] [connect] Successful connection Feb 11 19:54:11 volumio volumio[21094]: info: MYVOLUMIO Environment detected Feb 11 19:54:11 volumio volumio[21094]: info: Plugin folders cleanup Feb 11 19:54:11 volumio volumio[21094]: info: Scanning into folder /volumio/app/plugins/ Feb 11 19:54:11 volumio volumio[21094]: info: Scanning category audio_interface Feb 11 19:54:11 volumio volumio[21094]: info: Scanning category miscellanea Feb 11 19:54:11 volumio volumio[21094]: info: Scanning category music_service Feb 11 19:54:11 volumio volumio[21094]: info: Scanning category plugins.json Feb 11 19:54:11 volumio volumio[21094]: info: Scanning category system_controller Feb 11 19:54:11 volumio volumio[21094]: info: Scanning category user_interface Feb 11 19:54:11 volumio volumio[21094]: info: Scanning into folder /data/plugins/ Feb 11 19:54:11 volumio volumio[21094]: info: Scanning category music_service Feb 11 19:54:11 volumio volumio[21094]: info: Plugin folders cleanup completed Feb 11 19:54:11 volumio volumio[21094]: info: ------------------------------------------- Feb 11 19:54:11 volumio volumio[21094]: info: ----- Core plugins startup ---- Feb 11 19:54:11 volumio volumio[21094]: info: ------------------------------------------- Feb 11 19:54:11 volumio volumio[21094]: info: Loading plugins from folder /volumio/app/plugins/ Feb 11 19:54:11 volumio volumio[21094]: info: Adding plugin upnp to MyMusic Plugins Feb 11 19:54:11 volumio volumio[21094]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 11 19:54:11 volumio volumio[21094]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 11 19:54:11 volumio volumio[21094]: info: Loading plugins from folder /data/plugins/ Feb 11 19:54:11 volumio volumio[21094]: info: Loading plugin "system"... Feb 11 19:54:11 volumio volumio[21094]: info: Loading plugin "appearance"... Feb 11 19:54:13 volumio volumio[21094]: info: Loading plugin "network"... Feb 11 19:54:13 volumio volumio[21094]: info: Refreshing Cached IP Addresses Feb 11 19:54:13 volumio sudo[21135]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 19:54:13 volumio sudo[21135]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:54:13 volumio volumio[21094]: info: Loading plugin "services"... Feb 11 19:54:13 volumio sudo[21135]: pam_unix(sudo:session): session closed for user root Feb 11 19:54:13 volumio sudo[21137]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 19:54:13 volumio sudo[21137]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:54:13 volumio volumio[21094]: info: Loading plugin "alsa_controller"... Feb 11 19:54:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Feb 11 19:54:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:54:13 volumio sudo[21144]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 11 19:54:13 volumio sudo[21144]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:54:13 volumio sudo[21137]: pam_unix(sudo:session): session closed for user root Feb 11 19:54:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:54:13 volumio go-librespot[21155]: go-librespot daemon starting... Feb 11 19:54:13 volumio go-librespot[21162]: time="2026-02-11T19:54:13+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 19:54:13 volumio go-librespot[21162]: time="2026-02-11T19:54:13+07:00" level=debug msg="app state loaded" Feb 11 19:54:13 volumio go-librespot[21162]: time="2026-02-11T19:54:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 19:54:13 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 19:54:13 volumio volumio[21094]: info: Loading plugin "wizard"... Feb 11 19:54:14 volumio volumio[21094]: info: Loading plugin "networkfs"... Feb 11 19:54:14 volumio volumio[21094]: info: Starting Udev Watcher for removable devices Feb 11 19:54:14 volumio volumio[21094]: info: Ignoring mount for partition: boot Feb 11 19:54:14 volumio volumio[21094]: info: Ignoring mount for partition: volumio Feb 11 19:54:14 volumio volumio[21094]: info: Ignoring mount for partition: volumio_data Feb 11 19:54:14 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 19:54:14 volumio volumio[21094]: info: Loading plugin "volumio_command_line_client"... Feb 11 19:54:14 volumio volumio[21094]: info: Loading plugin "upnp"... Feb 11 19:54:14 volumio volumio[21094]: info: [1770814454151] Starting Upmpd Daemon Feb 11 19:54:14 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 19:54:14 volumio volumio[21094]: info: Loading plugin "my_music"... Feb 11 19:54:14 volumio volumio[21094]: info: Loading plugin "mpd"... Feb 11 19:54:14 volumio go-librespot[21162]: time="2026-02-11T19:54: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-gew1.spotify.com:80]" Feb 11 19:54:14 volumio go-librespot[21162]: time="2026-02-11T19:54:14+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 11 19:54:14 volumio go-librespot[21162]: time="2026-02-11T19:54:14+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 11 19:54:14 volumio go-librespot[21162]: time="2026-02-11T19:54:14+07:00" level=info msg="zeroconf server listening on port 35099" Feb 11 19:54:14 volumio go-librespot[21162]: time="2026-02-11T19:54:14+07:00" level=debug msg="obtained new client token: AAAAGjXGSVLS/c8ZPWfiIjUHVJF8cgqD7vi0FdtX7/E1ksUC+LGULWxnEStI3AD4FQgK8Uqu1wWaz4tQ0GrqXtU/7RD7ffs2x3OA7y6tI/zULCaB9pTstbNqm5Obpuc6mE5pHfIdl1iyyPpZnW6HotARXF9T7Xqhj+v0ATBBr54vgEcO6JRe0uAx+N4qlaeIKrPjLH6tziHh9iY3W4Lx96mhCBf3LDBl09T2pByVUXS2rz0Out1fMjxzlA==" Feb 11 19:54:14 volumio volumio[21094]: info: Loading plugin "upnp_browser"... Feb 11 19:54:14 volumio go-librespot[21162]: time="2026-02-11T19:54:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 19:54:14 volumio go-librespot[21162]: time="2026-02-11T19:54:14+07:00" level=debug msg="completed keyexchange" Feb 11 19:54:14 volumio go-librespot[21162]: time="2026-02-11T19:54:14+07:00" level=debug msg="completed challenge" Feb 11 19:54:15 volumio go-librespot[21162]: time="2026-02-11T19:54: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 11 19:54:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 19:54:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 19:54:16 volumio sudo[21144]: pam_unix(sudo:session): session closed for user root Feb 11 19:54:17 volumio volumio[21094]: info: Starting UPNP Browser Feb 11 19:54:17 volumio volumio[21094]: info: Loading plugin "alarm-clock"... Feb 11 19:54:18 volumio volumio[21094]: info: Loading plugin "airplay_emulation"... Feb 11 19:54:18 volumio volumio[21094]: info: Starting Shairport Sync Feb 11 19:54:18 volumio volumio[21094]: info: Loading plugin "last_100"... Feb 11 19:54:18 volumio volumio[21094]: info: Loading plugin "webradio"... Feb 11 19:54:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Feb 11 19:54:18 volumio volumio[21094]: info: Loading plugin "i2s_dacs"... Feb 11 19:54:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:54:18 volumio volumio[21094]: info: Loading plugin "volumiodiscovery"... Feb 11 19:54:18 volumio volumio[21094]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 11 19:54:18 volumio volumio[21094]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 19:54:18 volumio volumio[21094]: *** WARNING *** For more information see Feb 11 19:54:18 volumio volumio[21094]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 11 19:54:18 volumio volumio[21094]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 19:54:18 volumio volumio[21094]: *** WARNING *** For more information see Feb 11 19:54:18 volumio node[21094]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 11 19:54:18 volumio node[21094]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 19:54:18 volumio node[21094]: *** WARNING *** For more information see Feb 11 19:54:18 volumio node[21094]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 11 19:54:18 volumio node[21094]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 19:54:18 volumio node[21094]: *** WARNING *** For more information see Feb 11 19:54:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:54:18 volumio volumio[21094]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 11 19:54:18 volumio go-librespot[21176]: go-librespot daemon starting... Feb 11 19:54:18 volumio volumio[21094]: info: Discovery: Started advertising with name: Volumio Feb 11 19:54:18 volumio go-librespot[21177]: time="2026-02-11T19:54:18+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 19:54:18 volumio go-librespot[21177]: time="2026-02-11T19:54:18+07:00" level=debug msg="app state loaded" Feb 11 19:54:18 volumio go-librespot[21177]: time="2026-02-11T19:54:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 19:54:18 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 19:54:18 volumio volumio[21094]: info: Loading plugin "spop"... Feb 11 19:54:18 volumio go-librespot[21177]: time="2026-02-11T19:54:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 19:54:18 volumio go-librespot[21177]: time="2026-02-11T19:54:18+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 11 19:54:18 volumio go-librespot[21177]: time="2026-02-11T19:54:18+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 11 19:54:18 volumio go-librespot[21177]: time="2026-02-11T19:54:18+07:00" level=info msg="zeroconf server listening on port 37173" Feb 11 19:54:19 volumio go-librespot[21177]: time="2026-02-11T19:54:19+07:00" level=debug msg="obtained new client token: AAA9ztvB2h7LoeK1LDpEmfcd2IVVIvpyLzvI76MqkHetsIPaMavbIPLZgLrr/cAoIWs0LdTMV/VGU1Kv9ncJywxeA/vxQKBbS6WfjTl7luW5K68EaCfUKZY8IKOml0xXMnT26z36cgWjkfZ54ZeswDWoTZC5Sn4ahGIQLvYHPrL1JMqL5MNAvNNWfdest+EZnuGTKe1cBcz4frO95OAoFBWLc0Nwa2Jtd7RMuaXcZ2TFk0Jvm2DzNhE=" Feb 11 19:54:19 volumio go-librespot[21177]: time="2026-02-11T19:54:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 19:54:19 volumio go-librespot[21177]: time="2026-02-11T19:54:19+07:00" level=debug msg="completed keyexchange" Feb 11 19:54:19 volumio go-librespot[21177]: time="2026-02-11T19:54:19+07:00" level=debug msg="completed challenge" Feb 11 19:54:19 volumio go-librespot[21177]: time="2026-02-11T19:54: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 11 19:54:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 19:54:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 19:54:20 volumio volumio[21094]: info: Loading plugin "ytcr"... Feb 11 19:54:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Feb 11 19:54:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:54:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:54:22 volumio go-librespot[21187]: go-librespot daemon starting... Feb 11 19:54:22 volumio go-librespot[21188]: time="2026-02-11T19:54:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 19:54:22 volumio go-librespot[21188]: time="2026-02-11T19:54:22+07:00" level=debug msg="app state loaded" Feb 11 19:54:22 volumio go-librespot[21188]: time="2026-02-11T19:54:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 19:54:23 volumio volumio[21094]: info: Loading plugin "ytmusic"... Feb 11 19:54:23 volumio go-librespot[21188]: time="2026-02-11T19:54:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 19:54:23 volumio go-librespot[21188]: time="2026-02-11T19:54:23+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 19:54:23 volumio go-librespot[21188]: time="2026-02-11T19:54:23+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 19:54:23 volumio go-librespot[21188]: time="2026-02-11T19:54:23+07:00" level=info msg="zeroconf server listening on port 38141" Feb 11 19:54:23 volumio go-librespot[21188]: time="2026-02-11T19:54:23+07:00" level=debug msg="obtained new client token: AABaLxZyp5ECyyaz9PxAC7TW3f8ozXCV/HtqkYHM4H4FMIvpp5LwfPw7bbH6OPVUNAZsLQNiDMsxMxyyKYpXolKsnTi/TpwupNjKCAs/aHSu1gG4Hz3UEB97IXVH6rIblc/EGQ0tvmfyZPWxCT445r+b2uME6wohSYp1jtZj+i2AjQ6vvdg6uYqc3yuThd8nE6rPcklULCA7t8+I2Ey8gSmlT+qR5XI3Xx71/hC/OkLML54M3QwR5KL81Q==" Feb 11 19:54:23 volumio go-librespot[21188]: time="2026-02-11T19:54:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 19:54:23 volumio go-librespot[21188]: time="2026-02-11T19:54:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 19:54:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 19:54:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 19:54:23 volumio volumio-remote-updater[643]: [2026-02-11 19:54:23] [connect] Successful connection Feb 11 19:54:24 volumio volumio[21094]: info: Loading plugin "outputs"... Feb 11 19:54:24 volumio volumio[21094]: info: Loading plugin "albumart"... Feb 11 19:54:24 volumio volumio[21094]: info: Plugin example_plugin is not enabled Feb 11 19:54:24 volumio volumio[21094]: info: Loading plugin "inputs"... Feb 11 19:54:24 volumio volumio[21094]: info: Loading plugin "updater_comm"... Feb 11 19:54:24 volumio volumio[21094]: info: Plugin mpdemulation is not enabled Feb 11 19:54:24 volumio volumio[21094]: info: Loading plugin "rest_api"... Feb 11 19:54:24 volumio volumio[21094]: info: Loading plugin "websocket"... Feb 11 19:54:24 volumio volumio[21094]: info: Starting Socket.io Server version 1.7.4 Feb 11 19:54:24 volumio volumio[21094]: info: Loading plugin "RoonBridge"... Feb 11 19:54:24 volumio volumio[21094]: info: Applying required configuration parameters for plugin RoonBridge Feb 11 19:54:24 volumio volumio[21094]: info: Loading i18n strings for locale en Feb 11 19:54:24 volumio volumio[21094]: Updating browse sources language Feb 11 19:54:24 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 19:54:25 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 19:54:25 volumio volumio[21094]: info: CoreCommandRouter::initPlayerControls Feb 11 19:54:25 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:54:25 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:54:25 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:54:25 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:54:25 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:54:25 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:54:25 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:54:25 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:54:25 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 19:54:25 volumio volumio[21094]: Express server listening on port 3000 Feb 11 19:54:25 volumio volumio[21094]: [Metrics] WebUI: 16s 58.19ms Feb 11 19:54:25 volumio volumio[21210]: Forking 3 albumart workers Feb 11 19:54:25 volumio volumio[21094]: info: CoreStateMachine::resetVolumioState Feb 11 19:54:25 volumio volumio[21094]: info: CoreStateMachine::getcurrentVolume Feb 11 19:54:25 volumio volumio[21094]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 19:54:25 volumio sudo[21245]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 19:54:25 volumio sudo[21245]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:54:25 volumio sudo[21236]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 19:54:25 volumio sudo[21245]: pam_unix(sudo:session): session closed for user root Feb 11 19:54:25 volumio sudo[21236]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:54:25 volumio sudo[21236]: pam_unix(sudo:session): session closed for user root Feb 11 19:54:25 volumio volumio[21094]: info: Volumio Network Manager: Network status updated: 1 Feb 11 19:54:25 volumio volumio-remote-updater[643]: [2026-02-11 19:54:25] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770814463 101 Feb 11 19:54:25 volumio volumio[21094]: 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 11 19:54:25 volumio volumio[21094]: info: VolumeController:: Volume=100 Mute =false Feb 11 19:54:25 volumio volumio[21094]: info: CoreStateMachine::pushState Feb 11 19:54:25 volumio volumio[21094]: info: CorePlayQueue::getTrack 0 Feb 11 19:54:25 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 19:54:25 volumio volumio[21094]: info: CoreCommandRouter::volumioPushState Feb 11 19:54:25 volumio volumio[21094]: info: CoreStateMachine::updateTrackBlock Feb 11 19:54:25 volumio volumio[21094]: info: CorePlayQueue::getTrackBlock Feb 11 19:54:25 volumio volumio[21094]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 19:54:25 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 19:54:25 volumio volumio[21094]: info: Reloading queue from file Feb 11 19:54:26 volumio volumio[21094]: info: CoreStateMachine::setRepeat null single undefined Feb 11 19:54:26 volumio volumio[21094]: info: CoreStateMachine::pushState Feb 11 19:54:26 volumio volumio[21094]: info: CorePlayQueue::getTrack 0 Feb 11 19:54:26 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 19:54:26 volumio volumio[21094]: info: CoreCommandRouter::volumioPushState Feb 11 19:54:26 volumio volumio[21094]: info: CoreStateMachine::setRandom null Feb 11 19:54:26 volumio volumio[21094]: info: CoreStateMachine::pushState Feb 11 19:54:26 volumio volumio[21094]: info: CorePlayQueue::getTrack 0 Feb 11 19:54:26 volumio volumio[21094]: info: CoreCommandRouter::volumioPushState Feb 11 19:54:26 volumio volumio[21094]: info: Setting Device type: Raspberry PI Feb 11 19:54:26 volumio volumio[21094]: info: Completed loading Core Plugins Feb 11 19:54:26 volumio volumio[21094]: info: Preparing to generate the ALSA configuration file Feb 11 19:54:26 volumio volumio[21094]: info: VolumeController:: Volume=100 Mute =false Feb 11 19:54:26 volumio volumio[21094]: info: CoreStateMachine::pushState Feb 11 19:54:26 volumio volumio[21094]: info: CorePlayQueue::getTrack 0 Feb 11 19:54:26 volumio volumio[21094]: info: CoreCommandRouter::volumioPushState Feb 11 19:54:26 volumio volumio[21094]: info: Asound.conf file unchanged, so no further update is needed Feb 11 19:54:26 volumio volumio[21094]: info: Output device has changed, restarting MPD Feb 11 19:54:26 volumio sudo[21270]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 11 19:54:26 volumio sudo[21270]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:54:26 volumio volumio[21094]: info: Output device has changed, restarting Shairport Sync Feb 11 19:54:26 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:54:26 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 19:54:26 volumio volumio[21094]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 19:54:26 volumio volumio[21094]: info: ___________ START PLUGINS ___________ Feb 11 19:54:26 volumio volumio[21094]: info: ControllerMpd::onStart: Initializing MPD Feb 11 19:54:26 volumio volumio[21094]: info: Creating MPD Configuration file Feb 11 19:54:26 volumio sudo[21272]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 19:54:26 volumio sudo[21272]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:54:26 volumio sudo[21272]: pam_unix(sudo:session): session closed for user root Feb 11 19:54:26 volumio sudo[21275]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 19:54:26 volumio sudo[21275]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:54:26 volumio sudo[21270]: pam_unix(sudo:session): session closed for user root Feb 11 19:54:26 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 19:54:26 volumio volumio[21094]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 19:54:26 volumio volumio[21094]: info: [1770814466558] CoreMusicLibrary::Adding element Media Servers Feb 11 19:54:26 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 19:54:26 volumio sudo[21282]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 19:54:26 volumio sudo[21282]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:54:26 volumio volumio[21094]: info: UPNP Browser: Client initialized successfully Feb 11 19:54:26 volumio sudo[21284]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 19:54:26 volumio sudo[21284]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:54:26 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:54:26 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 19:54:26 volumio sudo[21282]: pam_unix(sudo:session): session closed for user root Feb 11 19:54:26 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 11 19:54:26 volumio volumio[21094]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 19:54:26 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:54:26 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 19:54:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Feb 11 19:54:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:54:26 volumio volumio[21094]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 19:54:26 volumio volumio[21094]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 19:54:26 volumio volumio[21094]: info: [1770814466852] CoreMusicLibrary::Adding element Last_100 Feb 11 19:54:26 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 19:54:26 volumio volumio[21094]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 19:54:26 volumio volumio[21094]: info: [1770814466864] CoreMusicLibrary::Adding element Webradio Feb 11 19:54:26 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 19:54:26 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 19:54:26 volumio volumio[21094]: info: Initializing BBC Radios Feb 11 19:54:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:54:26 volumio go-librespot[21296]: go-librespot daemon starting... Feb 11 19:54:26 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 11 19:54:26 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 11 19:54:26 volumio systemd[1]: mpd.service: Consumed 7.176s CPU time. Feb 11 19:54:26 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 11 19:54:26 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 11 19:54:26 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 11 19:54:27 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 11 19:54:27 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 11 19:54:27 volumio go-librespot[21302]: time="2026-02-11T19:54:27+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 19:54:27 volumio go-librespot[21302]: time="2026-02-11T19:54:27+07:00" level=debug msg="app state loaded" Feb 11 19:54:27 volumio go-librespot[21302]: time="2026-02-11T19:54:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 19:54:27 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 19:54:27 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 19:54:27 volumio volumio[21094]: info: Creating Spotify config file Feb 11 19:54:27 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:54:27 volumio sudo[21311]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 11 19:54:27 volumio sudo[21311]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 11 19:54:27 volumio sudo[21311]: pam_unix(sudo:session): session closed for user root Feb 11 19:54:27 volumio go-librespot[21302]: time="2026-02-11T19:54:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 11 19:54:27 volumio go-librespot[21302]: time="2026-02-11T19:54:27+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 11 19:54:27 volumio go-librespot[21302]: time="2026-02-11T19:54:27+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 11 19:54:27 volumio go-librespot[21302]: time="2026-02-11T19:54:27+07:00" level=info msg="zeroconf server listening on port 43681" Feb 11 19:54:28 volumio go-librespot[21302]: time="2026-02-11T19:54:28+07:00" level=debug msg="obtained new client token: AAAssOGqIjOgEK7h21GHV5t/hDsq0/WYtWYK5GfnfMRQlARtcEZTtOTNHYfVY7+Ek+8y4bkSlZ3q1ESbNEsADS8aA0CiunQcI1N//CTvYFpyknaJ0q+231fM+AX3SSPhSxuTHi1+HrCYFndG9inoYfGnCGXFcQCu7FnveIXB0t7Mch9v9E2GX3lrVipR7OSbBzRnD8Uio4ReYa6cgMvCqgfWIX3Mp9HBcAaRmetL35Du39Zu6ltyNkc=" Feb 11 19:54:28 volumio go-librespot[21302]: time="2026-02-11T19:54:28+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 11 19:54:28 volumio volumio[21094]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 19:54:28 volumio volumio[21094]: info: [1770814468370] CoreMusicLibrary::Adding element YouTube Music Feb 11 19:54:28 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 19:54:28 volumio volumio[21094]: Cannot find translation for source YouTube Music Feb 11 19:54:28 volumio volumio[21094]: info: Volumio Calling Home Feb 11 19:54:28 volumio go-librespot[21302]: time="2026-02-11T19:54:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 11 19:54:28 volumio go-librespot[21302]: time="2026-02-11T19:54:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 19:54:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 19:54:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 19:54:28 volumio sudo[21322]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 11 19:54:28 volumio sudo[21322]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:54:28 volumio volumio[21224]: Starting albumart workers Feb 11 19:54:28 volumio sudo[21322]: pam_unix(sudo:session): session closed for user root Feb 11 19:54:29 volumio volumio[21223]: Starting albumart workers Feb 11 19:54:29 volumio volumio[21226]: Starting albumart workers Feb 11 19:54:29 volumio volumio[21094]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 11 19:54:29 volumio volumio[21094]: info: Discovery: Found device Volumio Feb 11 19:54:29 volumio volumio[21094]: info: CoreCommandRouter::volumioGetState Feb 11 19:54:29 volumio volumio[21094]: info: CorePlayQueue::getTrack 0 Feb 11 19:54:29 volumio volumio[21094]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 11 19:54:29 volumio volumio[21094]: info: Discovery: Found device Volumio Feb 11 19:54:29 volumio volumio[21094]: info: CoreCommandRouter::volumioGetState Feb 11 19:54:29 volumio volumio[21094]: info: CorePlayQueue::getTrack 0 Feb 11 19:54:29 volumio volumio[21094]: info: MPD Permissions set Feb 11 19:54:29 volumio volumio[21094]: info: MPD Permissions set Feb 11 19:54:29 volumio volumio[21094]: info: Upmpdcli Daemon Started Feb 11 19:54:29 volumio volumio[21094]: info: Spotify config file written Feb 11 19:54:29 volumio sudo[21328]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 11 19:54:29 volumio sudo[21328]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:54:29 volumio volumio[21094]: 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 11 19:54:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:54:29 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:54:29 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:54:29 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:54:29 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:54:29 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:54:29 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:54:29 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:54:29 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:54:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:54:29 volumio go-librespot[21330]: go-librespot daemon starting... Feb 11 19:54:29 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 19:54:29 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:54:29 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:54:29 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:54:29 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:54:29 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:54:29 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:54:29 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:54:29 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:54:29 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:54:29 volumio sudo[21328]: pam_unix(sudo:session): session closed for user root Feb 11 19:54:29 volumio go-librespot[21336]: time="2026-02-11T19:54:29+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 19:54:29 volumio go-librespot[21336]: time="2026-02-11T19:54:29+07:00" level=debug msg="app state loaded" Feb 11 19:54:29 volumio go-librespot[21336]: time="2026-02-11T19:54:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 19:54:29 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 19:54:29 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 19:54:29 volumio volumio[21094]: info: No need to fix Spotify hosts Feb 11 19:54:30 volumio go-librespot[21336]: time="2026-02-11T19:54:30+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 19:54:30 volumio go-librespot[21336]: time="2026-02-11T19:54:30+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 11 19:54:30 volumio go-librespot[21336]: time="2026-02-11T19:54:30+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 11 19:54:30 volumio go-librespot[21336]: time="2026-02-11T19:54:30+07:00" level=info msg="zeroconf server listening on port 33911" Feb 11 19:54:30 volumio go-librespot[21336]: time="2026-02-11T19:54:30+07:00" level=debug msg="obtained new client token: AACT9Mef7Z1t9uSsESkaUkBlLkfAru1i2RPUlxEyOw0dMTQHcXxvyHvk89QCXRL0q5jH5I2ma+9iYVNxkigeQR34VF6MG+YJZ2P2aY5B2tKzozLaG2w2lkNDZmX4h3IiN+3n4qlbWOjXCXGFGLTHK78VDTFLslTvJzjDoYKZEW8xioZG+EuoXU7GInnnwoicNtGP/9vZPOrX57hSLfZxMIlHuIL4gXlUvrGKA9RXM6+v7FTwoUNfhRi4vQ==" Feb 11 19:54:30 volumio volumio[21094]: info: Volumio called home Feb 11 19:54:30 volumio go-librespot[21336]: time="2026-02-11T19:54:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 19:54:31 volumio go-librespot[21336]: time="2026-02-11T19:54:31+07:00" level=debug msg="completed keyexchange" Feb 11 19:54:31 volumio go-librespot[21336]: time="2026-02-11T19:54:31+07:00" level=debug msg="completed challenge" Feb 11 19:54:31 volumio go-librespot[21336]: time="2026-02-11T19:54: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 11 19:54:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 19:54:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 19:54:31 volumio volumio[21094]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 11 19:54:31 volumio volumio[21094]: SPOTIFY: BQA_HV7R6nx9x7_tMw5_DlwTEZAsfonlzZJ4l72dZ88ftXjmtF10U9ezWgqy21EpfBMZtrLHmWTRd459AIstCyj_T1Pw9vS6aNpanrop_bcQKz2viomx6DjvVBjhzop4yT5T5L24FVxA2KoHzY4uV9ZmBi-iKNUZjtsLSQ2pnCGV4r2O6VOl7PQu6mO4BTIxz_CgXbW8K2G6Z9vGCyMStba8dCmdbzc5MvbvaB_39kxI6HHLBD__KqDFsPGot5XKxFnQfG5HtlMPL60mQnbjuODkVLxVdkmbqOGK3sJhko7zt3EYqxjlrvJY Feb 11 19:54:31 volumio volumio[21094]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 11 19:54:31 volumio volumio[21094]: info: New Spotify access token = BQA_HV7R6nx9x7_tMw5_DlwTEZAsfonlzZJ4l72dZ88ftXjmtF10U9ezWgqy21EpfBMZtrLHmWTRd459AIstCyj_T1Pw9vS6aNpanrop_bcQKz2viomx6DjvVBjhzop4yT5T5L24FVxA2KoHzY4uV9ZmBi-iKNUZjtsLSQ2pnCGV4r2O6VOl7PQu6mO4BTIxz_CgXbW8K2G6Z9vGCyMStba8dCmdbzc5MvbvaB_39kxI6HHLBD__KqDFsPGot5XKxFnQfG5HtlMPL60mQnbjuODkVLxVdkmbqOGK3sJhko7zt3EYqxjlrvJY Feb 11 19:54:31 volumio volumio[21094]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 11 19:54:31 volumio volumio[21094]: info: Starting Shairport Sync Feb 11 19:54:31 volumio volumio[21094]: info: Starting Shairport Sync Feb 11 19:54:31 volumio volumio[21094]: info: Starting Shairport Sync Feb 11 19:54:31 volumio sudo[21367]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 19:54:31 volumio sudo[21367]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:54:31 volumio sudo[21369]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 19:54:31 volumio sudo[21369]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:54:31 volumio sudo[21371]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 19:54:31 volumio sudo[21371]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:54:31 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 11 19:54:31 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 11 19:54:31 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 19:54:31 volumio systemd[1]: shairport-sync.service: Consumed 2.303s CPU time. Feb 11 19:54:31 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 19:54:31 volumio sudo[21371]: pam_unix(sudo:session): session closed for user root Feb 11 19:54:31 volumio sudo[21367]: pam_unix(sudo:session): session closed for user root Feb 11 19:54:31 volumio sudo[21369]: pam_unix(sudo:session): session closed for user root Feb 11 19:54:31 volumio volumio[21094]: info: CoreCommandRouter::volumioGetState Feb 11 19:54:31 volumio volumio[21094]: info: CorePlayQueue::getTrack 0 Feb 11 19:54:32 volumio volumio[21094]: info: Shairport-Sync Started Feb 11 19:54:32 volumio volumio[21094]: Error adding Membership: Error: addMembership EINVAL Feb 11 19:54:32 volumio volumio[21094]: info: Shairport-Sync Started Feb 11 19:54:32 volumio volumio[21094]: info: Shairport-Sync Started Feb 11 19:54:32 volumio volumio[21094]: 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 11 19:54:32 volumio volumio[21094]: info: Spotify Successfully logged in Feb 11 19:54:32 volumio volumio[21094]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 19:54:32 volumio volumio[21094]: info: [1770814472214] CoreMusicLibrary::Adding element Spotify Feb 11 19:54:32 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 19:54:32 volumio volumio[21094]: Cannot find translation for source YouTube Music Feb 11 19:54:32 volumio volumio[21094]: Cannot find translation for source Spotify Feb 11 19:54:32 volumio volumio[21094]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 11 19:54:32 volumio volumio[21094]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 19:54:33 volumio volumio[21094]: info: VolumeController:: Volume=100 Mute =false Feb 11 19:54:33 volumio volumio[21094]: info: CoreCommandRouter::volumioGetState Feb 11 19:54:33 volumio volumio[21094]: info: CorePlayQueue::getTrack 0 Feb 11 19:54:33 volumio volumio[21094]: info: CoreStateMachine::pushState Feb 11 19:54:33 volumio volumio[21094]: info: CorePlayQueue::getTrack 0 Feb 11 19:54:33 volumio volumio[21094]: info: CoreCommandRouter::volumioPushState Feb 11 19:54:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Feb 11 19:54:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:54:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:54:34 volumio go-librespot[21408]: go-librespot daemon starting... Feb 11 19:54:34 volumio volumio[21094]: info: go-librespot daemon successfully initialized Feb 11 19:54:34 volumio go-librespot[21409]: time="2026-02-11T19:54:34+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 19:54:34 volumio go-librespot[21409]: time="2026-02-11T19:54:34+07:00" level=debug msg="app state loaded" Feb 11 19:54:34 volumio go-librespot[21409]: time="2026-02-11T19:54:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 19:54:34 volumio mpd[21320]: 2026-02-11T19:54:34 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 11 19:54:34 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 11 19:54:34 volumio sudo[21275]: pam_unix(sudo:session): session closed for user root Feb 11 19:54:34 volumio sudo[21284]: pam_unix(sudo:session): session closed for user root Feb 11 19:54:34 volumio volumio[21094]: error: MPD error: The expression evaluated to a falsy value: Feb 11 19:54:34 volumio volumio[21094]: assert.ok(self.idling) Feb 11 19:54:34 volumio volumio[21094]: error: The expression evaluated to a falsy value: Feb 11 19:54:34 volumio volumio[21094]: assert.ok(self.idling) Feb 11 19:54:34 volumio volumio[21094]: info: MPD running with PID21320 Feb 11 19:54:34 volumio volumio[21094]: ,establishing connection Feb 11 19:54:34 volumio volumio[21094]: error: updateQueue error: null Feb 11 19:54:34 volumio volumio[21094]: info: Completed starting Core Plugins Feb 11 19:54:34 volumio volumio[21094]: info: ------------------------------------------- Feb 11 19:54:34 volumio volumio[21094]: info: ----- MyVolumio plugins startup ---- Feb 11 19:54:34 volumio volumio[21094]: info: ------------------------------------------- Feb 11 19:54:34 volumio volumio[21094]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 11 19:54:34 volumio volumio[21094]: error: updateQueue error: null Feb 11 19:54:34 volumio go-librespot[21409]: time="2026-02-11T19:54:34+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 19:54:34 volumio go-librespot[21409]: time="2026-02-11T19:54:34+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 19:54:34 volumio go-librespot[21409]: time="2026-02-11T19:54:34+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 19:54:35 volumio go-librespot[21409]: time="2026-02-11T19:54:35+07:00" level=info msg="zeroconf server listening on port 35629" Feb 11 19:54:35 volumio go-librespot[21409]: time="2026-02-11T19:54:35+07:00" level=debug msg="obtained new client token: AAB/J31QPF/88vyllqbTyvCUDF4X4HH2oVYsSwWF4txkLcZWX36R2TZW45ShQlDSwa4zmICAVDjPxbhkvxa20jEC+TFzC9vZolCBCNxO4LOQeKjxq/FiwpL9TMlTN8qZV5yuRYQRfHAIgsL12UQnXU8Idi0pkiXpdoFHsX6sMnbhiPNbNZaoKDXh3WDNdjT+N/ZYKDMt9JfP0Sf7+zH6I+x6oqS7BZZPxQgEaG+paI20e4WhyD6BPG0=" Feb 11 19:54:35 volumio go-librespot[21409]: time="2026-02-11T19:54:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 19:54:35 volumio go-librespot[21409]: time="2026-02-11T19:54:35+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 19:54:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 19:54:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 19:54:37 volumio volumio[21094]: info: Initializing connection to go-librespot Websocket Feb 11 19:54:37 volumio volumio[21094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 19:54:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Feb 11 19:54:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:54:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:54:38 volumio go-librespot[21420]: go-librespot daemon starting... Feb 11 19:54:38 volumio go-librespot[21421]: time="2026-02-11T19:54:38+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 19:54:38 volumio go-librespot[21421]: time="2026-02-11T19:54:38+07:00" level=debug msg="app state loaded" Feb 11 19:54:38 volumio go-librespot[21421]: time="2026-02-11T19:54:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 19:54:39 volumio go-librespot[21421]: time="2026-02-11T19:54:39+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 11 19:54:39 volumio go-librespot[21421]: time="2026-02-11T19:54:39+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 11 19:54:39 volumio go-librespot[21421]: time="2026-02-11T19:54:39+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 11 19:54:39 volumio go-librespot[21421]: time="2026-02-11T19:54:39+07:00" level=info msg="zeroconf server listening on port 36567" Feb 11 19:54:39 volumio go-librespot[21421]: time="2026-02-11T19:54:39+07:00" level=debug msg="obtained new client token: AABooY0L04EdY6+rMuB4G8Qqd7bZHMTkqhwpHK7umizieiikr++Z9MZQlMIIG9yAxQ6uLL9HupUxwbVV7jNcb/YJGH3/zp5Zi25JTcYXJdZwjLNfZMZsoJwpFW3HHhdHjCqPL13Y1hbujxTUcr+z6BG1hVbfqmgpvTjloJlyRdCDIGPdwxnAovAh3Mo0UH/X0LM8xkRiDNWf3IOPXSwdq6g89Vu2Q6dCR0prYSoqkZnrjPRCSLFCfioWJA==" Feb 11 19:54:39 volumio go-librespot[21421]: time="2026-02-11T19:54:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 19:54:39 volumio go-librespot[21421]: time="2026-02-11T19:54:39+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 19:54:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 19:54:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 19:54:39 volumio volumio[21094]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 11 19:54:40 volumio volumio[21094]: info: Initializing connection to go-librespot Websocket Feb 11 19:54:40 volumio volumio[21094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 19:54:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Feb 11 19:54:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:54:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:54:42 volumio go-librespot[21431]: go-librespot daemon starting... Feb 11 19:54:42 volumio go-librespot[21432]: time="2026-02-11T19:54:42+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 19:54:42 volumio go-librespot[21432]: time="2026-02-11T19:54:42+07:00" level=debug msg="app state loaded" Feb 11 19:54:42 volumio go-librespot[21432]: time="2026-02-11T19:54:42+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 19:54:43 volumio go-librespot[21432]: time="2026-02-11T19:54:43+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 11 19:54:43 volumio go-librespot[21432]: time="2026-02-11T19:54:43+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 11 19:54:43 volumio go-librespot[21432]: time="2026-02-11T19:54:43+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 11 19:54:43 volumio go-librespot[21432]: time="2026-02-11T19:54:43+07:00" level=info msg="zeroconf server listening on port 37933" Feb 11 19:54:43 volumio volumio[21094]: info: Initializing connection to go-librespot Websocket Feb 11 19:54:43 volumio go-librespot[21432]: time="2026-02-11T19:54:43+07:00" level=debug msg="new websocket client" Feb 11 19:54:43 volumio volumio[21094]: info: Connection to go-librespot Websocket established Feb 11 19:54:43 volumio go-librespot[21432]: time="2026-02-11T19:54:43+07:00" level=debug msg="obtained new client token: AAByH8p9vuPVCicW3NeTdFICJqHP4mykLt+PxjTZPoqRWZFOuunHaaL122yG7RvcHMAPB1Duwxa4KAzy8w9lsvXp6y77Ztczt6Cln/aKIrxs+hnmRcoO3k2GU1htcV6yj0r4RRUeib2tZjQmsFxitjAqrPIBQHuhEi1/HUEu7rk9bibBWz4JWpZKvW5h9Ql59BgcPom3cjHpAoDlJmv2NbMiWJUsmHkP7nFSlrcN3vclRCnNvJ0jOyYHnA==" Feb 11 19:54:43 volumio go-librespot[21432]: time="2026-02-11T19:54:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 19:54:43 volumio go-librespot[21432]: time="2026-02-11T19:54:43+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 19:54:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 19:54:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 19:54:43 volumio volumio[21094]: info: Connection to go-librespot Websocket closed Feb 11 19:54:43 volumio volumio[21094]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 11 19:54:43 volumio volumio[21094]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 11 19:54:43 volumio volumio[21094]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 11 19:54:43 volumio volumio[21094]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 11 19:54:43 volumio volumio[21094]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 11 19:54:43 volumio volumio[21094]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 11 19:54:43 volumio volumio[21094]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 11 19:54:43 volumio volumio[21094]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 11 19:54:43 volumio volumio[21094]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 11 19:54:43 volumio volumio[21094]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 11 19:54:43 volumio volumio[21094]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 11 19:54:43 volumio volumio[21094]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 11 19:54:43 volumio volumio[21094]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 11 19:54:43 volumio volumio[21094]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 11 19:54:43 volumio volumio[21094]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 11 19:54:43 volumio volumio[21094]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 11 19:54:43 volumio volumio[21094]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 11 19:54:43 volumio volumio[21094]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 11 19:54:43 volumio volumio[21094]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 11 19:54:43 volumio volumio[21094]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 11 19:54:43 volumio volumio[21094]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 11 19:54:43 volumio volumio[21094]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 11 19:54:43 volumio volumio[21094]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 11 19:54:43 volumio volumio[21094]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 11 19:54:43 volumio volumio[21094]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 11 19:54:43 volumio volumio[21094]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 11 19:54:43 volumio volumio[21094]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 11 19:54:43 volumio volumio[21094]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 11 19:54:43 volumio volumio[21094]: info: Adding plugin bluetooth to MyMusic Plugins Feb 11 19:54:43 volumio volumio[21094]: info: Adding plugin multiroom to MyMusic Plugins Feb 11 19:54:43 volumio volumio[21094]: info: Adding plugin metavolumio to MyMusic Plugins Feb 11 19:54:43 volumio volumio[21094]: info: Adding plugin cd_controller to MyMusic Plugins Feb 11 19:54:43 volumio volumio[21094]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 11 19:54:43 volumio volumio[21094]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 11 19:54:43 volumio volumio[21094]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 11 19:54:43 volumio volumio[21094]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 11 19:54:45 volumio volumio[21094]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 11 19:54:45 volumio volumio[21094]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 11 19:54:45 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 19:54:45 volumio volumio[21094]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 19:54:45 volumio volumio[21094]: info: Starting MyVolumio Remote Streaming Endpoints Feb 11 19:54:45 volumio volumio[21094]: info: MyVolumio login type: Token Feb 11 19:54:45 volumio volumio[21094]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 11 19:54:45 volumio volumio[21094]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 11 19:54:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Feb 11 19:54:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:54:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 19:54:46 volumio go-librespot[21453]: go-librespot daemon starting... Feb 11 19:54:46 volumio go-librespot[21454]: time="2026-02-11T19:54:46+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 19:54:46 volumio go-librespot[21454]: time="2026-02-11T19:54:46+07:00" level=debug msg="app state loaded" Feb 11 19:54:46 volumio go-librespot[21454]: time="2026-02-11T19:54:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 19:54:47 volumio go-librespot[21454]: time="2026-02-11T19:54:47+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 11 19:54:47 volumio go-librespot[21454]: time="2026-02-11T19:54:47+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 11 19:54:47 volumio go-librespot[21454]: time="2026-02-11T19:54:47+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 11 19:54:47 volumio go-librespot[21454]: time="2026-02-11T19:54:47+07:00" level=info msg="zeroconf server listening on port 33309" Feb 11 19:54:47 volumio volumio[21094]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 11 19:54:47 volumio volumio[21094]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 11 19:54:47 volumio volumio[21094]: info: Streaming services startup Feb 11 19:54:47 volumio volumio[21094]: info: Starting Streaming Daemon Feb 11 19:54:47 volumio sudo[21462]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 11 19:54:47 volumio sudo[21462]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 19:54:47 volumio volumio[21094]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 11 19:54:47 volumio go-librespot[21454]: time="2026-02-11T19:54:47+07:00" level=debug msg="obtained new client token: AAA3e0ziJ3/3NmCAMepuXOeppFV+op/f/D/PgxN/Vcn/mLjp+Cg4+fRELVyIE7bmRIKENdQR6TbmUqAoui77L/pxzpr+HQJBk2h19HxiV7qi6Xws7vAOOtrgxzvksfiBZI0HEo7YN/ubuq/g2lO4SZTK0Hv+Jism2vD61DTgh/SBnRFAEJAMsmV19lw6ZKtDx2cABDJtzS+FH18agRIGAzScjGJRFUyKQzjy01xpjUB3LMpBOqMCd0D5PQ==" Feb 11 19:54:47 volumio sudo[21462]: pam_unix(sudo:session): session closed for user root Feb 11 19:54:47 volumio volumio[21094]: info: Getting Spotify volume Feb 11 19:54:47 volumio go-librespot[21454]: time="2026-02-11T19:54:47+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 19:54:47 volumio volumio[21094]: info: Initializing connection to go-librespot Websocket Feb 11 19:54:47 volumio volumio[21094]: error: Cannot start Volumio Streaming Daemon Feb 11 19:54:47 volumio volumio[21094]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 11 19:54:47 volumio volumio[21094]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 11 19:54:47 volumio go-librespot[21454]: time="2026-02-11T19:54:47+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 19:54:47 volumio volumio[21094]: 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 11 19:54:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 19:54:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 19:54:48 volumio volumio[21094]: info: Error connecting to go-librespot Websocket: Error: socket hang up Feb 11 19:54:48 volumio volumio[21094]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 19:54:48 volumio volumio[21094]: Error: socket hang up Feb 11 19:54:48 volumio volumio[21094]: at connResetException (node:internal/errors:720:14) Feb 11 19:54:48 volumio volumio[21094]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 11 19:54:48 volumio volumio[21094]: at Socket.emit (node:events:526:35) Feb 11 19:54:48 volumio volumio[21094]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 11 19:54:48 volumio volumio[21094]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 11 19:54:48 volumio volumio[21094]: code: 'ECONNRESET', Feb 11 19:54:48 volumio volumio[21094]: response: undefined Feb 11 19:54:48 volumio volumio[21094]: } Feb 11 19:54:48 volumio volumio[21094]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 19:54:49 volumio sudo[21483]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-11 19:53' Feb 11 19:54:49 volumio sudo[21483]: 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"