Feb 17 08:15:00 volumio go-librespot[9568]: time="2026-02-17T08:15:00+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 08:15:00 volumio go-librespot[9568]: time="2026-02-17T08:15:00+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 17 08:15:00 volumio go-librespot[9568]: time="2026-02-17T08:15:00+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 17 08:15:00 volumio go-librespot[9568]: time="2026-02-17T08:15:00+07:00" level=info msg="zeroconf server listening on port 34073" Feb 17 08:15:00 volumio go-librespot[9568]: time="2026-02-17T08:15:00+07:00" level=debug msg="obtained new client token: AAA0F37pOwmdHFo2LSAOFEkvOCnOz6F7nNe0xXxo5N8/+r4OKIpbq6v1jxjHOucad653BbJCiHtW/Tk33EVsSnuCYbkE7x4bS4UMPXBx9g+W1C4Bkwg39zQq6v+yP9GVmA83Kk+sNmb36CIJ//Oo0BJGaGruV0oe8+z3fD44kcT8vS7xiYURE+suT+CO/opAwjEBX9VwSyTN5ngtfwYFsDs4+phK9fKtBvNtr6SkVAcay/iAH9pZgkXjCA==" Feb 17 08:15:00 volumio volumio[9229]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 17 08:15:00 volumio go-librespot[9568]: time="2026-02-17T08:15:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 08:15:00 volumio go-librespot[9568]: time="2026-02-17T08:15:00+07:00" level=debug msg="completed keyexchange" Feb 17 08:15:00 volumio go-librespot[9568]: time="2026-02-17T08:15:00+07:00" level=debug msg="completed challenge" Feb 17 08:15:00 volumio go-librespot[9568]: time="2026-02-17T08:15:00+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 08:15:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 08:15:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 08:15:00 volumio volumio[9229]: info: Initializing connection to go-librespot Websocket Feb 17 08:15:00 volumio volumio[9229]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 08:15:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 17 08:15:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:15:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:15:03 volumio go-librespot[9577]: go-librespot daemon starting... Feb 17 08:15:03 volumio go-librespot[9578]: time="2026-02-17T08:15:03+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 08:15:03 volumio go-librespot[9578]: time="2026-02-17T08:15:03+07:00" level=debug msg="app state loaded" Feb 17 08:15:03 volumio go-librespot[9578]: time="2026-02-17T08:15:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 08:15:03 volumio volumio[9229]: info: Initializing connection to go-librespot Websocket Feb 17 08:15:03 volumio go-librespot[9578]: time="2026-02-17T08:15:03+07:00" level=debug msg="new websocket client" Feb 17 08:15:03 volumio volumio[9229]: info: Connection to go-librespot Websocket established Feb 17 08:15:04 volumio go-librespot[9578]: time="2026-02-17T08:15:04+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 08:15:04 volumio go-librespot[9578]: time="2026-02-17T08:15:04+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 08:15:04 volumio go-librespot[9578]: time="2026-02-17T08:15:04+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 08:15:04 volumio go-librespot[9578]: time="2026-02-17T08:15:04+07:00" level=info msg="zeroconf server listening on port 39025" Feb 17 08:15:04 volumio go-librespot[9578]: time="2026-02-17T08:15:04+07:00" level=debug msg="obtained new client token: AAAbl/TALULMULpjyx20e8wa1JZB+1wmFJk5dED0lzys1SG/3TBIDXhOBVSWNW+H6LC9XANHxn2YY96NQCMpF+KjmQMRu+59+Zblt9Mp5gjr++MVJIAd8N2GzgviQnfRtRrg2vZs0TH7/HtOWq6dCFiQzu0TYyy9+qjHZBzWEahZvsCWQHeN4jasdK3ppWTysI+FzeKP62V2STVbsQxd+NlMcyHEp78V1iwU2iVhSoI4OMqxYByVbJWQ2w==" Feb 17 08:15:04 volumio go-librespot[9578]: time="2026-02-17T08:15:04+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 17 08:15:04 volumio volumio[9229]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 17 08:15:04 volumio volumio[9229]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 17 08:15:04 volumio volumio[9229]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 17 08:15:04 volumio volumio[9229]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 17 08:15:04 volumio volumio[9229]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 17 08:15:04 volumio volumio[9229]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 17 08:15:04 volumio volumio[9229]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 17 08:15:04 volumio volumio[9229]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 17 08:15:04 volumio volumio[9229]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 17 08:15:04 volumio volumio[9229]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 17 08:15:04 volumio volumio[9229]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 17 08:15:04 volumio volumio[9229]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 17 08:15:04 volumio volumio[9229]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 17 08:15:04 volumio volumio[9229]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 17 08:15:04 volumio volumio[9229]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 17 08:15:04 volumio volumio[9229]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 17 08:15:04 volumio volumio[9229]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 17 08:15:04 volumio volumio[9229]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 17 08:15:04 volumio volumio[9229]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 17 08:15:04 volumio volumio[9229]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 17 08:15:04 volumio volumio[9229]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 17 08:15:04 volumio volumio[9229]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 17 08:15:04 volumio volumio[9229]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 17 08:15:04 volumio volumio[9229]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 17 08:15:04 volumio volumio[9229]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 17 08:15:04 volumio volumio[9229]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 17 08:15:04 volumio volumio[9229]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 17 08:15:04 volumio volumio[9229]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 17 08:15:04 volumio volumio[9229]: info: Adding plugin bluetooth to MyMusic Plugins Feb 17 08:15:04 volumio volumio[9229]: info: Adding plugin multiroom to MyMusic Plugins Feb 17 08:15:04 volumio volumio[9229]: info: Adding plugin metavolumio to MyMusic Plugins Feb 17 08:15:04 volumio volumio[9229]: info: Adding plugin cd_controller to MyMusic Plugins Feb 17 08:15:04 volumio volumio[9229]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 17 08:15:04 volumio volumio[9229]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 17 08:15:04 volumio volumio[9229]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 17 08:15:04 volumio volumio[9229]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 17 08:15:04 volumio go-librespot[9578]: time="2026-02-17T08:15:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 17 08:15:04 volumio go-librespot[9578]: time="2026-02-17T08:15:04+07:00" level=debug msg="completed keyexchange" Feb 17 08:15:04 volumio go-librespot[9578]: time="2026-02-17T08:15:04+07:00" level=debug msg="completed challenge" Feb 17 08:15:05 volumio go-librespot[9578]: time="2026-02-17T08:15:05+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 17 08:15:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 08:15:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 08:15:06 volumio volumio[9229]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 17 08:15:06 volumio volumio[9229]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 17 08:15:06 volumio volumio[9229]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 08:15:06 volumio volumio[9229]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 08:15:06 volumio volumio[9229]: info: Starting MyVolumio Remote Streaming Endpoints Feb 17 08:15:06 volumio volumio[9229]: info: MyVolumio login type: Token Feb 17 08:15:06 volumio volumio[9229]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 17 08:15:06 volumio volumio[9229]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 17 08:15:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 17 08:15:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:15:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:15:08 volumio go-librespot[9599]: go-librespot daemon starting... Feb 17 08:15:08 volumio go-librespot[9600]: time="2026-02-17T08:15:08+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 08:15:08 volumio go-librespot[9600]: time="2026-02-17T08:15:08+07:00" level=debug msg="app state loaded" Feb 17 08:15:08 volumio go-librespot[9600]: time="2026-02-17T08:15:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 08:15:08 volumio volumio[9229]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 17 08:15:08 volumio volumio[9229]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 17 08:15:08 volumio volumio[9229]: info: Streaming services startup Feb 17 08:15:08 volumio volumio[9229]: info: Starting Streaming Daemon Feb 17 08:15:08 volumio sudo[9608]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 17 08:15:08 volumio sudo[9608]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:15:08 volumio volumio[9229]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 17 08:15:08 volumio sudo[9608]: pam_unix(sudo:session): session closed for user root Feb 17 08:15:08 volumio volumio[9229]: info: Getting Spotify volume Feb 17 08:15:08 volumio volumio[9229]: info: Connection to go-librespot Websocket closed Feb 17 08:15:08 volumio volumio[9229]: error: Cannot start Volumio Streaming Daemon Feb 17 08:15:08 volumio volumio[9229]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 17 08:15:08 volumio volumio[9229]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 17 08:15:08 volumio volumio[9229]: 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 17 08:15:08 volumio go-librespot[9600]: time="2026-02-17T08:15:08+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 08:15:08 volumio go-librespot[9600]: time="2026-02-17T08:15:08+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 17 08:15:08 volumio go-librespot[9600]: time="2026-02-17T08:15:08+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 17 08:15:08 volumio go-librespot[9600]: time="2026-02-17T08:15:08+07:00" level=info msg="zeroconf server listening on port 39329" Feb 17 08:15:08 volumio volumio[9229]: info: CoreCommandRouter::volumioGetState Feb 17 08:15:08 volumio volumio[9229]: info: CorePlayQueue::getTrack 0 Feb 17 08:15:08 volumio volumio[9229]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 17 08:15:08 volumio volumio[9229]: SPOTIFY: SPOTIFY VOLUME undefined Feb 17 08:15:08 volumio volumio[9229]: SPOTIFY: VOLUMIO VOLUME 100 Feb 17 08:15:08 volumio volumio[9229]: info: Aligning Spotify Volume to Volumio Volume Feb 17 08:15:08 volumio volumio[9229]: info: CoreCommandRouter::volumioGetState Feb 17 08:15:08 volumio volumio[9229]: info: CorePlayQueue::getTrack 0 Feb 17 08:15:08 volumio volumio[9229]: info: Setting Spotify Volume from Volumio: 100 Feb 17 08:15:08 volumio go-librespot[9600]: time="2026-02-17T08:15:08+07:00" level=debug msg="obtained new client token: AAAyDchqSF4MBsrDs4Axp5sgDadKzrPal83A5nsh4bb9/9saEYKTIcmEgQNusqhSs8gIpAb2RqeeSQ6FltJkZqWBVZiPjwc7QjbDahPVjwJKj8WPhQJaEpQ+YEqXhqqQHRYAaJ7JjfOgQ4tkdrVA4HI5Wq2c9e8EpB/vdye9q6cAzkDvVV4NJ84lR7Q8aoKwXIzRtjRPLuy750jRr7BnHT+6QFgQyNqgFvGHDoRJ5dce/cpFzLt/nKcPMw==" Feb 17 08:15:09 volumio go-librespot[9600]: time="2026-02-17T08:15:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 08:15:09 volumio go-librespot[9600]: time="2026-02-17T08:15:09+07:00" level=debug msg="completed keyexchange" Feb 17 08:15:09 volumio go-librespot[9600]: time="2026-02-17T08:15:09+07:00" level=debug msg="completed challenge" Feb 17 08:15:09 volumio go-librespot[9600]: time="2026-02-17T08:15:09+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 08:15:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 08:15:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 08:15:09 volumio volumio[9229]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 08:15:09 volumio volumio[9229]: Error: socket hang up Feb 17 08:15:09 volumio volumio[9229]: at connResetException (node:internal/errors:720:14) Feb 17 08:15:09 volumio volumio[9229]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 17 08:15:09 volumio volumio[9229]: at Socket.emit (node:events:526:35) Feb 17 08:15:09 volumio volumio[9229]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 17 08:15:09 volumio volumio[9229]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 17 08:15:09 volumio volumio[9229]: code: 'ECONNRESET', Feb 17 08:15:09 volumio volumio[9229]: response: undefined Feb 17 08:15:09 volumio volumio[9229]: } Feb 17 08:15:09 volumio volumio[9229]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 08:15:10 volumio sudo[9630]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 08:14' Feb 17 08:15:10 volumio sudo[9630]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:15:11 volumio sudo[9630]: pam_unix(sudo:session): session closed for user root Feb 17 08:15:11 volumio volumio-remote-updater[25144]: [2026-02-17 08:15:11] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 17 08:15:11 volumio volumio-remote-updater[25144]: [2026-02-17 08:15:11] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 17 08:15:11 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 17 08:15:11 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 17 08:15:11 volumio systemd[1]: volumio.service: Consumed 55.689s CPU time. Feb 17 08:15:11 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 08:15:11 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 08:15:11 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 20112. Feb 17 08:15:11 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 08:15:11 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 17 08:15:11 volumio systemd[1]: volumio.service: Consumed 55.689s CPU time. Feb 17 08:15:11 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 17 08:15:11 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 08:15:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 17 08:15:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:15:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:15:12 volumio go-librespot[9658]: go-librespot daemon starting... Feb 17 08:15:12 volumio go-librespot[9659]: time="2026-02-17T08:15:12+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 08:15:12 volumio go-librespot[9659]: time="2026-02-17T08:15:12+07:00" level=debug msg="app state loaded" Feb 17 08:15:12 volumio go-librespot[9659]: time="2026-02-17T08:15:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 08:15:12 volumio go-librespot[9659]: time="2026-02-17T08:15:12+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 08:15:12 volumio go-librespot[9659]: time="2026-02-17T08:15:12+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 17 08:15:12 volumio go-librespot[9659]: time="2026-02-17T08:15:12+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 17 08:15:13 volumio go-librespot[9659]: time="2026-02-17T08:15:13+07:00" level=info msg="zeroconf server listening on port 46161" Feb 17 08:15:13 volumio go-librespot[9659]: time="2026-02-17T08:15:13+07:00" level=debug msg="obtained new client token: AACCGy2JoZuPX2fep6lzHyo3dVJHa6utTCExG8vzha8Ulh2Knxqo6YgcipzxN+8WUxZCT8W0uvL0aOnvbehkpbcV4CA3B/WQHRlJ/AGhefgxUWYUk7ji5sJBtJcAcInhx/i4Wt/xQ7ZlMDXN12Z8akJ9tB2qM6kgE/HhxDI3Fs4b0UBL5/QwU0iR05tGe0NBPrL+PP7kk2Tm4B6TFxPVBbV5gPlCzQrhcxurxhaygzs2CGDZb8vUmvc=" Feb 17 08:15:13 volumio go-librespot[9659]: time="2026-02-17T08:15:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 08:15:13 volumio go-librespot[9659]: time="2026-02-17T08:15:13+07:00" level=debug msg="completed keyexchange" Feb 17 08:15:13 volumio go-librespot[9659]: time="2026-02-17T08:15:13+07:00" level=debug msg="completed challenge" Feb 17 08:15:13 volumio go-librespot[9659]: time="2026-02-17T08:15:13+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 08:15:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 08:15:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 08:15:15 volumio volumio[9643]: info: ------------------------------------------- Feb 17 08:15:15 volumio volumio[9643]: info: ----- Volumio3 ---- Feb 17 08:15:15 volumio volumio[9643]: info: ------------------------------------------- Feb 17 08:15:15 volumio volumio[9643]: info: ----- System startup ---- Feb 17 08:15:15 volumio volumio[9643]: info: ------------------------------------------- Feb 17 08:15:16 volumio volumio-remote-updater[25144]: [2026-02-17 08:15:16] [connect] Successful connection Feb 17 08:15:16 volumio volumio[9643]: info: MYVOLUMIO Environment detected Feb 17 08:15:16 volumio volumio[9643]: info: Plugin folders cleanup Feb 17 08:15:16 volumio volumio[9643]: info: Scanning into folder /volumio/app/plugins/ Feb 17 08:15:16 volumio volumio[9643]: info: Scanning category audio_interface Feb 17 08:15:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 17 08:15:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:15:16 volumio volumio[9643]: info: Scanning category miscellanea Feb 17 08:15:16 volumio volumio[9643]: info: Scanning category music_service Feb 17 08:15:16 volumio volumio[9643]: info: Scanning category plugins.json Feb 17 08:15:16 volumio volumio[9643]: info: Scanning category system_controller Feb 17 08:15:16 volumio volumio[9643]: info: Scanning category user_interface Feb 17 08:15:16 volumio volumio[9643]: info: Scanning into folder /data/plugins/ Feb 17 08:15:16 volumio volumio[9643]: info: Scanning category music_service Feb 17 08:15:16 volumio volumio[9643]: info: Plugin folders cleanup completed Feb 17 08:15:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:15:16 volumio volumio[9643]: info: ------------------------------------------- Feb 17 08:15:16 volumio volumio[9643]: info: ----- Core plugins startup ---- Feb 17 08:15:16 volumio volumio[9643]: info: ------------------------------------------- Feb 17 08:15:16 volumio volumio[9643]: info: Loading plugins from folder /volumio/app/plugins/ Feb 17 08:15:16 volumio go-librespot[9675]: go-librespot daemon starting... Feb 17 08:15:16 volumio volumio[9643]: info: Adding plugin upnp to MyMusic Plugins Feb 17 08:15:16 volumio volumio[9643]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 17 08:15:16 volumio volumio[9643]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 17 08:15:16 volumio volumio[9643]: info: Loading plugins from folder /data/plugins/ Feb 17 08:15:16 volumio volumio[9643]: info: Loading plugin "system"... Feb 17 08:15:16 volumio go-librespot[9676]: time="2026-02-17T08:15:16+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 08:15:16 volumio go-librespot[9676]: time="2026-02-17T08:15:16+07:00" level=debug msg="app state loaded" Feb 17 08:15:16 volumio go-librespot[9676]: time="2026-02-17T08:15:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 08:15:16 volumio volumio[9643]: info: Loading plugin "appearance"... Feb 17 08:15:17 volumio go-librespot[9676]: time="2026-02-17T08:15:17+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 08:15:17 volumio go-librespot[9676]: time="2026-02-17T08:15:17+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 17 08:15:17 volumio go-librespot[9676]: time="2026-02-17T08:15:17+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 17 08:15:17 volumio go-librespot[9676]: time="2026-02-17T08:15:17+07:00" level=info msg="zeroconf server listening on port 42573" Feb 17 08:15:17 volumio go-librespot[9676]: time="2026-02-17T08:15:17+07:00" level=debug msg="obtained new client token: AADNyQ5KNgB7nObCeM09t8+JqmC4A5pj2GEHiEz8wEnpx5h658QTJ01It8qgc+BkenosR+GTDXIuVJ1z8O61hjCmqLmivZ40vWTb0ZWSyxZKLR0F4kxL5Q2aS9dei2g3vC04ns3HJHf3dE1YzNGHgJivGue7KYZu2S7J29ZM8yU+1IE2ekvPKJvQ6VczFJ8+eH4KUO0+xTOCea5dUhlum4Fr5C5houLvE7urY3zFB/l5eN+Q0rrxlPKKrA==" Feb 17 08:15:17 volumio go-librespot[9676]: time="2026-02-17T08:15:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 08:15:17 volumio go-librespot[9676]: time="2026-02-17T08:15:17+07:00" level=debug msg="completed keyexchange" Feb 17 08:15:17 volumio go-librespot[9676]: time="2026-02-17T08:15:17+07:00" level=debug msg="completed challenge" Feb 17 08:15:17 volumio go-librespot[9676]: time="2026-02-17T08:15:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 08:15:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 08:15:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 08:15:18 volumio volumio[9643]: info: Loading plugin "network"... Feb 17 08:15:18 volumio volumio[9643]: info: Refreshing Cached IP Addresses Feb 17 08:15:18 volumio sudo[9688]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 08:15:18 volumio sudo[9688]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:15:18 volumio sudo[9690]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 08:15:18 volumio sudo[9688]: pam_unix(sudo:session): session closed for user root Feb 17 08:15:18 volumio sudo[9690]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:15:18 volumio volumio[9643]: info: Loading plugin "services"... Feb 17 08:15:18 volumio volumio[9643]: info: Loading plugin "alsa_controller"... Feb 17 08:15:18 volumio sudo[9690]: pam_unix(sudo:session): session closed for user root Feb 17 08:15:18 volumio sudo[9698]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 17 08:15:18 volumio sudo[9698]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:15:18 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 08:15:18 volumio volumio[9643]: info: Loading plugin "wizard"... Feb 17 08:15:18 volumio volumio[9643]: info: Loading plugin "networkfs"... Feb 17 08:15:18 volumio volumio[9643]: info: Starting Udev Watcher for removable devices Feb 17 08:15:19 volumio volumio[9643]: info: Ignoring mount for partition: boot Feb 17 08:15:19 volumio volumio[9643]: info: Ignoring mount for partition: volumio Feb 17 08:15:19 volumio volumio[9643]: info: Ignoring mount for partition: volumio_data Feb 17 08:15:19 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 08:15:19 volumio volumio[9643]: info: Loading plugin "volumio_command_line_client"... Feb 17 08:15:19 volumio volumio[9643]: info: Loading plugin "upnp"... Feb 17 08:15:19 volumio volumio[9643]: info: [1771290919056] Starting Upmpd Daemon Feb 17 08:15:19 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 08:15:19 volumio volumio[9643]: info: Loading plugin "my_music"... Feb 17 08:15:19 volumio volumio[9643]: info: Loading plugin "mpd"... Feb 17 08:15:19 volumio volumio[9643]: info: Loading plugin "upnp_browser"... Feb 17 08:15:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 17 08:15:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:15:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:15:20 volumio go-librespot[9721]: go-librespot daemon starting... Feb 17 08:15:20 volumio go-librespot[9722]: time="2026-02-17T08:15:20+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 08:15:20 volumio go-librespot[9722]: time="2026-02-17T08:15:20+07:00" level=debug msg="app state loaded" Feb 17 08:15:20 volumio go-librespot[9722]: time="2026-02-17T08:15:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 08:15:21 volumio go-librespot[9722]: time="2026-02-17T08:15:21+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 08:15:21 volumio go-librespot[9722]: time="2026-02-17T08:15:21+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 17 08:15:21 volumio go-librespot[9722]: time="2026-02-17T08:15:21+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 17 08:15:21 volumio go-librespot[9722]: time="2026-02-17T08:15:21+07:00" level=info msg="zeroconf server listening on port 39789" Feb 17 08:15:21 volumio sudo[9698]: pam_unix(sudo:session): session closed for user root Feb 17 08:15:21 volumio go-librespot[9722]: time="2026-02-17T08:15:21+07:00" level=debug msg="obtained new client token: AABjXWGEr9d+HwIzlC5NWJXe3oJGTTF4CJRYsF/M1wjO8fUVKA4ebW7Kz9nkIqVBWs90vl7ZrCgfsU6D4o/R8vP4EqC/OON+UxvxcWtIpz77YNcViyILk0n2j+KMPuaRts6f0s05M8Cj/D3KKNtLdQ4lIAiB5+WXO+BJ8SKmaoSER2x5qKtKp7adajW20AKGSBYDXEjxDYpGjSMT1OOwTD+HTE68pO4c/jwmMyr2yoVOA7AY54gg69Z8PQ==" Feb 17 08:15:21 volumio go-librespot[9722]: time="2026-02-17T08:15:21+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 17 08:15:21 volumio go-librespot[9722]: time="2026-02-17T08:15:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 17 08:15:21 volumio go-librespot[9722]: time="2026-02-17T08:15:21+07:00" level=debug msg="completed keyexchange" Feb 17 08:15:21 volumio go-librespot[9722]: time="2026-02-17T08:15:21+07:00" level=debug msg="completed challenge" Feb 17 08:15:22 volumio go-librespot[9722]: time="2026-02-17T08:15:22+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 17 08:15:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 08:15:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 08:15:22 volumio volumio[9643]: info: Starting UPNP Browser Feb 17 08:15:22 volumio volumio[9643]: info: Loading plugin "alarm-clock"... Feb 17 08:15:22 volumio volumio[9643]: info: Loading plugin "airplay_emulation"... Feb 17 08:15:22 volumio volumio[9643]: info: Starting Shairport Sync Feb 17 08:15:22 volumio volumio[9643]: info: Loading plugin "last_100"... Feb 17 08:15:22 volumio volumio[9643]: info: Loading plugin "webradio"... Feb 17 08:15:23 volumio volumio[9643]: info: Loading plugin "i2s_dacs"... Feb 17 08:15:23 volumio volumio[9643]: info: Loading plugin "volumiodiscovery"... Feb 17 08:15:23 volumio volumio[9643]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 08:15:23 volumio volumio[9643]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 08:15:23 volumio node[9643]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 08:15:23 volumio volumio[9643]: *** WARNING *** For more information see Feb 17 08:15:23 volumio volumio[9643]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 08:15:23 volumio volumio[9643]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 08:15:23 volumio volumio[9643]: *** WARNING *** For more information see Feb 17 08:15:23 volumio node[9643]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 08:15:23 volumio node[9643]: *** WARNING *** For more information see Feb 17 08:15:23 volumio node[9643]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 08:15:23 volumio node[9643]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 08:15:23 volumio node[9643]: *** WARNING *** For more information see Feb 17 08:15:23 volumio volumio[9643]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 17 08:15:23 volumio volumio[9643]: info: Discovery: Started advertising with name: Volumio Feb 17 08:15:23 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 08:15:23 volumio volumio[9643]: info: Loading plugin "spop"... Feb 17 08:15:25 volumio volumio[9643]: info: Loading plugin "ytcr"... Feb 17 08:15:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 17 08:15:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:15:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:15:25 volumio go-librespot[9732]: go-librespot daemon starting... Feb 17 08:15:25 volumio go-librespot[9733]: time="2026-02-17T08:15:25+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 08:15:25 volumio go-librespot[9733]: time="2026-02-17T08:15:25+07:00" level=debug msg="app state loaded" Feb 17 08:15:25 volumio go-librespot[9733]: time="2026-02-17T08:15:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 08:15:25 volumio go-librespot[9733]: time="2026-02-17T08:15:25+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 17 08:15:25 volumio go-librespot[9733]: time="2026-02-17T08:15:25+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 17 08:15:25 volumio go-librespot[9733]: time="2026-02-17T08:15:25+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 17 08:15:25 volumio go-librespot[9733]: time="2026-02-17T08:15:25+07:00" level=info msg="zeroconf server listening on port 45603" Feb 17 08:15:26 volumio go-librespot[9733]: time="2026-02-17T08:15:26+07:00" level=debug msg="obtained new client token: AACe4EnWbESz4OfG7w/c6OcGrlqTS54JqCFbjlYkCybSFNI2dk5Ewbgcn8RI6qHFePybdMTcPSTL4vVttW0XcKLsB46kmIkP7cacS97L/gDAhGlN/R2UCcdUMssZE2gcVNgwj++Pg0O5+vo9aKGF/5mHJj6hu+5aQH3rzTfD3v29JC1PVrlXu5odgkUcK69ybSqKvkp4ePYPOGcP6wOQVmyHkaYS8BAiRdwX9zvacihrLaSRe1F8i2g=" Feb 17 08:15:26 volumio go-librespot[9733]: time="2026-02-17T08:15:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 08:15:26 volumio go-librespot[9733]: time="2026-02-17T08:15:26+07:00" level=debug msg="completed keyexchange" Feb 17 08:15:26 volumio go-librespot[9733]: time="2026-02-17T08:15:26+07:00" level=debug msg="completed challenge" Feb 17 08:15:26 volumio go-librespot[9733]: time="2026-02-17T08:15:26+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 08:15:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 08:15:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 08:15:27 volumio volumio[9643]: info: Loading plugin "ytmusic"... Feb 17 08:15:28 volumio volumio-remote-updater[25144]: [2026-02-17 08:15:28] [connect] Successful connection Feb 17 08:15:28 volumio volumio[9643]: info: Loading plugin "outputs"... Feb 17 08:15:28 volumio volumio[9643]: info: Loading plugin "albumart"... Feb 17 08:15:28 volumio volumio[9643]: info: Plugin example_plugin is not enabled Feb 17 08:15:28 volumio volumio[9643]: info: Loading plugin "inputs"... Feb 17 08:15:28 volumio volumio[9643]: info: Loading plugin "updater_comm"... Feb 17 08:15:29 volumio volumio[9643]: info: Plugin mpdemulation is not enabled Feb 17 08:15:29 volumio volumio[9643]: info: Loading plugin "rest_api"... Feb 17 08:15:29 volumio volumio[9643]: info: Loading plugin "websocket"... Feb 17 08:15:29 volumio volumio[9643]: info: Starting Socket.io Server version 1.7.4 Feb 17 08:15:29 volumio volumio[9643]: info: Loading plugin "RoonBridge"... Feb 17 08:15:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 17 08:15:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:15:29 volumio volumio[9643]: info: Applying required configuration parameters for plugin RoonBridge Feb 17 08:15:29 volumio volumio[9643]: info: Loading i18n strings for locale en Feb 17 08:15:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:15:29 volumio go-librespot[9764]: go-librespot daemon starting... Feb 17 08:15:29 volumio volumio[9643]: Updating browse sources language Feb 17 08:15:29 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 08:15:29 volumio go-librespot[9765]: time="2026-02-17T08:15:29+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 08:15:29 volumio go-librespot[9765]: time="2026-02-17T08:15:29+07:00" level=debug msg="app state loaded" Feb 17 08:15:29 volumio go-librespot[9765]: time="2026-02-17T08:15:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 08:15:29 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 08:15:29 volumio volumio[9643]: info: CoreCommandRouter::initPlayerControls Feb 17 08:15:29 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:15:29 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:15:29 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:15:29 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:15:29 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:15:29 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:15:29 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:15:29 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:15:29 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 08:15:29 volumio volumio[9643]: Express server listening on port 3000 Feb 17 08:15:29 volumio volumio[9643]: [Metrics] WebUI: 15s 832.63ms Feb 17 08:15:29 volumio volumio[9740]: Forking 3 albumart workers Feb 17 08:15:30 volumio volumio[9643]: info: CoreStateMachine::resetVolumioState Feb 17 08:15:30 volumio volumio[9643]: info: CoreStateMachine::getcurrentVolume Feb 17 08:15:30 volumio volumio[9643]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 08:15:30 volumio sudo[9781]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 08:15:30 volumio sudo[9781]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:15:30 volumio sudo[9781]: pam_unix(sudo:session): session closed for user root Feb 17 08:15:30 volumio sudo[9806]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 08:15:30 volumio sudo[9806]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:15:30 volumio sudo[9806]: pam_unix(sudo:session): session closed for user root Feb 17 08:15:30 volumio volumio[9643]: info: Volumio Network Manager: Network status updated: 1 Feb 17 08:15:30 volumio go-librespot[9765]: time="2026-02-17T08:15:30+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 08:15:30 volumio go-librespot[9765]: time="2026-02-17T08:15:30+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 17 08:15:30 volumio go-librespot[9765]: time="2026-02-17T08:15:30+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 17 08:15:30 volumio go-librespot[9765]: time="2026-02-17T08:15:30+07:00" level=info msg="zeroconf server listening on port 34143" Feb 17 08:15:30 volumio go-librespot[9765]: time="2026-02-17T08:15:30+07:00" level=debug msg="obtained new client token: AACvKYY0Y2wt4hsYKPaVDNkBoqszopma5OgCD/Wdp+17xrMG3niw9aIkaIm3EP5IP2kQh/q8xitbqkS++Vv7RBLGEnPJ3boUVO7FyWJs0jX6gBBU6Z/tZzvr9rGpQ5scMdjsOw4fT6WxtWzkqfHenUp+bXURTVexQF4YYU7HS3hpDX6ORVU1Pj9E1TJGNN2eHxlMF5p9TV4maQqc+2esBwpUJt6G9W5KSf4BFYWkNMnvDheWiSsESgdaFA==" Feb 17 08:15:30 volumio volumio[9643]: info: VolumeController:: Volume=100 Mute =false Feb 17 08:15:30 volumio volumio[9643]: info: CoreStateMachine::pushState Feb 17 08:15:30 volumio volumio[9643]: info: CorePlayQueue::getTrack 0 Feb 17 08:15:30 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 08:15:30 volumio volumio[9643]: info: CoreCommandRouter::volumioPushState Feb 17 08:15:30 volumio volumio[9643]: info: CoreStateMachine::updateTrackBlock Feb 17 08:15:30 volumio volumio[9643]: info: CorePlayQueue::getTrackBlock Feb 17 08:15:30 volumio volumio[9643]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 08:15:30 volumio volumio-remote-updater[25144]: [2026-02-17 08:15:30] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771290928 101 Feb 17 08:15:30 volumio go-librespot[9765]: time="2026-02-17T08:15:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 08:15:30 volumio volumio[9643]: 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 17 08:15:30 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 08:15:30 volumio volumio[9643]: info: Reloading queue from file Feb 17 08:15:30 volumio volumio[9643]: info: CoreStateMachine::setRepeat null single undefined Feb 17 08:15:30 volumio volumio[9643]: info: CoreStateMachine::pushState Feb 17 08:15:30 volumio volumio[9643]: info: CorePlayQueue::getTrack 0 Feb 17 08:15:30 volumio go-librespot[9765]: time="2026-02-17T08:15:30+07:00" level=debug msg="completed keyexchange" Feb 17 08:15:30 volumio go-librespot[9765]: time="2026-02-17T08:15:30+07:00" level=debug msg="completed challenge" Feb 17 08:15:30 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 08:15:30 volumio volumio[9643]: info: CoreCommandRouter::volumioPushState Feb 17 08:15:30 volumio volumio[9643]: info: CoreStateMachine::setRandom null Feb 17 08:15:30 volumio volumio[9643]: info: CoreStateMachine::pushState Feb 17 08:15:30 volumio volumio[9643]: info: CorePlayQueue::getTrack 0 Feb 17 08:15:30 volumio volumio[9643]: info: CoreCommandRouter::volumioPushState Feb 17 08:15:30 volumio volumio[9643]: info: Setting Device type: Raspberry PI Feb 17 08:15:30 volumio go-librespot[9765]: time="2026-02-17T08:15:30+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 17 08:15:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 08:15:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 08:15:30 volumio volumio[9643]: info: Completed loading Core Plugins Feb 17 08:15:30 volumio volumio[9643]: info: Preparing to generate the ALSA configuration file Feb 17 08:15:31 volumio volumio[9643]: info: VolumeController:: Volume=100 Mute =false Feb 17 08:15:31 volumio volumio[9643]: info: CoreStateMachine::pushState Feb 17 08:15:31 volumio volumio[9643]: info: CorePlayQueue::getTrack 0 Feb 17 08:15:31 volumio volumio[9643]: info: CoreCommandRouter::volumioPushState Feb 17 08:15:31 volumio volumio[9643]: info: Asound.conf file unchanged, so no further update is needed Feb 17 08:15:31 volumio volumio[9643]: info: Output device has changed, restarting MPD Feb 17 08:15:31 volumio sudo[9823]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 17 08:15:31 volumio sudo[9823]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:15:31 volumio sudo[9825]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 08:15:31 volumio sudo[9825]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:15:31 volumio volumio[9643]: info: Output device has changed, restarting Shairport Sync Feb 17 08:15:31 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:15:31 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 08:15:31 volumio sudo[9825]: pam_unix(sudo:session): session closed for user root Feb 17 08:15:31 volumio sudo[9827]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 08:15:31 volumio sudo[9827]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:15:31 volumio volumio[9643]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 08:15:31 volumio sudo[9823]: pam_unix(sudo:session): session closed for user root Feb 17 08:15:31 volumio volumio[9643]: info: ___________ START PLUGINS ___________ Feb 17 08:15:31 volumio volumio[9643]: info: ControllerMpd::onStart: Initializing MPD Feb 17 08:15:31 volumio volumio[9643]: info: Creating MPD Configuration file Feb 17 08:15:31 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 17 08:15:31 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 08:15:31 volumio volumio[9643]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 08:15:31 volumio volumio[9643]: info: [1771290931513] CoreMusicLibrary::Adding element Media Servers Feb 17 08:15:31 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 08:15:31 volumio volumio[9643]: info: UPNP Browser: Client initialized successfully Feb 17 08:15:31 volumio sudo[9837]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 08:15:31 volumio sudo[9837]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:15:31 volumio sudo[9837]: pam_unix(sudo:session): session closed for user root Feb 17 08:15:31 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:15:31 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 08:15:31 volumio sudo[9839]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 08:15:31 volumio sudo[9839]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:15:31 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 08:15:31 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 08:15:31 volumio systemd[1]: mpd.service: Consumed 7.179s CPU time. Feb 17 08:15:31 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 08:15:31 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 08:15:31 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 08:15:31 volumio volumio[9643]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 08:15:31 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:15:31 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 08:15:31 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 08:15:31 volumio volumio[9643]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 08:15:31 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 08:15:31 volumio volumio[9643]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 08:15:31 volumio volumio[9643]: info: [1771290931760] CoreMusicLibrary::Adding element Last_100 Feb 17 08:15:31 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 08:15:31 volumio volumio[9643]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 08:15:31 volumio volumio[9643]: info: [1771290931779] CoreMusicLibrary::Adding element Webradio Feb 17 08:15:31 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 08:15:31 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 08:15:31 volumio volumio[9643]: info: Initializing BBC Radios Feb 17 08:15:31 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 08:15:31 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 08:15:31 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 08:15:31 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 08:15:31 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 08:15:31 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 08:15:31 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 08:15:31 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 08:15:31 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 08:15:32 volumio volumio[9643]: info: Creating Spotify config file Feb 17 08:15:32 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:15:32 volumio sudo[9861]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 17 08:15:32 volumio sudo[9861]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 17 08:15:32 volumio sudo[9861]: pam_unix(sudo:session): session closed for user root Feb 17 08:15:33 volumio volumio[9643]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 08:15:33 volumio volumio[9643]: info: [1771290933141] CoreMusicLibrary::Adding element YouTube Music Feb 17 08:15:33 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 08:15:33 volumio volumio[9643]: Cannot find translation for source YouTube Music Feb 17 08:15:33 volumio volumio[9643]: info: Volumio Calling Home Feb 17 08:15:33 volumio sudo[9870]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 17 08:15:33 volumio sudo[9870]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:15:33 volumio sudo[9870]: pam_unix(sudo:session): session closed for user root Feb 17 08:15:33 volumio volumio[9776]: Starting albumart workers Feb 17 08:15:33 volumio volumio[9777]: Starting albumart workers Feb 17 08:15:33 volumio volumio[9779]: Starting albumart workers Feb 17 08:15:33 volumio volumio[9643]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 08:15:33 volumio volumio[9643]: info: Discovery: Found device Volumio Feb 17 08:15:33 volumio volumio[9643]: info: CoreCommandRouter::volumioGetState Feb 17 08:15:33 volumio volumio[9643]: info: CorePlayQueue::getTrack 0 Feb 17 08:15:34 volumio volumio[9643]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 08:15:34 volumio volumio[9643]: info: Discovery: Found device Volumio Feb 17 08:15:34 volumio volumio[9643]: info: CoreCommandRouter::volumioGetState Feb 17 08:15:34 volumio volumio[9643]: info: CorePlayQueue::getTrack 0 Feb 17 08:15:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 17 08:15:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:15:34 volumio volumio[9643]: info: MPD Permissions set Feb 17 08:15:34 volumio volumio[9643]: info: MPD Permissions set Feb 17 08:15:34 volumio volumio[9643]: info: Upmpdcli Daemon Started Feb 17 08:15:34 volumio go-librespot[9875]: go-librespot daemon starting... Feb 17 08:15:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:15:34 volumio go-librespot[9876]: time="2026-02-17T08:15:34+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 08:15:34 volumio go-librespot[9876]: time="2026-02-17T08:15:34+07:00" level=debug msg="app state loaded" Feb 17 08:15:34 volumio go-librespot[9876]: time="2026-02-17T08:15:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 08:15:34 volumio volumio[9643]: info: Spotify config file written Feb 17 08:15:34 volumio sudo[9884]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 17 08:15:34 volumio sudo[9884]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:15:34 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 17 08:15:34 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 17 08:15:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:15:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:15:34 volumio go-librespot[9886]: go-librespot daemon starting... Feb 17 08:15:34 volumio sudo[9884]: pam_unix(sudo:session): session closed for user root Feb 17 08:15:34 volumio go-librespot[9887]: time="2026-02-17T08:15:34+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 08:15:34 volumio go-librespot[9887]: time="2026-02-17T08:15:34+07:00" level=debug msg="app state loaded" Feb 17 08:15:34 volumio go-librespot[9887]: time="2026-02-17T08:15:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 08:15:35 volumio volumio[9643]: 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 17 08:15:35 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:15:35 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:15:35 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:15:35 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:15:35 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:15:35 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:15:35 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:15:35 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:15:35 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 08:15:35 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:15:35 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:15:35 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:15:35 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:15:35 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:15:35 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:15:35 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:15:35 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:15:35 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:15:35 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 08:15:35 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:15:35 volumio volumio[9643]: info: No need to fix Spotify hosts Feb 17 08:15:35 volumio go-librespot[9887]: time="2026-02-17T08:15:35+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 08:15:35 volumio go-librespot[9887]: time="2026-02-17T08:15:35+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 17 08:15:35 volumio go-librespot[9887]: time="2026-02-17T08:15:35+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 17 08:15:35 volumio go-librespot[9887]: time="2026-02-17T08:15:35+07:00" level=info msg="zeroconf server listening on port 39585" Feb 17 08:15:35 volumio go-librespot[9887]: time="2026-02-17T08:15:35+07:00" level=debug msg="obtained new client token: AAB61sB5HNZkdh9Vw9OXI3TNM3J5szaRw+GkqUKtNliflitjy/nLjYGb/HBqAST31VMofE2FEPo64/iVjg69NwgueTYOelJ6mMRkwLroywNQGiSaIt6h9aQZEfCUaxP0Go765sCBSST2MB9QPq8d7L/4qaEYxhFyxx3lWyastBP4V0mIMp91UDEU4b2gTaXbYsapwCQ0Kt8i5gsA71kylmdLMbPXKzkCFe98ZvosWY+ZZv7r4Dn1COCBkQ==" Feb 17 08:15:36 volumio go-librespot[9887]: time="2026-02-17T08:15:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 08:15:36 volumio go-librespot[9887]: time="2026-02-17T08:15:36+07:00" level=debug msg="completed keyexchange" Feb 17 08:15:36 volumio go-librespot[9887]: time="2026-02-17T08:15:36+07:00" level=debug msg="completed challenge" Feb 17 08:15:36 volumio volumio[9643]: info: Volumio called home Feb 17 08:15:36 volumio go-librespot[9887]: time="2026-02-17T08:15: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 17 08:15:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 08:15:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 08:15:36 volumio volumio[9643]: info: Starting Shairport Sync Feb 17 08:15:36 volumio volumio[9643]: info: Starting Shairport Sync Feb 17 08:15:36 volumio volumio[9643]: info: Starting Shairport Sync Feb 17 08:15:36 volumio sudo[9923]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 08:15:36 volumio sudo[9923]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:15:36 volumio sudo[9925]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 08:15:36 volumio sudo[9925]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:15:36 volumio sudo[9927]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 08:15:36 volumio sudo[9927]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:15:36 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 08:15:36 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 08:15:36 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 08:15:36 volumio systemd[1]: shairport-sync.service: Consumed 2.317s CPU time. Feb 17 08:15:36 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 08:15:36 volumio sudo[9923]: pam_unix(sudo:session): session closed for user root Feb 17 08:15:36 volumio sudo[9927]: pam_unix(sudo:session): session closed for user root Feb 17 08:15:36 volumio sudo[9925]: pam_unix(sudo:session): session closed for user root Feb 17 08:15:36 volumio volumio[9643]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 08:15:36 volumio volumio[9643]: SPOTIFY: BQCxIsQ75ly4DDK12P-KjCEt-cyE5RHSYJpbqOpF3TEX2eEe9fLNHVqMWM0zJwt5U2rD6VwD41t8P2ZEYAQIUR3PstNlmGW5SF1a6VrsThjd1YmuqqLx0EpcchxGCdPWX2r0O38D_m1blZdmPzKg30WTOcTcPAnez55HHaPo-WjUP2phdQfqwT4P8JtDrPJPSvy-ji2aS4HeY8zmxhKN6DyY0jJ7aXXGQ5M9Yi4nDzdIqL6Y_MkzpNhmgZ8QfJ03kc8_U9ZUbojUa3NiHcVsjJ5mZaKliBbf21weq1eoApiVweEca9jbWF0b Feb 17 08:15:36 volumio volumio[9643]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 08:15:36 volumio volumio[9643]: info: New Spotify access token = BQCxIsQ75ly4DDK12P-KjCEt-cyE5RHSYJpbqOpF3TEX2eEe9fLNHVqMWM0zJwt5U2rD6VwD41t8P2ZEYAQIUR3PstNlmGW5SF1a6VrsThjd1YmuqqLx0EpcchxGCdPWX2r0O38D_m1blZdmPzKg30WTOcTcPAnez55HHaPo-WjUP2phdQfqwT4P8JtDrPJPSvy-ji2aS4HeY8zmxhKN6DyY0jJ7aXXGQ5M9Yi4nDzdIqL6Y_MkzpNhmgZ8QfJ03kc8_U9ZUbojUa3NiHcVsjJ5mZaKliBbf21weq1eoApiVweEca9jbWF0b Feb 17 08:15:36 volumio volumio[9643]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 17 08:15:36 volumio volumio[9643]: info: Shairport-Sync Started Feb 17 08:15:36 volumio volumio[9643]: Error adding Membership: Error: addMembership EINVAL Feb 17 08:15:36 volumio volumio[9643]: info: Shairport-Sync Started Feb 17 08:15:36 volumio volumio[9643]: info: Shairport-Sync Started Feb 17 08:15:36 volumio volumio[9643]: info: CoreCommandRouter::volumioGetState Feb 17 08:15:36 volumio volumio[9643]: info: CorePlayQueue::getTrack 0 Feb 17 08:15:37 volumio volumio[9643]: 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 17 08:15:37 volumio volumio[9643]: info: Spotify Successfully logged in Feb 17 08:15:37 volumio volumio[9643]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 08:15:37 volumio volumio[9643]: info: [1771290937298] CoreMusicLibrary::Adding element Spotify Feb 17 08:15:37 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 08:15:37 volumio volumio[9643]: Cannot find translation for source YouTube Music Feb 17 08:15:37 volumio volumio[9643]: Cannot find translation for source Spotify Feb 17 08:15:37 volumio volumio[9643]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 17 08:15:37 volumio volumio[9643]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 08:15:37 volumio volumio[9643]: info: VolumeController:: Volume=100 Mute =false Feb 17 08:15:37 volumio volumio[9643]: info: CoreCommandRouter::volumioGetState Feb 17 08:15:37 volumio volumio[9643]: info: CorePlayQueue::getTrack 0 Feb 17 08:15:37 volumio volumio[9643]: info: CoreStateMachine::pushState Feb 17 08:15:37 volumio volumio[9643]: info: CorePlayQueue::getTrack 0 Feb 17 08:15:37 volumio volumio[9643]: info: CoreCommandRouter::volumioPushState Feb 17 08:15:39 volumio volumio[9643]: info: go-librespot daemon successfully initialized Feb 17 08:15:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 17 08:15:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:15:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:15:39 volumio go-librespot[9964]: go-librespot daemon starting... Feb 17 08:15:39 volumio go-librespot[9965]: time="2026-02-17T08:15:39+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 08:15:39 volumio go-librespot[9965]: time="2026-02-17T08:15:39+07:00" level=debug msg="app state loaded" Feb 17 08:15:39 volumio go-librespot[9965]: time="2026-02-17T08:15:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 08:15:39 volumio mpd[9868]: 2026-02-17T08:15:39 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 17 08:15:39 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 17 08:15:39 volumio sudo[9827]: pam_unix(sudo:session): session closed for user root Feb 17 08:15:39 volumio sudo[9839]: pam_unix(sudo:session): session closed for user root Feb 17 08:15:39 volumio volumio[9643]: error: MPD error: The expression evaluated to a falsy value: Feb 17 08:15:39 volumio volumio[9643]: assert.ok(self.idling) Feb 17 08:15:39 volumio volumio[9643]: error: The expression evaluated to a falsy value: Feb 17 08:15:39 volumio volumio[9643]: assert.ok(self.idling) Feb 17 08:15:39 volumio volumio[9643]: info: MPD running with PID9868 Feb 17 08:15:39 volumio volumio[9643]: ,establishing connection Feb 17 08:15:39 volumio volumio[9643]: error: updateQueue error: null Feb 17 08:15:39 volumio volumio[9643]: info: Completed starting Core Plugins Feb 17 08:15:39 volumio volumio[9643]: info: ------------------------------------------- Feb 17 08:15:39 volumio volumio[9643]: info: ----- MyVolumio plugins startup ---- Feb 17 08:15:39 volumio volumio[9643]: info: ------------------------------------------- Feb 17 08:15:39 volumio volumio[9643]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 17 08:15:39 volumio volumio[9643]: error: updateQueue error: null Feb 17 08:15:39 volumio go-librespot[9965]: time="2026-02-17T08:15: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 08:15:39 volumio go-librespot[9965]: time="2026-02-17T08:15:39+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 17 08:15:39 volumio go-librespot[9965]: time="2026-02-17T08:15:39+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 17 08:15:39 volumio go-librespot[9965]: time="2026-02-17T08:15:39+07:00" level=info msg="zeroconf server listening on port 39259" Feb 17 08:15:40 volumio go-librespot[9965]: time="2026-02-17T08:15:40+07:00" level=debug msg="obtained new client token: AABphl7BMb9oo5vQOx/jnbOOsYjsQLQJM1Wc0OAc0k9qgP1CzlXdd+qlP0kTar/cnmsxBzuv5xX4/DBtJaxSE3b+d/gjNAkkw4r0jR5uGOS5eDaXp5rWzXey24cZw8PA8iakbhVQm6XtEgeJbALZXRWAh4/Xt5HtMEY1PvFPXIYbSjlgrNJ2dHOab9lWsiCjUxc5rDnrIFHezu0P/658ZMrX7/OBLL4eQRbpZtD60jxHLNhdwcYiY9E=" Feb 17 08:15:40 volumio go-librespot[9965]: time="2026-02-17T08:15:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 08:15:40 volumio go-librespot[9965]: time="2026-02-17T08:15:40+07:00" level=debug msg="completed keyexchange" Feb 17 08:15:40 volumio go-librespot[9965]: time="2026-02-17T08:15:40+07:00" level=debug msg="completed challenge" Feb 17 08:15:40 volumio go-librespot[9965]: time="2026-02-17T08:15:40+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 08:15:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 08:15:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 08:15:42 volumio volumio[9643]: info: Initializing connection to go-librespot Websocket Feb 17 08:15:42 volumio volumio[9643]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 08:15:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 17 08:15:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:15:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:15:43 volumio go-librespot[9976]: go-librespot daemon starting... Feb 17 08:15:43 volumio go-librespot[9977]: time="2026-02-17T08:15:43+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 08:15:43 volumio go-librespot[9977]: time="2026-02-17T08:15:43+07:00" level=debug msg="app state loaded" Feb 17 08:15:43 volumio go-librespot[9977]: time="2026-02-17T08:15:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 08:15:44 volumio go-librespot[9977]: time="2026-02-17T08:15: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 08:15:44 volumio go-librespot[9977]: time="2026-02-17T08:15:44+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 17 08:15:44 volumio go-librespot[9977]: time="2026-02-17T08:15:44+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 17 08:15:44 volumio go-librespot[9977]: time="2026-02-17T08:15:44+07:00" level=info msg="zeroconf server listening on port 35073" Feb 17 08:15:44 volumio go-librespot[9977]: time="2026-02-17T08:15:44+07:00" level=debug msg="obtained new client token: AAAKP4HOHeAGMXu1uoIVSwryfo63CdpWnQnfRqXAtKpvq30ZOYkH5rd/OFaR1XM/urfcyv53FSbN+7y6Le0mb+4kI4saNVxk4J1KI12ayn5O0pIyeucdxEEgYFCJFLnB26lI8zzeHjARFn+l7toxvkdRukGzT5dVEeDllFHDB56YKyaPqwB9eZC9gIdgh2K/qjPawUEmQ+IH5vsd8Luyb7tVVypwx9eKQ1KjHz9dy4zo53RfmHGchWEHbQ==" Feb 17 08:15:44 volumio volumio[9643]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 17 08:15:44 volumio go-librespot[9977]: time="2026-02-17T08:15:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 08:15:44 volumio go-librespot[9977]: time="2026-02-17T08:15:44+07:00" level=debug msg="completed keyexchange" Feb 17 08:15:44 volumio go-librespot[9977]: time="2026-02-17T08:15:44+07:00" level=debug msg="completed challenge" Feb 17 08:15:44 volumio go-librespot[9977]: time="2026-02-17T08:15:44+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 17 08:15:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 08:15:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 08:15:45 volumio volumio[9643]: info: Initializing connection to go-librespot Websocket Feb 17 08:15:45 volumio volumio[9643]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 08:15:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 17 08:15:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:15:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:15:48 volumio go-librespot[9984]: go-librespot daemon starting... Feb 17 08:15:48 volumio go-librespot[9985]: time="2026-02-17T08:15:48+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 08:15:48 volumio go-librespot[9985]: time="2026-02-17T08:15:48+07:00" level=debug msg="app state loaded" Feb 17 08:15:48 volumio go-librespot[9985]: time="2026-02-17T08:15:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 08:15:48 volumio volumio[9643]: info: Initializing connection to go-librespot Websocket Feb 17 08:15:48 volumio go-librespot[9985]: time="2026-02-17T08:15:48+07:00" level=debug msg="new websocket client" Feb 17 08:15:48 volumio volumio[9643]: info: Connection to go-librespot Websocket established Feb 17 08:15:48 volumio volumio[9643]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 17 08:15:48 volumio volumio[9643]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 17 08:15:48 volumio volumio[9643]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 17 08:15:48 volumio volumio[9643]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 17 08:15:48 volumio volumio[9643]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 17 08:15:48 volumio volumio[9643]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 17 08:15:48 volumio volumio[9643]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 17 08:15:48 volumio volumio[9643]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 17 08:15:48 volumio volumio[9643]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 17 08:15:48 volumio volumio[9643]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 17 08:15:48 volumio volumio[9643]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 17 08:15:48 volumio volumio[9643]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 17 08:15:48 volumio volumio[9643]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 17 08:15:48 volumio volumio[9643]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 17 08:15:48 volumio volumio[9643]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 17 08:15:48 volumio volumio[9643]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 17 08:15:48 volumio volumio[9643]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 17 08:15:48 volumio volumio[9643]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 17 08:15:48 volumio volumio[9643]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 17 08:15:48 volumio volumio[9643]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 17 08:15:48 volumio volumio[9643]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 17 08:15:48 volumio volumio[9643]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 17 08:15:48 volumio volumio[9643]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 17 08:15:48 volumio volumio[9643]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 17 08:15:48 volumio volumio[9643]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 17 08:15:48 volumio volumio[9643]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 17 08:15:48 volumio volumio[9643]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 17 08:15:48 volumio volumio[9643]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 17 08:15:48 volumio go-librespot[9985]: time="2026-02-17T08:15:48+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 08:15:48 volumio go-librespot[9985]: time="2026-02-17T08:15:48+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 17 08:15:48 volumio go-librespot[9985]: time="2026-02-17T08:15:48+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 17 08:15:48 volumio volumio[9643]: info: Adding plugin bluetooth to MyMusic Plugins Feb 17 08:15:48 volumio volumio[9643]: info: Adding plugin multiroom to MyMusic Plugins Feb 17 08:15:48 volumio volumio[9643]: info: Adding plugin metavolumio to MyMusic Plugins Feb 17 08:15:48 volumio volumio[9643]: info: Adding plugin cd_controller to MyMusic Plugins Feb 17 08:15:48 volumio volumio[9643]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 17 08:15:48 volumio volumio[9643]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 17 08:15:48 volumio volumio[9643]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 17 08:15:48 volumio volumio[9643]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 17 08:15:48 volumio go-librespot[9985]: time="2026-02-17T08:15:48+07:00" level=info msg="zeroconf server listening on port 36443" Feb 17 08:15:48 volumio go-librespot[9985]: time="2026-02-17T08:15:48+07:00" level=debug msg="obtained new client token: AACObL38/5dpTDyLfgJFNFZbjqP4VrJxDvMznSKs98IyQOCL+UxAbc9e0Pqnjz7Es0oUnSU99cUiYtS6ZpyNLBfebgkP5pm5SKYazv1Lq6yznXT8jIg+DdZuYxTTFCqSLeqGzUCy6h30YAcF6Yh7xZbB6aurOwD7mKJDdMizLNcf3PiYNCsX6x1Kav7sKc8I1ZSZ+GOuM81NUGJtIpbQSGJET+HjvDvQS4Jpv7PsB1MksL4T6PqzO6njVQ==" Feb 17 08:15:49 volumio go-librespot[9985]: time="2026-02-17T08:15:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 08:15:49 volumio go-librespot[9985]: time="2026-02-17T08:15:49+07:00" level=debug msg="completed keyexchange" Feb 17 08:15:49 volumio go-librespot[9985]: time="2026-02-17T08:15:49+07:00" level=debug msg="completed challenge" Feb 17 08:15:49 volumio go-librespot[9985]: time="2026-02-17T08:15: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 17 08:15:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 08:15:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 08:15:50 volumio volumio[9643]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 17 08:15:50 volumio volumio[9643]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 17 08:15:50 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 08:15:50 volumio volumio[9643]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 08:15:50 volumio volumio[9643]: info: Starting MyVolumio Remote Streaming Endpoints Feb 17 08:15:50 volumio volumio[9643]: info: MyVolumio login type: Token Feb 17 08:15:50 volumio volumio[9643]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 17 08:15:50 volumio volumio[9643]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 17 08:15:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 17 08:15:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:15:52 volumio volumio[9643]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 17 08:15:52 volumio volumio[9643]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 17 08:15:52 volumio volumio[9643]: info: Streaming services startup Feb 17 08:15:52 volumio volumio[9643]: info: Starting Streaming Daemon Feb 17 08:15:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:15:52 volumio go-librespot[10006]: go-librespot daemon starting... Feb 17 08:15:52 volumio sudo[10008]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 17 08:15:52 volumio sudo[10008]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:15:52 volumio volumio[9643]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 17 08:15:52 volumio go-librespot[10012]: time="2026-02-17T08:15:52+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 08:15:52 volumio go-librespot[10012]: time="2026-02-17T08:15:52+07:00" level=debug msg="app state loaded" Feb 17 08:15:52 volumio go-librespot[10012]: time="2026-02-17T08:15:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 08:15:52 volumio sudo[10008]: pam_unix(sudo:session): session closed for user root Feb 17 08:15:52 volumio volumio[9643]: info: Getting Spotify volume Feb 17 08:15:52 volumio volumio[9643]: info: Connection to go-librespot Websocket closed Feb 17 08:15:52 volumio volumio[9643]: error: Cannot start Volumio Streaming Daemon Feb 17 08:15:52 volumio volumio[9643]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 17 08:15:52 volumio volumio[9643]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 17 08:15:52 volumio volumio[9643]: 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 17 08:15:52 volumio volumio[9643]: info: CoreCommandRouter::volumioGetState Feb 17 08:15:52 volumio volumio[9643]: info: CorePlayQueue::getTrack 0 Feb 17 08:15:52 volumio volumio[9643]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 17 08:15:52 volumio volumio[9643]: SPOTIFY: SPOTIFY VOLUME undefined Feb 17 08:15:52 volumio volumio[9643]: SPOTIFY: VOLUMIO VOLUME 100 Feb 17 08:15:52 volumio volumio[9643]: info: Aligning Spotify Volume to Volumio Volume Feb 17 08:15:52 volumio volumio[9643]: info: CoreCommandRouter::volumioGetState Feb 17 08:15:52 volumio volumio[9643]: info: CorePlayQueue::getTrack 0 Feb 17 08:15:52 volumio volumio[9643]: info: Setting Spotify Volume from Volumio: 100 Feb 17 08:15:52 volumio go-librespot[10012]: time="2026-02-17T08:15:52+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 08:15:52 volumio go-librespot[10012]: time="2026-02-17T08:15:52+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 17 08:15:52 volumio go-librespot[10012]: time="2026-02-17T08:15:52+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 17 08:15:53 volumio go-librespot[10012]: time="2026-02-17T08:15:53+07:00" level=info msg="zeroconf server listening on port 40259" Feb 17 08:15:53 volumio go-librespot[10012]: time="2026-02-17T08:15:53+07:00" level=debug msg="obtained new client token: AAAttR0O3vwR+5d6d8iLGMUzUdyEWui+rB6+b1c72AN3n2l61bNGF+u3yg/JQYkvB+2iGldKK2jVxWzZAmLzGvCnIm/ANGjpvc0A7XcQVtx5HlJh/ZU+3+OA/m5XcVHKX0/z0r+SkMmKwDlBfM+YW7yciMy4vtxhFGmoZNy+tVkMsUOqPGnRJs1+RF8t0/FuvuILxDXF6W9tK5A7gOKzKGKySeKOocLGP2I7QNf55ENoM4efBQS8CGM=" Feb 17 08:15:53 volumio go-librespot[10012]: time="2026-02-17T08:15:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 08:15:53 volumio go-librespot[10012]: time="2026-02-17T08:15:53+07:00" level=debug msg="completed keyexchange" Feb 17 08:15:53 volumio go-librespot[10012]: time="2026-02-17T08:15:53+07:00" level=debug msg="completed challenge" Feb 17 08:15:53 volumio go-librespot[10012]: time="2026-02-17T08:15: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 17 08:15:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 08:15:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 08:15:53 volumio volumio[9643]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 17 08:15:53 volumio volumio[9643]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 08:15:53 volumio volumio[9643]: Error: socket hang up Feb 17 08:15:53 volumio volumio[9643]: at connResetException (node:internal/errors:720:14) Feb 17 08:15:53 volumio volumio[9643]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 17 08:15:53 volumio volumio[9643]: at Socket.emit (node:events:526:35) Feb 17 08:15:53 volumio volumio[9643]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 17 08:15:53 volumio volumio[9643]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 17 08:15:53 volumio volumio[9643]: code: 'ECONNRESET', Feb 17 08:15:53 volumio volumio[9643]: response: undefined Feb 17 08:15:53 volumio volumio[9643]: } Feb 17 08:15:53 volumio volumio[9643]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 08:15:55 volumio sudo[10035]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 08:14' Feb 17 08:15:55 volumio sudo[10035]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:15:55 volumio sudo[10035]: pam_unix(sudo:session): session closed for user root Feb 17 08:15:55 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 17 08:15:55 volumio volumio-remote-updater[25144]: [2026-02-17 08:15:55] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 17 08:15:55 volumio volumio-remote-updater[25144]: [2026-02-17 08:15:55] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 17 08:15:55 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 17 08:15:55 volumio systemd[1]: volumio.service: Consumed 55.721s CPU time. Feb 17 08:15:55 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 08:15:55 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 08:15:55 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 20113. Feb 17 08:15:55 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 08:15:55 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 17 08:15:55 volumio systemd[1]: volumio.service: Consumed 55.721s CPU time. Feb 17 08:15:55 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 17 08:15:55 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 08:15:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 17 08:15:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:15:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:15:56 volumio go-librespot[10062]: go-librespot daemon starting... Feb 17 08:15:56 volumio go-librespot[10063]: time="2026-02-17T08:15:56+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 08:15:56 volumio go-librespot[10063]: time="2026-02-17T08:15:56+07:00" level=debug msg="app state loaded" Feb 17 08:15:56 volumio go-librespot[10063]: time="2026-02-17T08:15:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 08:15:57 volumio go-librespot[10063]: time="2026-02-17T08:15:57+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 08:15:57 volumio go-librespot[10063]: time="2026-02-17T08:15:57+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 17 08:15:57 volumio go-librespot[10063]: time="2026-02-17T08:15:57+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 17 08:15:57 volumio go-librespot[10063]: time="2026-02-17T08:15:57+07:00" level=info msg="zeroconf server listening on port 42911" Feb 17 08:15:57 volumio go-librespot[10063]: time="2026-02-17T08:15:57+07:00" level=debug msg="obtained new client token: AADmOGB3bEwgP3wjAlh9FeI0VfKbUi0P+FkaYWXQoocadWxTWbqLhJtUNrwfX/nlbxH9hORaFUP8WYoNUvXDFi6Y6GodMd8TfigP9F1LZTpzHOZVe+fzyTGf+R+X3HV72vaNo66yJyF6iIT2JRknuEYoYNt56bvykD1m7GboVeKU3hrEwSk04r603t/tqBunNztY6xB8xTuOkwPWMRpVB8rU1m2qvjWJQriRlx9wlxyHl+gCXc19evLkDA==" Feb 17 08:15:57 volumio go-librespot[10063]: time="2026-02-17T08:15:57+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 17 08:15:57 volumio go-librespot[10063]: time="2026-02-17T08:15:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 17 08:15:57 volumio go-librespot[10063]: time="2026-02-17T08:15:57+07:00" level=debug msg="completed keyexchange" Feb 17 08:15:57 volumio go-librespot[10063]: time="2026-02-17T08:15:57+07:00" level=debug msg="completed challenge" Feb 17 08:15:57 volumio go-librespot[10063]: time="2026-02-17T08:15:57+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 17 08:15:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 08:15:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 08:15:59 volumio volumio[10047]: info: ------------------------------------------- Feb 17 08:15:59 volumio volumio[10047]: info: ----- Volumio3 ---- Feb 17 08:15:59 volumio volumio[10047]: info: ------------------------------------------- Feb 17 08:15:59 volumio volumio[10047]: info: ----- System startup ---- Feb 17 08:15:59 volumio volumio[10047]: info: ------------------------------------------- Feb 17 08:16:00 volumio volumio-remote-updater[25144]: [2026-02-17 08:16:00] [connect] Successful connection Feb 17 08:16:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 17 08:16:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:16:00 volumio volumio[10047]: info: MYVOLUMIO Environment detected Feb 17 08:16:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:16:00 volumio go-librespot[10079]: go-librespot daemon starting... Feb 17 08:16:00 volumio go-librespot[10083]: time="2026-02-17T08:16:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 08:16:00 volumio go-librespot[10083]: time="2026-02-17T08:16:00+07:00" level=debug msg="app state loaded" Feb 17 08:16:00 volumio go-librespot[10083]: time="2026-02-17T08:16:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 08:16:00 volumio volumio[10047]: info: Plugin folders cleanup Feb 17 08:16:00 volumio volumio[10047]: info: Scanning into folder /volumio/app/plugins/ Feb 17 08:16:00 volumio volumio[10047]: info: Scanning category audio_interface Feb 17 08:16:01 volumio volumio[10047]: info: Scanning category miscellanea Feb 17 08:16:01 volumio volumio[10047]: info: Scanning category music_service Feb 17 08:16:01 volumio volumio[10047]: info: Scanning category plugins.json Feb 17 08:16:01 volumio volumio[10047]: info: Scanning category system_controller Feb 17 08:16:01 volumio volumio[10047]: info: Scanning category user_interface Feb 17 08:16:01 volumio volumio[10047]: info: Scanning into folder /data/plugins/ Feb 17 08:16:01 volumio volumio[10047]: info: Scanning category music_service Feb 17 08:16:01 volumio volumio[10047]: info: Plugin folders cleanup completed Feb 17 08:16:01 volumio volumio[10047]: info: ------------------------------------------- Feb 17 08:16:01 volumio volumio[10047]: info: ----- Core plugins startup ---- Feb 17 08:16:01 volumio volumio[10047]: info: ------------------------------------------- Feb 17 08:16:01 volumio volumio[10047]: info: Loading plugins from folder /volumio/app/plugins/ Feb 17 08:16:01 volumio volumio[10047]: info: Adding plugin upnp to MyMusic Plugins Feb 17 08:16:01 volumio volumio[10047]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 17 08:16:01 volumio volumio[10047]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 17 08:16:01 volumio volumio[10047]: info: Loading plugins from folder /data/plugins/ Feb 17 08:16:01 volumio volumio[10047]: info: Loading plugin "system"... Feb 17 08:16:01 volumio volumio[10047]: info: Loading plugin "appearance"... Feb 17 08:16:01 volumio go-librespot[10083]: time="2026-02-17T08:16: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-gew4.spotify.com:80]" Feb 17 08:16:01 volumio go-librespot[10083]: time="2026-02-17T08:16:01+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 17 08:16:01 volumio go-librespot[10083]: time="2026-02-17T08:16:01+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 17 08:16:01 volumio go-librespot[10083]: time="2026-02-17T08:16:01+07:00" level=info msg="zeroconf server listening on port 36893" Feb 17 08:16:01 volumio go-librespot[10083]: time="2026-02-17T08:16:01+07:00" level=debug msg="obtained new client token: AACr86cw44Od4R4ndpWMfGTHwemIK8BbkLj7NXt5cn50KvkGOmv69DoeOjanRQsEsvZxsmXPGpDcNcl/tTy5Lp200XclXm9iCy7+fGpr9lBo59J/eUAaJYN44Si4Qmxkxdj/PUVhqsJ7XLg4v4TJpasG5BILwwegD9Rbw0g5LZZ/lZmC8iCxRQgwIpv9DcFP8i3YyruDXQFgS7aHsRlAJBp9gtpEbvz7nUZWQcybYMImoIc8fMOOIw9K2Q==" Feb 17 08:16:01 volumio go-librespot[10083]: time="2026-02-17T08:16:01+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 17 08:16:01 volumio go-librespot[10083]: time="2026-02-17T08:16:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 17 08:16:02 volumio go-librespot[10083]: time="2026-02-17T08:16:02+07:00" level=debug msg="completed keyexchange" Feb 17 08:16:02 volumio go-librespot[10083]: time="2026-02-17T08:16:02+07:00" level=debug msg="completed challenge" Feb 17 08:16:02 volumio go-librespot[10083]: time="2026-02-17T08:16:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 08:16:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 08:16:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 08:16:03 volumio volumio[10047]: info: Loading plugin "network"... Feb 17 08:16:03 volumio volumio[10047]: info: Refreshing Cached IP Addresses Feb 17 08:16:03 volumio sudo[10097]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 08:16:03 volumio sudo[10097]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:16:03 volumio sudo[10099]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 08:16:03 volumio sudo[10099]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:16:03 volumio volumio[10047]: info: Loading plugin "services"... Feb 17 08:16:03 volumio sudo[10099]: pam_unix(sudo:session): session closed for user root Feb 17 08:16:03 volumio volumio[10047]: info: Loading plugin "alsa_controller"... Feb 17 08:16:03 volumio sudo[10097]: pam_unix(sudo:session): session closed for user root Feb 17 08:16:03 volumio sudo[10107]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 17 08:16:03 volumio sudo[10107]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:16:03 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 08:16:03 volumio volumio[10047]: info: Loading plugin "wizard"... Feb 17 08:16:03 volumio volumio[10047]: info: Loading plugin "networkfs"... Feb 17 08:16:03 volumio volumio[10047]: info: Starting Udev Watcher for removable devices Feb 17 08:16:03 volumio volumio[10047]: info: Ignoring mount for partition: boot Feb 17 08:16:03 volumio volumio[10047]: info: Ignoring mount for partition: volumio Feb 17 08:16:03 volumio volumio[10047]: info: Ignoring mount for partition: volumio_data Feb 17 08:16:03 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 08:16:03 volumio volumio[10047]: info: Loading plugin "volumio_command_line_client"... Feb 17 08:16:03 volumio volumio[10047]: info: Loading plugin "upnp"... Feb 17 08:16:03 volumio volumio[10047]: info: [1771290963507] Starting Upmpd Daemon Feb 17 08:16:03 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 08:16:03 volumio volumio[10047]: info: Loading plugin "my_music"... Feb 17 08:16:03 volumio volumio[10047]: info: Loading plugin "mpd"... Feb 17 08:16:04 volumio volumio[10047]: info: Loading plugin "upnp_browser"... Feb 17 08:16:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 17 08:16:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:16:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:16:05 volumio go-librespot[10130]: go-librespot daemon starting... Feb 17 08:16:05 volumio go-librespot[10131]: time="2026-02-17T08:16:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 08:16:05 volumio go-librespot[10131]: time="2026-02-17T08:16:05+07:00" level=debug msg="app state loaded" Feb 17 08:16:05 volumio go-librespot[10131]: time="2026-02-17T08:16:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 08:16:05 volumio go-librespot[10131]: time="2026-02-17T08:16:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 08:16:05 volumio go-librespot[10131]: time="2026-02-17T08:16:05+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 08:16:05 volumio go-librespot[10131]: time="2026-02-17T08:16:05+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 08:16:06 volumio go-librespot[10131]: time="2026-02-17T08:16:06+07:00" level=info msg="zeroconf server listening on port 33439" Feb 17 08:16:06 volumio sudo[10107]: pam_unix(sudo:session): session closed for user root Feb 17 08:16:06 volumio go-librespot[10131]: time="2026-02-17T08:16:06+07:00" level=debug msg="obtained new client token: AACJ2JgIvADX//a2GB0FuIOkc6Ta0CEzE/z0lQtYlVqkEva0+5tauQAHm+8V0cYsz5yyOT4tvTAy6z0OrnCANYK+PulI0HqKJqxzeLLPpwYqTgdAWAzGJshQgFJLlIEeuYDPvFZDPFisaQ7ua4fpMbjPzsdd9I9uFeB+Ig8fpkFLjqRQ7Lb/JltN2aFrqp8zdjSV33UGWT5oRm91M0FTxPyfITm9Nv0tHfGnLT5W+W9uBtTvoxoasxM=" Feb 17 08:16:06 volumio go-librespot[10131]: time="2026-02-17T08:16:06+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 17 08:16:06 volumio go-librespot[10131]: time="2026-02-17T08:16:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 17 08:16:06 volumio go-librespot[10131]: time="2026-02-17T08:16:06+07:00" level=debug msg="completed keyexchange" Feb 17 08:16:06 volumio go-librespot[10131]: time="2026-02-17T08:16:06+07:00" level=debug msg="completed challenge" Feb 17 08:16:06 volumio go-librespot[10131]: time="2026-02-17T08:16:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 08:16:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 08:16:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 08:16:07 volumio volumio[10047]: info: Starting UPNP Browser Feb 17 08:16:07 volumio volumio[10047]: info: Loading plugin "alarm-clock"... Feb 17 08:16:07 volumio volumio[10047]: info: Loading plugin "airplay_emulation"... Feb 17 08:16:07 volumio volumio[10047]: info: Starting Shairport Sync Feb 17 08:16:07 volumio volumio[10047]: info: Loading plugin "last_100"... Feb 17 08:16:07 volumio volumio[10047]: info: Loading plugin "webradio"... Feb 17 08:16:07 volumio volumio[10047]: info: Loading plugin "i2s_dacs"... Feb 17 08:16:07 volumio volumio[10047]: info: Loading plugin "volumiodiscovery"... Feb 17 08:16:07 volumio volumio[10047]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 08:16:07 volumio volumio[10047]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 08:16:07 volumio node[10047]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 08:16:07 volumio volumio[10047]: *** WARNING *** For more information see Feb 17 08:16:07 volumio volumio[10047]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 08:16:07 volumio volumio[10047]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 08:16:07 volumio volumio[10047]: *** WARNING *** For more information see Feb 17 08:16:07 volumio node[10047]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 08:16:07 volumio node[10047]: *** WARNING *** For more information see Feb 17 08:16:07 volumio node[10047]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 08:16:07 volumio node[10047]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 08:16:07 volumio node[10047]: *** WARNING *** For more information see Feb 17 08:16:07 volumio volumio[10047]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 17 08:16:07 volumio volumio[10047]: info: Discovery: Started advertising with name: Volumio Feb 17 08:16:07 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 08:16:07 volumio volumio[10047]: info: Loading plugin "spop"... Feb 17 08:16:09 volumio volumio[10047]: info: Loading plugin "ytcr"... Feb 17 08:16:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 17 08:16:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:16:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:16:09 volumio go-librespot[10140]: go-librespot daemon starting... Feb 17 08:16:09 volumio go-librespot[10141]: time="2026-02-17T08:16:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 08:16:09 volumio go-librespot[10141]: time="2026-02-17T08:16:09+07:00" level=debug msg="app state loaded" Feb 17 08:16:09 volumio go-librespot[10141]: time="2026-02-17T08:16:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 08:16:10 volumio go-librespot[10141]: time="2026-02-17T08:16: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 17 08:16:10 volumio go-librespot[10141]: time="2026-02-17T08:16: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 17 08:16:10 volumio go-librespot[10141]: time="2026-02-17T08:16: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 17 08:16:10 volumio go-librespot[10141]: time="2026-02-17T08:16:10+07:00" level=info msg="zeroconf server listening on port 39779" Feb 17 08:16:10 volumio go-librespot[10141]: time="2026-02-17T08:16:10+07:00" level=debug msg="obtained new client token: AAANQQ7G50sR/fcFPRz7Bvcb7umbVK0uRLi3aY7BVjeBUcruhvvzkyokjHl0C7iaBMqmBllxLm7JB8+jSekKOSCiE4B+wNPJlDM36Go9qlUtDg0h+RFLp64Pz7PojRS2nVOajIMDf/Bp0PgV3oGANc5O+VinZrGhhlOxrC4rIXuQRdpW+rrrHgxkwvDTqS23EGvECD9Z4Wovw9hcz5TMUH+31Tm4Lxmx8PcA4YidJ9zE+KiE0NLkVYhBtA==" Feb 17 08:16:10 volumio go-librespot[10141]: time="2026-02-17T08:16:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 08:16:10 volumio go-librespot[10141]: time="2026-02-17T08:16:10+07:00" level=debug msg="completed keyexchange" Feb 17 08:16:10 volumio go-librespot[10141]: time="2026-02-17T08:16:10+07:00" level=debug msg="completed challenge" Feb 17 08:16:10 volumio go-librespot[10141]: time="2026-02-17T08:16: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 17 08:16:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 08:16:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 08:16:12 volumio volumio[10047]: info: Loading plugin "ytmusic"... Feb 17 08:16:13 volumio volumio-remote-updater[25144]: [2026-02-17 08:16:13] [connect] Successful connection Feb 17 08:16:13 volumio volumio[10047]: info: Loading plugin "outputs"... Feb 17 08:16:13 volumio volumio[10047]: info: Loading plugin "albumart"... Feb 17 08:16:13 volumio volumio[10047]: info: Plugin example_plugin is not enabled Feb 17 08:16:13 volumio volumio[10047]: info: Loading plugin "inputs"... Feb 17 08:16:13 volumio volumio[10047]: info: Loading plugin "updater_comm"... Feb 17 08:16:13 volumio volumio[10047]: info: Plugin mpdemulation is not enabled Feb 17 08:16:13 volumio volumio[10047]: info: Loading plugin "rest_api"... Feb 17 08:16:13 volumio volumio[10047]: info: Loading plugin "websocket"... Feb 17 08:16:13 volumio volumio[10047]: info: Starting Socket.io Server version 1.7.4 Feb 17 08:16:13 volumio volumio[10047]: info: Loading plugin "RoonBridge"... Feb 17 08:16:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 17 08:16:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:16:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:16:14 volumio go-librespot[10172]: go-librespot daemon starting... Feb 17 08:16:14 volumio volumio[10047]: info: Applying required configuration parameters for plugin RoonBridge Feb 17 08:16:14 volumio go-librespot[10173]: time="2026-02-17T08:16:14+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 08:16:14 volumio go-librespot[10173]: time="2026-02-17T08:16:14+07:00" level=debug msg="app state loaded" Feb 17 08:16:14 volumio go-librespot[10173]: time="2026-02-17T08:16:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 08:16:14 volumio volumio[10047]: info: Loading i18n strings for locale en Feb 17 08:16:14 volumio volumio[10047]: Updating browse sources language Feb 17 08:16:14 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 08:16:14 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 08:16:14 volumio volumio[10047]: info: CoreCommandRouter::initPlayerControls Feb 17 08:16:14 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:16:14 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:16:14 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:16:14 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:16:14 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:16:14 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:16:14 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:16:14 volumio volumio[10162]: Forking 3 albumart workers Feb 17 08:16:14 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:16:14 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 08:16:14 volumio volumio[10047]: Express server listening on port 3000 Feb 17 08:16:14 volumio volumio[10047]: [Metrics] WebUI: 16s 9.51ms Feb 17 08:16:14 volumio volumio[10047]: info: CoreStateMachine::resetVolumioState Feb 17 08:16:14 volumio volumio[10047]: info: CoreStateMachine::getcurrentVolume Feb 17 08:16:14 volumio volumio[10047]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 08:16:14 volumio sudo[10207]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 08:16:14 volumio sudo[10207]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:16:14 volumio sudo[10214]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 08:16:14 volumio sudo[10214]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:16:14 volumio sudo[10207]: pam_unix(sudo:session): session closed for user root Feb 17 08:16:14 volumio go-librespot[10173]: time="2026-02-17T08:16: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 08:16:14 volumio go-librespot[10173]: time="2026-02-17T08:16:14+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 17 08:16:14 volumio go-librespot[10173]: time="2026-02-17T08:16:14+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 17 08:16:14 volumio sudo[10214]: pam_unix(sudo:session): session closed for user root Feb 17 08:16:14 volumio go-librespot[10173]: time="2026-02-17T08:16:14+07:00" level=info msg="zeroconf server listening on port 33409" Feb 17 08:16:14 volumio volumio[10047]: info: Volumio Network Manager: Network status updated: 1 Feb 17 08:16:15 volumio go-librespot[10173]: time="2026-02-17T08:16:15+07:00" level=debug msg="obtained new client token: AACkkrh6q4g7FTe+DIpb42vAJ7OYvdxQ8PcIttaNLNwG6rBmn/qmwnSA0aORDKGg76wuLmYG2uuVo5YTpVIbffOutEs4laRrDMKIwz68m5NE3/XOKD3fQeASVvJt4CNGcPuJQ1u78XCojHerGyCq4Kj2FwKj95GwhxNr0t4vParYRuFt1jQ4v47poybazTTsOJ3ACaP7ffrmiWQsJrjCzC96AwtcxurIauCPrNPYUz0vdeI0ZDh5MlQ=" Feb 17 08:16:15 volumio go-librespot[10173]: time="2026-02-17T08:16:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 08:16:15 volumio volumio[10047]: info: VolumeController:: Volume=100 Mute =false Feb 17 08:16:15 volumio volumio[10047]: info: CoreStateMachine::pushState Feb 17 08:16:15 volumio volumio[10047]: info: CorePlayQueue::getTrack 0 Feb 17 08:16:15 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 08:16:15 volumio volumio[10047]: info: CoreCommandRouter::volumioPushState Feb 17 08:16:15 volumio volumio[10047]: info: CoreStateMachine::updateTrackBlock Feb 17 08:16:15 volumio volumio[10047]: info: CorePlayQueue::getTrackBlock Feb 17 08:16:15 volumio volumio[10047]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 08:16:15 volumio go-librespot[10173]: time="2026-02-17T08:16:15+07:00" level=debug msg="completed keyexchange" Feb 17 08:16:15 volumio go-librespot[10173]: time="2026-02-17T08:16:15+07:00" level=debug msg="completed challenge" Feb 17 08:16:15 volumio volumio-remote-updater[25144]: [2026-02-17 08:16:15] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771290973 101 Feb 17 08:16:15 volumio volumio[10047]: 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 17 08:16:15 volumio go-librespot[10173]: time="2026-02-17T08:16: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 17 08:16:15 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 08:16:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 08:16:15 volumio volumio[10047]: info: Reloading queue from file Feb 17 08:16:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 08:16:15 volumio volumio[10047]: info: CoreStateMachine::setRepeat null single undefined Feb 17 08:16:15 volumio volumio[10047]: info: CoreStateMachine::pushState Feb 17 08:16:15 volumio volumio[10047]: info: CorePlayQueue::getTrack 0 Feb 17 08:16:15 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 08:16:15 volumio volumio[10047]: info: CoreCommandRouter::volumioPushState Feb 17 08:16:15 volumio volumio[10047]: info: CoreStateMachine::setRandom null Feb 17 08:16:15 volumio volumio[10047]: info: CoreStateMachine::pushState Feb 17 08:16:15 volumio volumio[10047]: info: CorePlayQueue::getTrack 0 Feb 17 08:16:15 volumio volumio[10047]: info: CoreCommandRouter::volumioPushState Feb 17 08:16:15 volumio volumio[10047]: info: Setting Device type: Raspberry PI Feb 17 08:16:15 volumio volumio[10047]: info: Completed loading Core Plugins Feb 17 08:16:15 volumio volumio[10047]: info: Preparing to generate the ALSA configuration file Feb 17 08:16:15 volumio volumio[10047]: info: VolumeController:: Volume=100 Mute =false Feb 17 08:16:15 volumio volumio[10047]: info: CoreStateMachine::pushState Feb 17 08:16:15 volumio volumio[10047]: info: CorePlayQueue::getTrack 0 Feb 17 08:16:15 volumio volumio[10047]: info: CoreCommandRouter::volumioPushState Feb 17 08:16:15 volumio volumio[10047]: info: Asound.conf file unchanged, so no further update is needed Feb 17 08:16:15 volumio volumio[10047]: info: Output device has changed, restarting MPD Feb 17 08:16:15 volumio volumio[10047]: info: Output device has changed, restarting Shairport Sync Feb 17 08:16:15 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:16:15 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 08:16:15 volumio sudo[10231]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 17 08:16:15 volumio sudo[10231]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:16:15 volumio sudo[10235]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 08:16:15 volumio sudo[10235]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:16:16 volumio sudo[10233]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 08:16:16 volumio sudo[10233]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:16:16 volumio sudo[10233]: pam_unix(sudo:session): session closed for user root Feb 17 08:16:16 volumio volumio[10047]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 08:16:16 volumio volumio[10047]: info: ___________ START PLUGINS ___________ Feb 17 08:16:16 volumio sudo[10231]: pam_unix(sudo:session): session closed for user root Feb 17 08:16:16 volumio volumio[10047]: info: ControllerMpd::onStart: Initializing MPD Feb 17 08:16:16 volumio volumio[10047]: info: Creating MPD Configuration file Feb 17 08:16:16 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 17 08:16:16 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 08:16:16 volumio volumio[10047]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 08:16:16 volumio volumio[10047]: info: [1771290976207] CoreMusicLibrary::Adding element Media Servers Feb 17 08:16:16 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 08:16:16 volumio sudo[10244]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 08:16:16 volumio sudo[10244]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:16:16 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 08:16:16 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 08:16:16 volumio sudo[10244]: pam_unix(sudo:session): session closed for user root Feb 17 08:16:16 volumio systemd[1]: mpd.service: Consumed 7.239s CPU time. Feb 17 08:16:16 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 08:16:16 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 08:16:16 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 08:16:16 volumio volumio[10047]: info: UPNP Browser: Client initialized successfully Feb 17 08:16:16 volumio sudo[10246]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 08:16:16 volumio sudo[10246]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:16:16 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 08:16:16 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:16:16 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 08:16:16 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 08:16:16 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 08:16:16 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 08:16:16 volumio volumio[10047]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 08:16:16 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 08:16:16 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 08:16:16 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 08:16:16 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:16:16 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 08:16:16 volumio volumio[10047]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 08:16:16 volumio volumio[10047]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 08:16:16 volumio volumio[10047]: info: [1771290976531] CoreMusicLibrary::Adding element Last_100 Feb 17 08:16:16 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 08:16:16 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 08:16:16 volumio volumio[10047]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 08:16:16 volumio volumio[10047]: info: [1771290976551] CoreMusicLibrary::Adding element Webradio Feb 17 08:16:16 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 08:16:16 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 08:16:16 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 08:16:16 volumio volumio[10047]: info: Initializing BBC Radios Feb 17 08:16:16 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 08:16:16 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 08:16:16 volumio volumio[10047]: info: Creating Spotify config file Feb 17 08:16:16 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:16:17 volumio sudo[10260]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 17 08:16:17 volumio sudo[10260]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 17 08:16:17 volumio sudo[10260]: pam_unix(sudo:session): session closed for user root Feb 17 08:16:17 volumio volumio[10179]: Starting albumart workers Feb 17 08:16:17 volumio volumio[10047]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 08:16:17 volumio volumio[10047]: info: [1771290977917] CoreMusicLibrary::Adding element YouTube Music Feb 17 08:16:17 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 08:16:17 volumio volumio[10047]: Cannot find translation for source YouTube Music Feb 17 08:16:17 volumio volumio[10185]: Starting albumart workers Feb 17 08:16:17 volumio volumio[10047]: info: Volumio Calling Home Feb 17 08:16:18 volumio volumio[10181]: Starting albumart workers Feb 17 08:16:18 volumio sudo[10277]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 17 08:16:18 volumio sudo[10277]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:16:18 volumio sudo[10277]: pam_unix(sudo:session): session closed for user root Feb 17 08:16:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 17 08:16:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:16:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:16:18 volumio go-librespot[10283]: go-librespot daemon starting... Feb 17 08:16:18 volumio go-librespot[10284]: time="2026-02-17T08:16:18+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 08:16:18 volumio volumio[10047]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 08:16:18 volumio volumio[10047]: info: Discovery: Found device Volumio Feb 17 08:16:18 volumio volumio[10047]: info: CoreCommandRouter::volumioGetState Feb 17 08:16:18 volumio volumio[10047]: info: CorePlayQueue::getTrack 0 Feb 17 08:16:18 volumio volumio[10047]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 08:16:18 volumio volumio[10047]: info: Discovery: Found device Volumio Feb 17 08:16:18 volumio volumio[10047]: info: CoreCommandRouter::volumioGetState Feb 17 08:16:18 volumio volumio[10047]: info: CorePlayQueue::getTrack 0 Feb 17 08:16:18 volumio volumio[10047]: info: MPD Permissions set Feb 17 08:16:18 volumio volumio[10047]: info: MPD Permissions set Feb 17 08:16:18 volumio volumio[10047]: info: Upmpdcli Daemon Started Feb 17 08:16:19 volumio volumio[10047]: info: Volumio called home Feb 17 08:16:19 volumio volumio[10047]: info: Spotify config file written Feb 17 08:16:19 volumio sudo[10292]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 17 08:16:19 volumio sudo[10292]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:16:19 volumio go-librespot[10284]: time="2026-02-17T08:16:19+07:00" level=info msg="zeroconf server listening on port 34783" Feb 17 08:16:19 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 17 08:16:19 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 17 08:16:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:16:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:16:19 volumio go-librespot[10294]: go-librespot daemon starting... Feb 17 08:16:19 volumio sudo[10292]: pam_unix(sudo:session): session closed for user root Feb 17 08:16:19 volumio go-librespot[10295]: time="2026-02-17T08:16:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 08:16:19 volumio go-librespot[10295]: time="2026-02-17T08:16:19+07:00" level=debug msg="app state loaded" Feb 17 08:16:19 volumio go-librespot[10295]: time="2026-02-17T08:16:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 08:16:19 volumio volumio[10047]: 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 17 08:16:19 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:16:19 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:16:19 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:16:19 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:16:19 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:16:19 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:16:19 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:16:19 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:16:19 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 08:16:19 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:16:19 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:16:19 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:16:19 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:16:19 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:16:19 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:16:20 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:16:20 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:16:20 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:16:20 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 08:16:20 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 08:16:20 volumio volumio[10047]: info: No need to fix Spotify hosts Feb 17 08:16:20 volumio go-librespot[10295]: time="2026-02-17T08:16:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 08:16:20 volumio go-librespot[10295]: time="2026-02-17T08:16:20+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 17 08:16:20 volumio go-librespot[10295]: time="2026-02-17T08:16:20+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 17 08:16:20 volumio go-librespot[10295]: time="2026-02-17T08:16:20+07:00" level=info msg="zeroconf server listening on port 34961" Feb 17 08:16:20 volumio go-librespot[10295]: time="2026-02-17T08:16:20+07:00" level=debug msg="obtained new client token: AADcOEgcJFBvSmn/BGQtBDk5DNitjGGkm6fgZMsOhK93PP++TDcy5oiLUJ+9MrQWHb9ZbGXqAynRTJf8viXj3vaEBo1DWm+KNcrK/tNzi0pLV26wUBPeJsUaOrM0/d42tNA97w28ZBieTtRYMJu1nPfKqTLzPjZQgw6Opj2KR666kSYHD+r2K5tnBP0+hnaH2yRF/yjdUVcy5f7WKQROLfLxqzVfKMNkRV7SU4Wu1e7Eea8aJSM/LmsSAw==" Feb 17 08:16:20 volumio go-librespot[10295]: time="2026-02-17T08:16:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 08:16:20 volumio volumio[10047]: info: Starting Shairport Sync Feb 17 08:16:20 volumio volumio[10047]: info: Starting Shairport Sync Feb 17 08:16:20 volumio volumio[10047]: info: Starting Shairport Sync Feb 17 08:16:20 volumio sudo[10332]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 08:16:20 volumio sudo[10332]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:16:21 volumio go-librespot[10295]: time="2026-02-17T08:16:21+07:00" level=debug msg="completed keyexchange" Feb 17 08:16:21 volumio go-librespot[10295]: time="2026-02-17T08:16:21+07:00" level=debug msg="completed challenge" Feb 17 08:16:21 volumio sudo[10334]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 08:16:21 volumio sudo[10334]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:16:21 volumio sudo[10338]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 08:16:21 volumio sudo[10338]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:16:21 volumio go-librespot[10295]: time="2026-02-17T08:16:21+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 08:16:21 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 08:16:21 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 08:16:21 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 08:16:21 volumio systemd[1]: shairport-sync.service: Consumed 2.269s CPU time. Feb 17 08:16:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 08:16:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 08:16:21 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 08:16:21 volumio sudo[10332]: pam_unix(sudo:session): session closed for user root Feb 17 08:16:21 volumio volumio[10047]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 08:16:21 volumio volumio[10047]: SPOTIFY: BQDy_xfoDWDlkP_Sh4DMcXBXP0Eio6XjiCiSBckaElOsQqBtFuxrKF8lHQdK_Xt6gGWOWhGtveBkX4nlSD5ts8n1MdbqKKEmYcrZ_o2THxFrQU566zS0_sjXty3Xd6Urpt9ZagAAO3BTgCwWM2OUOqBno9zDanYRbOycfZggv7HW4GFaXb76VaAOD_K_mNSgRxmAisVosJnl3F1d2pgpWZAEYH35Byygj4KNXfGW36MfoCAaiH2QYM-mplaCXAkScmrsS5Mv8p0HllzZs8oPSDyUmgeYC5bOL3KMaQipyvkKpgvDaeTrYVXd Feb 17 08:16:21 volumio volumio[10047]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 08:16:21 volumio volumio[10047]: info: New Spotify access token = BQDy_xfoDWDlkP_Sh4DMcXBXP0Eio6XjiCiSBckaElOsQqBtFuxrKF8lHQdK_Xt6gGWOWhGtveBkX4nlSD5ts8n1MdbqKKEmYcrZ_o2THxFrQU566zS0_sjXty3Xd6Urpt9ZagAAO3BTgCwWM2OUOqBno9zDanYRbOycfZggv7HW4GFaXb76VaAOD_K_mNSgRxmAisVosJnl3F1d2pgpWZAEYH35Byygj4KNXfGW36MfoCAaiH2QYM-mplaCXAkScmrsS5Mv8p0HllzZs8oPSDyUmgeYC5bOL3KMaQipyvkKpgvDaeTrYVXd Feb 17 08:16:21 volumio volumio[10047]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 17 08:16:21 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 08:16:21 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 08:16:21 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 08:16:21 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 08:16:21 volumio sudo[10338]: pam_unix(sudo:session): session closed for user root Feb 17 08:16:21 volumio sudo[10334]: pam_unix(sudo:session): session closed for user root Feb 17 08:16:21 volumio volumio[10047]: info: Shairport-Sync Started Feb 17 08:16:21 volumio volumio[10047]: Error adding Membership: Error: addMembership EINVAL Feb 17 08:16:21 volumio volumio[10047]: info: Shairport-Sync Started Feb 17 08:16:21 volumio volumio[10047]: info: Shairport-Sync Started Feb 17 08:16:21 volumio volumio[10047]: info: CoreCommandRouter::volumioGetState Feb 17 08:16:21 volumio volumio[10047]: info: CorePlayQueue::getTrack 0 Feb 17 08:16:21 volumio volumio[10047]: 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 17 08:16:21 volumio volumio[10047]: info: Spotify Successfully logged in Feb 17 08:16:21 volumio volumio[10047]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 08:16:21 volumio volumio[10047]: info: [1771290981827] CoreMusicLibrary::Adding element Spotify Feb 17 08:16:21 volumio volumio[10047]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 08:16:21 volumio volumio[10047]: Cannot find translation for source YouTube Music Feb 17 08:16:21 volumio volumio[10047]: Cannot find translation for source Spotify Feb 17 08:16:22 volumio volumio[10047]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 17 08:16:22 volumio volumio[10047]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 08:16:22 volumio volumio[10047]: info: VolumeController:: Volume=100 Mute =false Feb 17 08:16:22 volumio volumio[10047]: info: CoreCommandRouter::volumioGetState Feb 17 08:16:22 volumio volumio[10047]: info: CorePlayQueue::getTrack 0 Feb 17 08:16:22 volumio volumio[10047]: info: CoreStateMachine::pushState Feb 17 08:16:22 volumio volumio[10047]: info: CorePlayQueue::getTrack 0 Feb 17 08:16:22 volumio volumio[10047]: info: CoreCommandRouter::volumioPushState Feb 17 08:16:23 volumio volumio[10047]: info: go-librespot daemon successfully initialized Feb 17 08:16:24 volumio mpd[10275]: 2026-02-17T08:16:24 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 17 08:16:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 17 08:16:24 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 17 08:16:24 volumio sudo[10246]: pam_unix(sudo:session): session closed for user root Feb 17 08:16:24 volumio sudo[10235]: pam_unix(sudo:session): session closed for user root Feb 17 08:16:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:16:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:16:24 volumio go-librespot[10375]: go-librespot daemon starting... Feb 17 08:16:24 volumio go-librespot[10378]: time="2026-02-17T08:16:24+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 08:16:24 volumio go-librespot[10378]: time="2026-02-17T08:16:24+07:00" level=debug msg="app state loaded" Feb 17 08:16:24 volumio go-librespot[10378]: time="2026-02-17T08:16:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 08:16:24 volumio volumio[10047]: error: MPD error: The expression evaluated to a falsy value: Feb 17 08:16:24 volumio volumio[10047]: assert.ok(self.idling) Feb 17 08:16:24 volumio volumio[10047]: error: The expression evaluated to a falsy value: Feb 17 08:16:24 volumio volumio[10047]: assert.ok(self.idling) Feb 17 08:16:24 volumio volumio[10047]: error: updateQueue error: null Feb 17 08:16:24 volumio volumio[10047]: info: MPD running with PID10275 Feb 17 08:16:24 volumio volumio[10047]: ,establishing connection Feb 17 08:16:24 volumio volumio[10047]: info: Completed starting Core Plugins Feb 17 08:16:24 volumio volumio[10047]: info: ------------------------------------------- Feb 17 08:16:24 volumio volumio[10047]: info: ----- MyVolumio plugins startup ---- Feb 17 08:16:24 volumio volumio[10047]: info: ------------------------------------------- Feb 17 08:16:24 volumio volumio[10047]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 17 08:16:24 volumio volumio[10047]: error: updateQueue error: null Feb 17 08:16:24 volumio go-librespot[10378]: time="2026-02-17T08:16:24+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 08:16:24 volumio go-librespot[10378]: time="2026-02-17T08:16:24+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 17 08:16:24 volumio go-librespot[10378]: time="2026-02-17T08:16:24+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 17 08:16:24 volumio go-librespot[10378]: time="2026-02-17T08:16:24+07:00" level=info msg="zeroconf server listening on port 35449" Feb 17 08:16:25 volumio go-librespot[10378]: time="2026-02-17T08:16:25+07:00" level=debug msg="obtained new client token: AADpAr9NYZu4dzgoWBktGxlT+w7k1JCv45sIyCi2CfBzG66vYwPtAK/9Sy8rp4JY0NvhTf9/YskMH4FILPsmD+uLUK6Z5IDoISzjKtb2FX867YyDGlh2i0uZbj1vmp5mzDzWn3UGEB6L/ovWgDiNjk/3eui8PyZWlD+4MYf9Gw19fU6WGGSxt2rbs0mQeCG5YwVUNf2Gm/UU70PTw1npiNGI0HBGouWyBcR9M/+ayRsSKpkctBKRcWc=" Feb 17 08:16:25 volumio go-librespot[10378]: time="2026-02-17T08:16:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 08:16:25 volumio go-librespot[10378]: time="2026-02-17T08:16:25+07:00" level=debug msg="completed keyexchange" Feb 17 08:16:25 volumio go-librespot[10378]: time="2026-02-17T08:16:25+07:00" level=debug msg="completed challenge" Feb 17 08:16:25 volumio go-librespot[10378]: time="2026-02-17T08:16:25+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 08:16:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 08:16:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 08:16:26 volumio volumio[10047]: info: Initializing connection to go-librespot Websocket Feb 17 08:16:26 volumio volumio[10047]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 08:16:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 17 08:16:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:16:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:16:28 volumio go-librespot[10385]: go-librespot daemon starting... Feb 17 08:16:28 volumio go-librespot[10386]: time="2026-02-17T08:16:28+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 08:16:28 volumio go-librespot[10386]: time="2026-02-17T08:16:28+07:00" level=debug msg="app state loaded" Feb 17 08:16:28 volumio go-librespot[10386]: time="2026-02-17T08:16:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 08:16:29 volumio go-librespot[10386]: time="2026-02-17T08:16:29+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 08:16:29 volumio go-librespot[10386]: time="2026-02-17T08:16:29+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 17 08:16:29 volumio go-librespot[10386]: time="2026-02-17T08:16:29+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 17 08:16:29 volumio go-librespot[10386]: time="2026-02-17T08:16:29+07:00" level=info msg="zeroconf server listening on port 34459" Feb 17 08:16:29 volumio volumio[10047]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 17 08:16:29 volumio go-librespot[10386]: time="2026-02-17T08:16:29+07:00" level=debug msg="obtained new client token: AADO1suhnCsr8MQmSqkA/QW6qpdUmurGMID6S28uTkIcP4uFXl/3QcbqmQVfvzowQ45DbirTW0mAGDJ5FoM4lJV0eIvRl6a3FH5nZym0P1haJWJlIOnTK55lnVqrj2Oabv9w72mJ9RSTUPgfSrB0zu1xh+cJ1tpmQxejmh4GajqFIlcdeEmeszQmDz4Xjj76MjcSfMYQizw+H7ouMIg2OSOwWMNQMF1nbT7o+ynXnoNHJwhZZ6zQcC3SeA==" Feb 17 08:16:29 volumio go-librespot[10386]: time="2026-02-17T08:16:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 08:16:29 volumio go-librespot[10386]: time="2026-02-17T08:16:29+07:00" level=debug msg="completed keyexchange" Feb 17 08:16:29 volumio go-librespot[10386]: time="2026-02-17T08:16:29+07:00" level=debug msg="completed challenge" Feb 17 08:16:29 volumio volumio[10047]: info: Initializing connection to go-librespot Websocket Feb 17 08:16:29 volumio go-librespot[10386]: time="2026-02-17T08:16:29+07:00" level=debug msg="new websocket client" Feb 17 08:16:29 volumio volumio[10047]: info: Connection to go-librespot Websocket established Feb 17 08:16:30 volumio go-librespot[10386]: time="2026-02-17T08:16:30+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 17 08:16:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 08:16:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 08:16:30 volumio volumio[10047]: info: Connection to go-librespot Websocket closed Feb 17 08:16:32 volumio volumio[10047]: info: Getting Spotify volume Feb 17 08:16:32 volumio volumio[10047]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 08:16:32 volumio volumio[10047]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 08:16:32 volumio volumio[10047]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 17 08:16:32 volumio volumio[10047]: errno: -111, Feb 17 08:16:32 volumio volumio[10047]: code: 'ECONNREFUSED', Feb 17 08:16:32 volumio volumio[10047]: syscall: 'connect', Feb 17 08:16:32 volumio volumio[10047]: address: '127.0.0.1', Feb 17 08:16:32 volumio volumio[10047]: port: 9879, Feb 17 08:16:32 volumio volumio[10047]: response: undefined Feb 17 08:16:32 volumio volumio[10047]: } Feb 17 08:16:32 volumio volumio[10047]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 08:16:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 17 08:16:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:16:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 08:16:33 volumio go-librespot[10419]: go-librespot daemon starting... Feb 17 08:16:33 volumio go-librespot[10420]: time="2026-02-17T08:16:33+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 08:16:33 volumio go-librespot[10420]: time="2026-02-17T08:16:33+07:00" level=debug msg="app state loaded" Feb 17 08:16:33 volumio go-librespot[10420]: time="2026-02-17T08:16:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 08:16:34 volumio go-librespot[10420]: time="2026-02-17T08:16: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 17 08:16:34 volumio go-librespot[10420]: time="2026-02-17T08:16: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 17 08:16:34 volumio go-librespot[10420]: time="2026-02-17T08:16: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 17 08:16:34 volumio go-librespot[10420]: time="2026-02-17T08:16:34+07:00" level=info msg="zeroconf server listening on port 35097" Feb 17 08:16:34 volumio go-librespot[10420]: time="2026-02-17T08:16:34+07:00" level=debug msg="obtained new client token: AACjwgGFzCdvKwEM12MHeM8eC0aiUVKCgjo8oQrItIQ4J9qenvZFnVVMu5f+U4Y/XNGGyDqQt7R+/Tsy3Qe255JcxGabnOhprkdYnIq0Pi1SYZaDML3swwfrdtx6S2OrQjjLeIK12KBFM34oWh38OWiYJxU4uyYEA9m8XPHrY8HsR6aQtsRUbCU4VAMDUCmkk74vjYg4DY86yggDkTameO9P4NFj8D1XPETI6ju7GpCFY16g1linzOFYUA==" Feb 17 08:16:34 volumio sudo[10429]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 08:15' Feb 17 08:16:34 volumio sudo[10429]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 08:16:34 volumio go-librespot[10420]: time="2026-02-17T08:16:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 08:16:34 volumio go-librespot[10420]: time="2026-02-17T08:16:34+07:00" level=debug msg="completed keyexchange" Feb 17 08:16:34 volumio go-librespot[10420]: time="2026-02-17T08:16:34+07:00" level=debug msg="completed challenge" 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"