Feb 07 00:57:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 07 00:57:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:57:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:57:01 volumio go-librespot[31469]: go-librespot daemon starting... Feb 07 00:57:01 volumio go-librespot[31470]: time="2026-02-07T00:57:01+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 00:57:01 volumio go-librespot[31470]: time="2026-02-07T00:57:01+07:00" level=debug msg="app state loaded" Feb 07 00:57:01 volumio go-librespot[31470]: time="2026-02-07T00:57:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 00:57:01 volumio volumio[31127]: info: Initializing connection to go-librespot Websocket Feb 07 00:57:01 volumio go-librespot[31470]: time="2026-02-07T00:57:01+07:00" level=debug msg="new websocket client" Feb 07 00:57:01 volumio volumio[31127]: info: Connection to go-librespot Websocket established Feb 07 00:57:01 volumio volumio[31127]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 07 00:57:01 volumio volumio[31127]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 07 00:57:01 volumio volumio[31127]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 07 00:57:01 volumio volumio[31127]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 07 00:57:01 volumio volumio[31127]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 07 00:57:01 volumio volumio[31127]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 07 00:57:01 volumio volumio[31127]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 07 00:57:01 volumio volumio[31127]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 07 00:57:01 volumio volumio[31127]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 07 00:57:01 volumio volumio[31127]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 07 00:57:01 volumio volumio[31127]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 07 00:57:01 volumio volumio[31127]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 07 00:57:01 volumio volumio[31127]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 07 00:57:01 volumio volumio[31127]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 07 00:57:01 volumio volumio[31127]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 07 00:57:01 volumio volumio[31127]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 07 00:57:01 volumio volumio[31127]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 07 00:57:01 volumio volumio[31127]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 07 00:57:01 volumio volumio[31127]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 07 00:57:01 volumio volumio[31127]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 07 00:57:01 volumio volumio[31127]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 07 00:57:01 volumio volumio[31127]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 07 00:57:01 volumio volumio[31127]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 07 00:57:01 volumio volumio[31127]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 07 00:57:01 volumio volumio[31127]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 07 00:57:01 volumio volumio[31127]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 07 00:57:01 volumio volumio[31127]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 07 00:57:01 volumio volumio[31127]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 07 00:57:01 volumio volumio[31127]: info: Adding plugin bluetooth to MyMusic Plugins Feb 07 00:57:01 volumio volumio[31127]: info: Adding plugin multiroom to MyMusic Plugins Feb 07 00:57:01 volumio volumio[31127]: info: Adding plugin metavolumio to MyMusic Plugins Feb 07 00:57:01 volumio volumio[31127]: info: Adding plugin cd_controller to MyMusic Plugins Feb 07 00:57:01 volumio volumio[31127]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 07 00:57:01 volumio volumio[31127]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 07 00:57:01 volumio volumio[31127]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 07 00:57:01 volumio volumio[31127]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 07 00:57:01 volumio go-librespot[31470]: time="2026-02-07T00:57: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 07 00:57:01 volumio go-librespot[31470]: time="2026-02-07T00:57: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 07 00:57:01 volumio go-librespot[31470]: time="2026-02-07T00:57: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 07 00:57:01 volumio go-librespot[31470]: time="2026-02-07T00:57:01+07:00" level=info msg="zeroconf server listening on port 43491" Feb 07 00:57:01 volumio go-librespot[31470]: time="2026-02-07T00:57:01+07:00" level=debug msg="obtained new client token: AAAW0mQ8rmF9QNg/uH4X2tjN/VhQ4kyehnipSDrDAOTuGc6qoUgUa1Gduyt3n7boPiVihH3Q8ew5Ie4Yr7DUULkOaZLosP7Kxtq5CKd5RySYkfby5ktQ9IVfRiH+nP5GUHG6U5ozwFMqt0OFMd73x9nUmlUf7adHTD6LszkAaK6yn6EBEPAcdDZ8mXDULKCRl/jr72eg69RFXMrhpPHAe4alA2QwVMjFeG1cocBmr0Xz6Op457gvfZw6Jg==" Feb 07 00:57:02 volumio go-librespot[31470]: time="2026-02-07T00:57:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 00:57:02 volumio go-librespot[31470]: time="2026-02-07T00:57:02+07:00" level=debug msg="completed keyexchange" Feb 07 00:57:02 volumio go-librespot[31470]: time="2026-02-07T00:57:02+07:00" level=debug msg="completed challenge" Feb 07 00:57:02 volumio go-librespot[31470]: time="2026-02-07T00:57: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 07 00:57:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 00:57:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 00:57:03 volumio volumio[31127]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 07 00:57:03 volumio volumio[31127]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 07 00:57:03 volumio volumio[31127]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 00:57:03 volumio volumio[31127]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 00:57:03 volumio volumio[31127]: info: Starting MyVolumio Remote Streaming Endpoints Feb 07 00:57:03 volumio volumio[31127]: info: MyVolumio login type: Token Feb 07 00:57:03 volumio volumio[31127]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 07 00:57:03 volumio volumio[31127]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 07 00:57:05 volumio volumio[31127]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 07 00:57:05 volumio volumio[31127]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 07 00:57:05 volumio volumio[31127]: info: Streaming services startup Feb 07 00:57:05 volumio volumio[31127]: info: Starting Streaming Daemon Feb 07 00:57:05 volumio sudo[31493]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 07 00:57:05 volumio sudo[31493]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:57:05 volumio volumio[31127]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 07 00:57:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 07 00:57:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:57:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:57:05 volumio go-librespot[31499]: go-librespot daemon starting... Feb 07 00:57:05 volumio sudo[31493]: pam_unix(sudo:session): session closed for user root Feb 07 00:57:05 volumio go-librespot[31500]: time="2026-02-07T00:57:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 00:57:05 volumio go-librespot[31500]: time="2026-02-07T00:57:05+07:00" level=debug msg="app state loaded" Feb 07 00:57:05 volumio go-librespot[31500]: time="2026-02-07T00:57:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 00:57:05 volumio volumio[31127]: info: Getting Spotify volume Feb 07 00:57:05 volumio volumio[31127]: info: Connection to go-librespot Websocket closed Feb 07 00:57:05 volumio volumio[31127]: error: Cannot start Volumio Streaming Daemon Feb 07 00:57:05 volumio volumio[31127]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 07 00:57:05 volumio volumio[31127]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 07 00:57:05 volumio volumio[31127]: 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 07 00:57:05 volumio volumio[31127]: info: CoreCommandRouter::volumioGetState Feb 07 00:57:05 volumio volumio[31127]: info: CorePlayQueue::getTrack 0 Feb 07 00:57:05 volumio volumio[31127]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 07 00:57:05 volumio volumio[31127]: SPOTIFY: SPOTIFY VOLUME undefined Feb 07 00:57:05 volumio volumio[31127]: SPOTIFY: VOLUMIO VOLUME 100 Feb 07 00:57:05 volumio volumio[31127]: info: Aligning Spotify Volume to Volumio Volume Feb 07 00:57:05 volumio volumio[31127]: info: CoreCommandRouter::volumioGetState Feb 07 00:57:05 volumio volumio[31127]: info: CorePlayQueue::getTrack 0 Feb 07 00:57:05 volumio volumio[31127]: info: Setting Spotify Volume from Volumio: 100 Feb 07 00:57:05 volumio go-librespot[31500]: time="2026-02-07T00:57: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 07 00:57:05 volumio go-librespot[31500]: time="2026-02-07T00:57: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 07 00:57:05 volumio go-librespot[31500]: time="2026-02-07T00:57: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 07 00:57:05 volumio go-librespot[31500]: time="2026-02-07T00:57:05+07:00" level=info msg="zeroconf server listening on port 34495" Feb 07 00:57:06 volumio go-librespot[31500]: time="2026-02-07T00:57:06+07:00" level=debug msg="obtained new client token: AAAcX50xHsCQGaPA4Du8ntsqes7OPu8k0RwopP0sCa4rzrfU8v8ErGlwyqWf0NDctLuuP5mNehorOSwkfMhSeRXyTf7SjhowgsCbJc94iSoHDp4vol7sxA9jUIchi0uF8EODWkeRHAPIduB8PN5oPyLLw0UKIus1UrcS/J7HVEbPXr9/NALxxNnm3g5o3tnCAl3dFIhQ54hFM+qIkLXtV66fEr+uPBvGZwt7M5rHPyXTvRDGh46hXk0=" Feb 07 00:57:06 volumio go-librespot[31500]: time="2026-02-07T00:57:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 00:57:06 volumio go-librespot[31500]: time="2026-02-07T00:57:06+07:00" level=debug msg="completed keyexchange" Feb 07 00:57:06 volumio go-librespot[31500]: time="2026-02-07T00:57:06+07:00" level=debug msg="completed challenge" Feb 07 00:57:06 volumio volumio[31127]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 07 00:57:06 volumio go-librespot[31500]: time="2026-02-07T00:57: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 07 00:57:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 00:57:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 00:57:06 volumio volumio[31127]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 00:57:06 volumio volumio[31127]: Error: socket hang up Feb 07 00:57:06 volumio volumio[31127]: at connResetException (node:internal/errors:720:14) Feb 07 00:57:06 volumio volumio[31127]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 07 00:57:06 volumio volumio[31127]: at Socket.emit (node:events:526:35) Feb 07 00:57:06 volumio volumio[31127]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 07 00:57:06 volumio volumio[31127]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 07 00:57:06 volumio volumio[31127]: code: 'ECONNRESET', Feb 07 00:57:06 volumio volumio[31127]: response: undefined Feb 07 00:57:06 volumio volumio[31127]: } Feb 07 00:57:06 volumio volumio[31127]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 00:57:07 volumio sudo[31521]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 00:56' Feb 07 00:57:07 volumio sudo[31521]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:57:08 volumio sudo[31521]: pam_unix(sudo:session): session closed for user root Feb 07 00:57:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 07 00:57:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:57:09 volumio volumio-remote-updater[643]: [2026-02-07 00:57:09] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Feb 07 00:57:09 volumio volumio-remote-updater[643]: [2026-02-07 00:57:09] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Feb 07 00:57:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:57:09 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 07 00:57:09 volumio go-librespot[31529]: go-librespot daemon starting... Feb 07 00:57:09 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 07 00:57:09 volumio systemd[1]: volumio.service: Consumed 55.939s CPU time. Feb 07 00:57:09 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 00:57:09 volumio go-librespot[31530]: time="2026-02-07T00:57:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 00:57:09 volumio go-librespot[31530]: time="2026-02-07T00:57:09+07:00" level=debug msg="app state loaded" Feb 07 00:57:09 volumio go-librespot[31530]: time="2026-02-07T00:57:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 00:57:09 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 00:57:09 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 5042. Feb 07 00:57:09 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 00:57:09 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 07 00:57:09 volumio systemd[1]: volumio.service: Consumed 55.939s CPU time. Feb 07 00:57:09 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 07 00:57:09 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 00:57:10 volumio go-librespot[31530]: time="2026-02-07T00:57:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 00:57:10 volumio go-librespot[31530]: time="2026-02-07T00:57:10+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 00:57:10 volumio go-librespot[31530]: time="2026-02-07T00:57:10+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 00:57:10 volumio go-librespot[31530]: time="2026-02-07T00:57:10+07:00" level=info msg="zeroconf server listening on port 46067" Feb 07 00:57:10 volumio go-librespot[31530]: time="2026-02-07T00:57:10+07:00" level=debug msg="obtained new client token: AADif82RNZJeaksNH5kP82nAryUm8BZGeM1lIw91ZgOmy8TTYSqejmh6Izk6SV1f6G1xL6jKYxZJqxd51FacBj/ytRcew32JQXuqYtfNaKTk/mawVTcCYz27Wm5zq15mjNT1E6z+kLKFZlyBmHQA32n+6cjTrFceseTPvoO7rzAtBY6zvvHkt//ImfxrPuLmggl+Ch/Z1xrRpdJEhuHLBtcXRmOyNFJVKmxB6AADrlavwO+LeWG6VnMK5w==" Feb 07 00:57:10 volumio go-librespot[31530]: time="2026-02-07T00:57:10+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 07 00:57:10 volumio go-librespot[31530]: time="2026-02-07T00:57:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 07 00:57:10 volumio go-librespot[31530]: time="2026-02-07T00:57:10+07:00" level=debug msg="completed keyexchange" Feb 07 00:57:10 volumio go-librespot[31530]: time="2026-02-07T00:57:10+07:00" level=debug msg="completed challenge" Feb 07 00:57:10 volumio go-librespot[31530]: time="2026-02-07T00:57: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 07 00:57:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 00:57:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 00:57:12 volumio nmbd[966]: [2026/02/07 00:57:12.069581, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Feb 07 00:57:12 volumio nmbd[966]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.1.23 for name WORKGROUP<1d>. Feb 07 00:57:12 volumio nmbd[966]: This response was from IP 192.168.1.237, reporting an IP address of 192.168.1.237. Feb 07 00:57:13 volumio volumio[31548]: info: ------------------------------------------- Feb 07 00:57:13 volumio volumio[31548]: info: ----- Volumio3 ---- Feb 07 00:57:13 volumio volumio[31548]: info: ------------------------------------------- Feb 07 00:57:13 volumio volumio[31548]: info: ----- System startup ---- Feb 07 00:57:13 volumio volumio[31548]: info: ------------------------------------------- Feb 07 00:57:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 07 00:57:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:57:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:57:14 volumio go-librespot[31574]: go-librespot daemon starting... Feb 07 00:57:14 volumio go-librespot[31575]: time="2026-02-07T00:57:14+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 00:57:14 volumio go-librespot[31575]: time="2026-02-07T00:57:14+07:00" level=debug msg="app state loaded" Feb 07 00:57:14 volumio go-librespot[31575]: time="2026-02-07T00:57:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 00:57:14 volumio volumio-remote-updater[643]: [2026-02-07 00:57:14] [connect] Successful connection Feb 07 00:57:14 volumio go-librespot[31575]: time="2026-02-07T00:57:14+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 00:57:14 volumio go-librespot[31575]: time="2026-02-07T00:57:14+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 00:57:14 volumio go-librespot[31575]: time="2026-02-07T00:57:14+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 00:57:14 volumio go-librespot[31575]: time="2026-02-07T00:57:14+07:00" level=info msg="zeroconf server listening on port 33297" Feb 07 00:57:14 volumio volumio[31548]: info: MYVOLUMIO Environment detected Feb 07 00:57:15 volumio go-librespot[31575]: time="2026-02-07T00:57:15+07:00" level=debug msg="obtained new client token: AADX0BH/NsmVVNcFMFv2mmkDzScqnM8aDhuOtQjeMuvJ7Qp+hXuROP7pv4why8mds0jSgrM90rXUcLdxL2KRHMPgo12Du3K2ITzT9RSK0GwQd4Oml11ob3TR9KS4NQ3aBkbLq8pSuxmqsK4wWmScNgaZOO9hl7wEKtvcjTK1lzKXeYubI6tM4ssT1adVwh0zT2fU3aEU/Z2D571dXw/53HMyEyGuF6ihtIrcTsoDAXdKmir/IY7rQ2jnOQ==" Feb 07 00:57:15 volumio volumio[31548]: info: Plugin folders cleanup Feb 07 00:57:15 volumio volumio[31548]: info: Scanning into folder /volumio/app/plugins/ Feb 07 00:57:15 volumio volumio[31548]: info: Scanning category audio_interface Feb 07 00:57:15 volumio volumio[31548]: info: Scanning category miscellanea Feb 07 00:57:15 volumio volumio[31548]: info: Scanning category music_service Feb 07 00:57:15 volumio volumio[31548]: info: Scanning category plugins.json Feb 07 00:57:15 volumio volumio[31548]: info: Scanning category system_controller Feb 07 00:57:15 volumio volumio[31548]: info: Scanning category user_interface Feb 07 00:57:15 volumio volumio[31548]: info: Scanning into folder /data/plugins/ Feb 07 00:57:15 volumio volumio[31548]: info: Scanning category music_service Feb 07 00:57:15 volumio volumio[31548]: info: Plugin folders cleanup completed Feb 07 00:57:15 volumio volumio[31548]: info: ------------------------------------------- Feb 07 00:57:15 volumio volumio[31548]: info: ----- Core plugins startup ---- Feb 07 00:57:15 volumio volumio[31548]: info: ------------------------------------------- Feb 07 00:57:15 volumio volumio[31548]: info: Loading plugins from folder /volumio/app/plugins/ Feb 07 00:57:15 volumio volumio[31548]: info: Adding plugin upnp to MyMusic Plugins Feb 07 00:57:15 volumio go-librespot[31575]: time="2026-02-07T00:57:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 00:57:15 volumio volumio[31548]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 07 00:57:15 volumio volumio[31548]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 07 00:57:15 volumio volumio[31548]: info: Loading plugins from folder /data/plugins/ Feb 07 00:57:15 volumio volumio[31548]: info: Loading plugin "system"... Feb 07 00:57:15 volumio volumio[31548]: info: Loading plugin "appearance"... Feb 07 00:57:15 volumio go-librespot[31575]: time="2026-02-07T00:57:15+07:00" level=debug msg="completed keyexchange" Feb 07 00:57:15 volumio go-librespot[31575]: time="2026-02-07T00:57:15+07:00" level=debug msg="completed challenge" Feb 07 00:57:15 volumio go-librespot[31575]: time="2026-02-07T00:57: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 07 00:57:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 00:57:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 00:57:17 volumio volumio[31548]: info: Loading plugin "network"... Feb 07 00:57:17 volumio volumio[31548]: info: Refreshing Cached IP Addresses Feb 07 00:57:17 volumio sudo[31590]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 00:57:17 volumio sudo[31590]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:57:17 volumio sudo[31592]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 00:57:17 volumio sudo[31590]: pam_unix(sudo:session): session closed for user root Feb 07 00:57:17 volumio sudo[31592]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:57:17 volumio volumio[31548]: info: Loading plugin "services"... Feb 07 00:57:17 volumio volumio[31548]: info: Loading plugin "alsa_controller"... Feb 07 00:57:17 volumio sudo[31592]: pam_unix(sudo:session): session closed for user root Feb 07 00:57:17 volumio sudo[31605]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 07 00:57:17 volumio sudo[31605]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:57:17 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 00:57:17 volumio volumio[31548]: info: Loading plugin "wizard"... Feb 07 00:57:17 volumio volumio[31548]: info: Loading plugin "networkfs"... Feb 07 00:57:17 volumio volumio[31548]: info: Starting Udev Watcher for removable devices Feb 07 00:57:17 volumio volumio[31548]: info: Ignoring mount for partition: boot Feb 07 00:57:17 volumio volumio[31548]: info: Ignoring mount for partition: volumio Feb 07 00:57:17 volumio volumio[31548]: info: Ignoring mount for partition: volumio_data Feb 07 00:57:17 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 00:57:17 volumio volumio[31548]: info: Loading plugin "volumio_command_line_client"... Feb 07 00:57:17 volumio volumio[31548]: info: Loading plugin "upnp"... Feb 07 00:57:17 volumio volumio[31548]: info: [1770400637473] Starting Upmpd Daemon Feb 07 00:57:17 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 00:57:17 volumio volumio[31548]: info: Loading plugin "my_music"... Feb 07 00:57:17 volumio volumio[31548]: info: Loading plugin "mpd"... Feb 07 00:57:18 volumio volumio[31548]: info: Loading plugin "upnp_browser"... Feb 07 00:57:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 07 00:57:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:57:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:57:18 volumio go-librespot[31623]: go-librespot daemon starting... Feb 07 00:57:18 volumio go-librespot[31624]: time="2026-02-07T00:57:18+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 00:57:18 volumio go-librespot[31624]: time="2026-02-07T00:57:18+07:00" level=debug msg="app state loaded" Feb 07 00:57:18 volumio go-librespot[31624]: time="2026-02-07T00:57:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 00:57:18 volumio go-librespot[31624]: time="2026-02-07T00:57:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 00:57:18 volumio go-librespot[31624]: time="2026-02-07T00:57:18+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 00:57:18 volumio go-librespot[31624]: time="2026-02-07T00:57:18+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 00:57:18 volumio go-librespot[31624]: time="2026-02-07T00:57:18+07:00" level=info msg="zeroconf server listening on port 41497" Feb 07 00:57:19 volumio go-librespot[31624]: time="2026-02-07T00:57:19+07:00" level=debug msg="obtained new client token: AACRM/8ipnDUxO0LptfGTHI5npa8JWuiFP7/S3r9MNG9yp2wVEAQtpXMvEbfSXdhLbNQMIHaB7YGcC3sQ5UnVNH0DEM4IzI13QBG7LSWUnzplUSvw4IeYgCfPuxt6qAP19IiQobX0YoTiJtVu7z/e0rlw7+9jVlOC93YvQYj4JFPy8FYppMaJw/2hs/sKzUS2rmfIoHbZS/sFX8b9lNHUdWUc2/wXRq3f7NHpbumwgBV7NoDh+QZ2Ls=" Feb 07 00:57:19 volumio go-librespot[31624]: time="2026-02-07T00:57:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 00:57:19 volumio go-librespot[31624]: time="2026-02-07T00:57:19+07:00" level=debug msg="completed keyexchange" Feb 07 00:57:19 volumio go-librespot[31624]: time="2026-02-07T00:57:19+07:00" level=debug msg="completed challenge" Feb 07 00:57:19 volumio go-librespot[31624]: time="2026-02-07T00:57:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 07 00:57:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 00:57:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 00:57:20 volumio sudo[31605]: pam_unix(sudo:session): session closed for user root Feb 07 00:57:21 volumio volumio[31548]: info: Starting UPNP Browser Feb 07 00:57:21 volumio volumio[31548]: info: Loading plugin "alarm-clock"... Feb 07 00:57:21 volumio volumio[31548]: info: Loading plugin "airplay_emulation"... Feb 07 00:57:21 volumio volumio[31548]: info: Starting Shairport Sync Feb 07 00:57:21 volumio volumio[31548]: info: Loading plugin "last_100"... Feb 07 00:57:21 volumio volumio[31548]: info: Loading plugin "webradio"... Feb 07 00:57:21 volumio volumio[31548]: info: Loading plugin "i2s_dacs"... Feb 07 00:57:21 volumio volumio[31548]: info: Loading plugin "volumiodiscovery"... Feb 07 00:57:21 volumio volumio[31548]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 00:57:21 volumio volumio[31548]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 00:57:21 volumio node[31548]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 00:57:21 volumio volumio[31548]: *** WARNING *** For more information see Feb 07 00:57:21 volumio volumio[31548]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 00:57:21 volumio volumio[31548]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 00:57:21 volumio volumio[31548]: *** WARNING *** For more information see Feb 07 00:57:21 volumio node[31548]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 00:57:21 volumio node[31548]: *** WARNING *** For more information see Feb 07 00:57:21 volumio node[31548]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 00:57:21 volumio node[31548]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 00:57:21 volumio node[31548]: *** WARNING *** For more information see Feb 07 00:57:21 volumio volumio[31548]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 07 00:57:21 volumio volumio[31548]: info: Discovery: Started advertising with name: Volumio Feb 07 00:57:21 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 00:57:21 volumio volumio[31548]: info: Loading plugin "spop"... Feb 07 00:57:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 07 00:57:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:57:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:57:22 volumio go-librespot[31634]: go-librespot daemon starting... Feb 07 00:57:22 volumio go-librespot[31635]: time="2026-02-07T00:57:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 00:57:22 volumio go-librespot[31635]: time="2026-02-07T00:57:22+07:00" level=debug msg="app state loaded" Feb 07 00:57:22 volumio go-librespot[31635]: time="2026-02-07T00:57:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 00:57:23 volumio go-librespot[31635]: time="2026-02-07T00:57:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 00:57:23 volumio go-librespot[31635]: time="2026-02-07T00:57:23+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 07 00:57:23 volumio go-librespot[31635]: time="2026-02-07T00:57:23+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 07 00:57:23 volumio go-librespot[31635]: time="2026-02-07T00:57:23+07:00" level=info msg="zeroconf server listening on port 35195" Feb 07 00:57:23 volumio go-librespot[31635]: time="2026-02-07T00:57:23+07:00" level=debug msg="obtained new client token: AAC1zmpYxHmh1NLesdIhf17wkg8hds4fxP1b3GLTHiKAiIFkAtufZVbEh01LbaNL0ZjCdpd1od8zIBYvdeiRwg1DtHdADZQ239+pmtFqTgMz8pqt7TsoyL++NoRSwLfu8+ykV0cioWl4+2QGkfYT3ckOySj1afuSxB7ZP/2p8CG08hrPLWqn0quhSEkM1qC0INoc5O0LFLg0dUQjUxtLWwLRrSI1wvcf0WUIr/IFHOvJSUpE25lUqgiTow==" Feb 07 00:57:23 volumio go-librespot[31635]: time="2026-02-07T00:57:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 00:57:23 volumio volumio[31548]: info: Loading plugin "ytcr"... Feb 07 00:57:23 volumio go-librespot[31635]: time="2026-02-07T00:57:23+07:00" level=debug msg="completed keyexchange" Feb 07 00:57:23 volumio go-librespot[31635]: time="2026-02-07T00:57:23+07:00" level=debug msg="completed challenge" Feb 07 00:57:23 volumio go-librespot[31635]: time="2026-02-07T00:57:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 07 00:57:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 00:57:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 00:57:26 volumio volumio[31548]: info: Loading plugin "ytmusic"... Feb 07 00:57:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 07 00:57:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:57:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:57:26 volumio go-librespot[31642]: go-librespot daemon starting... Feb 07 00:57:26 volumio go-librespot[31643]: time="2026-02-07T00:57:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 00:57:26 volumio go-librespot[31643]: time="2026-02-07T00:57:26+07:00" level=debug msg="app state loaded" Feb 07 00:57:26 volumio go-librespot[31643]: time="2026-02-07T00:57:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 00:57:27 volumio volumio-remote-updater[643]: [2026-02-07 00:57:27] [connect] Successful connection Feb 07 00:57:27 volumio go-librespot[31643]: time="2026-02-07T00:57:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 07 00:57:27 volumio go-librespot[31643]: time="2026-02-07T00:57:27+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 07 00:57:27 volumio go-librespot[31643]: time="2026-02-07T00:57:27+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 07 00:57:27 volumio volumio[31548]: info: Loading plugin "outputs"... Feb 07 00:57:27 volumio volumio[31548]: info: Loading plugin "albumart"... Feb 07 00:57:27 volumio go-librespot[31643]: time="2026-02-07T00:57:27+07:00" level=info msg="zeroconf server listening on port 39705" Feb 07 00:57:27 volumio volumio[31548]: info: Plugin example_plugin is not enabled Feb 07 00:57:27 volumio volumio[31548]: info: Loading plugin "inputs"... Feb 07 00:57:27 volumio volumio[31548]: info: Loading plugin "updater_comm"... Feb 07 00:57:27 volumio volumio[31548]: info: Plugin mpdemulation is not enabled Feb 07 00:57:27 volumio volumio[31548]: info: Loading plugin "rest_api"... Feb 07 00:57:27 volumio go-librespot[31643]: time="2026-02-07T00:57:27+07:00" level=debug msg="obtained new client token: AADguWi9iIBIquTYsy16C2qg3AvsBSDBNc8FNMw5Rko11cbGEZsjHYxvkdPSOVyVi7DaJd3i4UjRFqMOkXt+hC3UXcO51oOua/1MnW7grfhnMj4aD12Y1mrQYre9yWz4rmmU4s1T4fKuQjbJyy+Fku1r2Te0t8Jwh8osOB6bFV/OXccgxCJrX+E+45rCsfXtY2dztS4hM09QCcBW0+A5eCSlyATErEXJkSvjMN5uOP74nRr3h9ptPF/S+Q==" Feb 07 00:57:27 volumio volumio[31548]: info: Loading plugin "websocket"... Feb 07 00:57:27 volumio go-librespot[31643]: time="2026-02-07T00:57:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 00:57:27 volumio volumio[31548]: info: Starting Socket.io Server version 1.7.4 Feb 07 00:57:27 volumio volumio[31548]: info: Loading plugin "RoonBridge"... Feb 07 00:57:27 volumio go-librespot[31643]: time="2026-02-07T00:57:27+07:00" level=debug msg="completed keyexchange" Feb 07 00:57:27 volumio go-librespot[31643]: time="2026-02-07T00:57:27+07:00" level=debug msg="completed challenge" Feb 07 00:57:28 volumio go-librespot[31643]: time="2026-02-07T00:57:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 07 00:57:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 00:57:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 00:57:28 volumio volumio[31548]: info: Applying required configuration parameters for plugin RoonBridge Feb 07 00:57:28 volumio volumio[31548]: info: Loading i18n strings for locale en Feb 07 00:57:28 volumio volumio[31548]: Updating browse sources language Feb 07 00:57:28 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 00:57:28 volumio volumio[31664]: Forking 3 albumart workers Feb 07 00:57:28 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 00:57:28 volumio volumio[31548]: info: CoreCommandRouter::initPlayerControls Feb 07 00:57:28 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:57:28 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:57:28 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:57:28 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:57:28 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:57:28 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:57:28 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:57:28 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:57:28 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 00:57:28 volumio volumio[31548]: Express server listening on port 3000 Feb 07 00:57:28 volumio volumio[31548]: [Metrics] WebUI: 16s 167.28ms Feb 07 00:57:28 volumio volumio[31548]: info: CoreStateMachine::resetVolumioState Feb 07 00:57:28 volumio volumio[31548]: info: CoreStateMachine::getcurrentVolume Feb 07 00:57:28 volumio volumio[31548]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 00:57:28 volumio sudo[31698]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 00:57:28 volumio sudo[31698]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:57:28 volumio sudo[31708]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 00:57:28 volumio sudo[31708]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:57:28 volumio sudo[31698]: pam_unix(sudo:session): session closed for user root Feb 07 00:57:29 volumio sudo[31708]: pam_unix(sudo:session): session closed for user root Feb 07 00:57:29 volumio volumio[31548]: info: Volumio Network Manager: Network status updated: 1 Feb 07 00:57:29 volumio volumio[31548]: info: VolumeController:: Volume=100 Mute =false Feb 07 00:57:29 volumio volumio[31548]: info: CoreStateMachine::pushState Feb 07 00:57:29 volumio volumio[31548]: info: CorePlayQueue::getTrack 0 Feb 07 00:57:29 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 00:57:29 volumio volumio[31548]: info: CoreCommandRouter::volumioPushState Feb 07 00:57:29 volumio volumio[31548]: info: CoreStateMachine::updateTrackBlock Feb 07 00:57:29 volumio volumio[31548]: info: CorePlayQueue::getTrackBlock Feb 07 00:57:29 volumio volumio[31548]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 00:57:29 volumio volumio-remote-updater[643]: [2026-02-07 00:57:29] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770400647 101 Feb 07 00:57:29 volumio volumio[31548]: 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 07 00:57:29 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 00:57:29 volumio volumio[31548]: info: Reloading queue from file Feb 07 00:57:29 volumio volumio[31548]: info: CoreStateMachine::setRepeat null single undefined Feb 07 00:57:29 volumio volumio[31548]: info: CoreStateMachine::pushState Feb 07 00:57:29 volumio volumio[31548]: info: CorePlayQueue::getTrack 0 Feb 07 00:57:29 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 00:57:29 volumio volumio[31548]: info: CoreCommandRouter::volumioPushState Feb 07 00:57:29 volumio volumio[31548]: info: CoreStateMachine::setRandom null Feb 07 00:57:29 volumio volumio[31548]: info: CoreStateMachine::pushState Feb 07 00:57:29 volumio volumio[31548]: info: CorePlayQueue::getTrack 0 Feb 07 00:57:29 volumio volumio[31548]: info: CoreCommandRouter::volumioPushState Feb 07 00:57:29 volumio volumio[31548]: info: Setting Device type: Raspberry PI Feb 07 00:57:29 volumio volumio[31548]: info: Completed loading Core Plugins Feb 07 00:57:29 volumio volumio[31548]: info: Preparing to generate the ALSA configuration file Feb 07 00:57:29 volumio volumio[31548]: info: VolumeController:: Volume=100 Mute =false Feb 07 00:57:29 volumio volumio[31548]: info: CoreStateMachine::pushState Feb 07 00:57:29 volumio volumio[31548]: info: CorePlayQueue::getTrack 0 Feb 07 00:57:29 volumio volumio[31548]: info: CoreCommandRouter::volumioPushState Feb 07 00:57:29 volumio volumio[31548]: info: Asound.conf file unchanged, so no further update is needed Feb 07 00:57:29 volumio volumio[31548]: info: Output device has changed, restarting MPD Feb 07 00:57:29 volumio volumio[31548]: info: Output device has changed, restarting Shairport Sync Feb 07 00:57:29 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:57:29 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 00:57:29 volumio sudo[31725]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 07 00:57:29 volumio sudo[31727]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 00:57:29 volumio sudo[31727]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:57:29 volumio sudo[31725]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:57:29 volumio sudo[31727]: pam_unix(sudo:session): session closed for user root Feb 07 00:57:29 volumio sudo[31729]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 00:57:29 volumio sudo[31729]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:57:29 volumio volumio[31548]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 00:57:29 volumio volumio[31548]: info: ___________ START PLUGINS ___________ Feb 07 00:57:30 volumio volumio[31548]: info: ControllerMpd::onStart: Initializing MPD Feb 07 00:57:30 volumio volumio[31548]: info: Creating MPD Configuration file Feb 07 00:57:30 volumio sudo[31725]: pam_unix(sudo:session): session closed for user root Feb 07 00:57:30 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 07 00:57:30 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 00:57:30 volumio volumio[31548]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 00:57:30 volumio volumio[31548]: info: [1770400650136] CoreMusicLibrary::Adding element Media Servers Feb 07 00:57:30 volumio sudo[31740]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 00:57:30 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 00:57:30 volumio sudo[31740]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:57:30 volumio sudo[31738]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 00:57:30 volumio sudo[31738]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:57:30 volumio sudo[31738]: pam_unix(sudo:session): session closed for user root Feb 07 00:57:30 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 07 00:57:30 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 00:57:30 volumio systemd[1]: mpd.service: Consumed 7.269s CPU time. Feb 07 00:57:30 volumio volumio[31548]: info: UPNP Browser: Client initialized successfully Feb 07 00:57:30 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 07 00:57:30 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 00:57:30 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 00:57:30 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:57:30 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 00:57:30 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 00:57:30 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 00:57:30 volumio volumio[31548]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 00:57:30 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 07 00:57:30 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 00:57:30 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:57:30 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 00:57:30 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 07 00:57:30 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 00:57:30 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 00:57:30 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 00:57:30 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 00:57:30 volumio volumio[31548]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 00:57:30 volumio volumio[31548]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 00:57:30 volumio volumio[31548]: info: [1770400650573] CoreMusicLibrary::Adding element Last_100 Feb 07 00:57:30 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 00:57:30 volumio volumio[31548]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 00:57:30 volumio volumio[31548]: info: [1770400650594] CoreMusicLibrary::Adding element Webradio Feb 07 00:57:30 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 00:57:30 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 00:57:30 volumio volumio[31548]: info: Initializing BBC Radios Feb 07 00:57:30 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 00:57:30 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 00:57:30 volumio volumio[31548]: info: Creating Spotify config file Feb 07 00:57:30 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:57:31 volumio sudo[31754]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 07 00:57:31 volumio sudo[31754]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 07 00:57:31 volumio sudo[31754]: pam_unix(sudo:session): session closed for user root Feb 07 00:57:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 07 00:57:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:57:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:57:31 volumio go-librespot[31770]: go-librespot daemon starting... Feb 07 00:57:31 volumio go-librespot[31771]: time="2026-02-07T00:57:31+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 00:57:31 volumio volumio[31676]: Starting albumart workers Feb 07 00:57:32 volumio go-librespot[31771]: time="2026-02-07T00:57:32+07:00" level=info msg="zeroconf server listening on port 43385" Feb 07 00:57:32 volumio volumio[31675]: Starting albumart workers Feb 07 00:57:32 volumio volumio[31674]: Starting albumart workers Feb 07 00:57:32 volumio volumio[31548]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 00:57:32 volumio volumio[31548]: info: [1770400652693] CoreMusicLibrary::Adding element YouTube Music Feb 07 00:57:32 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 00:57:32 volumio volumio[31548]: Cannot find translation for source YouTube Music Feb 07 00:57:32 volumio volumio[31548]: info: Volumio Calling Home Feb 07 00:57:32 volumio sudo[31779]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 07 00:57:32 volumio sudo[31779]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:57:33 volumio sudo[31779]: pam_unix(sudo:session): session closed for user root Feb 07 00:57:33 volumio volumio[31548]: info: MPD Permissions set Feb 07 00:57:33 volumio volumio[31548]: info: MPD Permissions set Feb 07 00:57:33 volumio volumio[31548]: info: Upmpdcli Daemon Started Feb 07 00:57:33 volumio volumio[31548]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 07 00:57:33 volumio volumio[31548]: info: Discovery: Found device Volumio Feb 07 00:57:33 volumio volumio[31548]: info: CoreCommandRouter::volumioGetState Feb 07 00:57:33 volumio volumio[31548]: info: CorePlayQueue::getTrack 0 Feb 07 00:57:33 volumio volumio[31548]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 07 00:57:33 volumio volumio[31548]: info: Discovery: Found device Volumio Feb 07 00:57:33 volumio volumio[31548]: info: CoreCommandRouter::volumioGetState Feb 07 00:57:33 volumio volumio[31548]: info: CorePlayQueue::getTrack 0 Feb 07 00:57:33 volumio volumio[31548]: info: Volumio called home Feb 07 00:57:33 volumio volumio[31548]: info: Spotify config file written Feb 07 00:57:33 volumio volumio[31548]: 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 07 00:57:33 volumio sudo[31797]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 07 00:57:33 volumio sudo[31797]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:57:34 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 07 00:57:34 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 07 00:57:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:57:34 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:57:34 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:57:34 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:57:34 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:57:34 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:57:34 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:57:34 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:57:34 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:57:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:57:34 volumio go-librespot[31799]: go-librespot daemon starting... Feb 07 00:57:34 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 00:57:34 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:57:34 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:57:34 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:57:34 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:57:34 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:57:34 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:57:34 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:57:34 volumio sudo[31797]: pam_unix(sudo:session): session closed for user root Feb 07 00:57:34 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:57:34 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:57:34 volumio go-librespot[31807]: time="2026-02-07T00:57:34+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 00:57:34 volumio go-librespot[31807]: time="2026-02-07T00:57:34+07:00" level=debug msg="app state loaded" Feb 07 00:57:34 volumio go-librespot[31807]: time="2026-02-07T00:57:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 00:57:34 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 00:57:34 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:57:34 volumio volumio[31548]: info: No need to fix Spotify hosts Feb 07 00:57:34 volumio go-librespot[31807]: time="2026-02-07T00:57: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-gew1.spotify.com:80]" Feb 07 00:57:34 volumio go-librespot[31807]: time="2026-02-07T00:57:34+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 07 00:57:34 volumio go-librespot[31807]: time="2026-02-07T00:57:34+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 07 00:57:34 volumio go-librespot[31807]: time="2026-02-07T00:57:34+07:00" level=info msg="zeroconf server listening on port 33721" Feb 07 00:57:35 volumio volumio[31548]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 07 00:57:35 volumio volumio[31548]: SPOTIFY: BQAUvHqWtU168mL7xy4jHv51BBzJ5QM_k6oLpxodaAqwz45IDJxU9eVoahHehi-F4BvInZo_c4eFpTV7uqmIPjiGOS9HEG1EMQ9SNWsgz7o3sr0cruGLcPa7h6UIoXH4IQFn3JHKinQl437bSEwrJEYH9FWbT1uTmJR9K09RZfG6L27r7DzyYlgEON91vJVf9ec5HqKIGEbzKxeZWTQoVyMseTHAulUUJzNohK6P2a2bjHRgvlj5tLUlJf_QwVcAMMyG1gxmgXKsS2YNcGrx1IRiTq3gE_RyItCkejpwXoVoeh6kp5kRJokf Feb 07 00:57:35 volumio volumio[31548]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 07 00:57:35 volumio volumio[31548]: info: New Spotify access token = BQAUvHqWtU168mL7xy4jHv51BBzJ5QM_k6oLpxodaAqwz45IDJxU9eVoahHehi-F4BvInZo_c4eFpTV7uqmIPjiGOS9HEG1EMQ9SNWsgz7o3sr0cruGLcPa7h6UIoXH4IQFn3JHKinQl437bSEwrJEYH9FWbT1uTmJR9K09RZfG6L27r7DzyYlgEON91vJVf9ec5HqKIGEbzKxeZWTQoVyMseTHAulUUJzNohK6P2a2bjHRgvlj5tLUlJf_QwVcAMMyG1gxmgXKsS2YNcGrx1IRiTq3gE_RyItCkejpwXoVoeh6kp5kRJokf Feb 07 00:57:35 volumio volumio[31548]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 07 00:57:35 volumio volumio[31548]: info: Starting Shairport Sync Feb 07 00:57:35 volumio go-librespot[31807]: time="2026-02-07T00:57:35+07:00" level=debug msg="obtained new client token: AAC7FeFLA4zJ6HqKfMFvVby+QlxxT5nf/98gQp8x86sRLvNNAPnjsa94lgooLs5DX/7Ppy1wZDBDa4qVrLDXkgvaFtdtEVej0RvKL/OwkjgH4Zy9IqfYZa875o2cLotVvmoMJpz3bYuEXOdB9dDW6Y0VlBXGq1MpnmFOSoGx4RyNB1d2akSQC6gWRbT+DLfiq2DUc1/xmq77V6JRNNhKlMsLiZNfO8cRUhTmlZVisl8du1HYigH0St4=" Feb 07 00:57:35 volumio volumio[31548]: info: Starting Shairport Sync Feb 07 00:57:35 volumio volumio[31548]: info: Starting Shairport Sync Feb 07 00:57:35 volumio sudo[31828]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 00:57:35 volumio sudo[31828]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:57:35 volumio sudo[31826]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 00:57:35 volumio sudo[31826]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:57:35 volumio sudo[31830]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 00:57:35 volumio sudo[31830]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:57:35 volumio go-librespot[31807]: time="2026-02-07T00:57:35+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 07 00:57:35 volumio go-librespot[31807]: time="2026-02-07T00:57:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 07 00:57:35 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 07 00:57:35 volumio go-librespot[31807]: time="2026-02-07T00:57:35+07:00" level=debug msg="completed keyexchange" Feb 07 00:57:35 volumio go-librespot[31807]: time="2026-02-07T00:57:35+07:00" level=debug msg="completed challenge" Feb 07 00:57:35 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 07 00:57:35 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 00:57:35 volumio systemd[1]: shairport-sync.service: Consumed 2.308s CPU time. Feb 07 00:57:35 volumio go-librespot[31807]: time="2026-02-07T00:57:35+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 07 00:57:35 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 00:57:35 volumio sudo[31826]: pam_unix(sudo:session): session closed for user root Feb 07 00:57:35 volumio sudo[31828]: pam_unix(sudo:session): session closed for user root Feb 07 00:57:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 00:57:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 00:57:35 volumio sudo[31830]: pam_unix(sudo:session): session closed for user root Feb 07 00:57:35 volumio volumio[31548]: info: CoreCommandRouter::volumioGetState Feb 07 00:57:35 volumio volumio[31548]: info: CorePlayQueue::getTrack 0 Feb 07 00:57:35 volumio volumio[31548]: info: Shairport-Sync Started Feb 07 00:57:35 volumio volumio[31548]: Error adding Membership: Error: addMembership EINVAL Feb 07 00:57:35 volumio volumio[31548]: info: Shairport-Sync Started Feb 07 00:57:35 volumio volumio[31548]: info: Shairport-Sync Started Feb 07 00:57:35 volumio volumio[31548]: 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 07 00:57:35 volumio volumio[31548]: info: Spotify Successfully logged in Feb 07 00:57:35 volumio volumio[31548]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 00:57:35 volumio volumio[31548]: info: [1770400655907] CoreMusicLibrary::Adding element Spotify Feb 07 00:57:35 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 00:57:35 volumio volumio[31548]: Cannot find translation for source YouTube Music Feb 07 00:57:35 volumio volumio[31548]: Cannot find translation for source Spotify Feb 07 00:57:36 volumio volumio[31548]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 07 00:57:36 volumio volumio[31548]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 00:57:36 volumio volumio[31548]: info: VolumeController:: Volume=100 Mute =false Feb 07 00:57:36 volumio volumio[31548]: info: CoreCommandRouter::volumioGetState Feb 07 00:57:36 volumio volumio[31548]: info: CorePlayQueue::getTrack 0 Feb 07 00:57:36 volumio volumio[31548]: info: CoreStateMachine::pushState Feb 07 00:57:36 volumio volumio[31548]: info: CorePlayQueue::getTrack 0 Feb 07 00:57:36 volumio volumio[31548]: info: CoreCommandRouter::volumioPushState Feb 07 00:57:37 volumio mpd[31769]: 2026-02-07T00:57:37 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 07 00:57:38 volumio volumio[31548]: info: go-librespot daemon successfully initialized Feb 07 00:57:38 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 07 00:57:38 volumio sudo[31729]: pam_unix(sudo:session): session closed for user root Feb 07 00:57:38 volumio sudo[31740]: pam_unix(sudo:session): session closed for user root Feb 07 00:57:38 volumio volumio[31548]: error: MPD error: The expression evaluated to a falsy value: Feb 07 00:57:38 volumio volumio[31548]: assert.ok(self.idling) Feb 07 00:57:38 volumio volumio[31548]: error: The expression evaluated to a falsy value: Feb 07 00:57:38 volumio volumio[31548]: assert.ok(self.idling) Feb 07 00:57:38 volumio volumio[31548]: info: MPD running with PID31769 Feb 07 00:57:38 volumio volumio[31548]: ,establishing connection Feb 07 00:57:38 volumio volumio[31548]: error: updateQueue error: null Feb 07 00:57:38 volumio volumio[31548]: info: Completed starting Core Plugins Feb 07 00:57:38 volumio volumio[31548]: info: ------------------------------------------- Feb 07 00:57:38 volumio volumio[31548]: info: ----- MyVolumio plugins startup ---- Feb 07 00:57:38 volumio volumio[31548]: info: ------------------------------------------- Feb 07 00:57:38 volumio volumio[31548]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 07 00:57:38 volumio volumio[31548]: error: updateQueue error: null Feb 07 00:57:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 07 00:57:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:57:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:57:38 volumio go-librespot[31872]: go-librespot daemon starting... Feb 07 00:57:38 volumio go-librespot[31873]: time="2026-02-07T00:57:38+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 00:57:38 volumio go-librespot[31873]: time="2026-02-07T00:57:38+07:00" level=debug msg="app state loaded" Feb 07 00:57:38 volumio go-librespot[31873]: time="2026-02-07T00:57:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 00:57:39 volumio go-librespot[31873]: time="2026-02-07T00:57: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 07 00:57:39 volumio go-librespot[31873]: time="2026-02-07T00:57: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 07 00:57:39 volumio go-librespot[31873]: time="2026-02-07T00:57: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 07 00:57:39 volumio go-librespot[31873]: time="2026-02-07T00:57:39+07:00" level=info msg="zeroconf server listening on port 46685" Feb 07 00:57:39 volumio go-librespot[31873]: time="2026-02-07T00:57:39+07:00" level=debug msg="obtained new client token: AAB1s3IgTBsWiaUNE/NgVWlZH+pgIWhD6ARnsy1d2x179cctUWo1TqGiRLTiITgIBXUmRtY3UfdFJD0pnhxozcIWa1Ook8uxvXYnUb0htsR4HJYXMRbCwU4Co5ty22KdPklivKd8nBl8JWwMmaMxtcNXvLnWZLX44OvZOQJu0CXUobx8Mhb19Zp1bCFdLL4nniodYK1KU+G9vKKfQ2d5BPzIDXkHnRKlBiebDTnedcS0ymxb1tVl/AhZnw==" Feb 07 00:57:39 volumio go-librespot[31873]: time="2026-02-07T00:57:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 00:57:39 volumio go-librespot[31873]: time="2026-02-07T00:57:39+07:00" level=debug msg="completed keyexchange" Feb 07 00:57:39 volumio go-librespot[31873]: time="2026-02-07T00:57:39+07:00" level=debug msg="completed challenge" Feb 07 00:57:39 volumio go-librespot[31873]: time="2026-02-07T00:57:39+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 07 00:57:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 00:57:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 00:57:41 volumio volumio[31548]: info: Initializing connection to go-librespot Websocket Feb 07 00:57:41 volumio volumio[31548]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 00:57:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 07 00:57:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:57:43 volumio volumio[31548]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 07 00:57:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:57:43 volumio go-librespot[31882]: go-librespot daemon starting... Feb 07 00:57:43 volumio go-librespot[31883]: time="2026-02-07T00:57:43+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 00:57:43 volumio go-librespot[31883]: time="2026-02-07T00:57:43+07:00" level=debug msg="app state loaded" Feb 07 00:57:43 volumio go-librespot[31883]: time="2026-02-07T00:57:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 00:57:43 volumio go-librespot[31883]: time="2026-02-07T00:57:43+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 00:57:43 volumio go-librespot[31883]: time="2026-02-07T00:57:43+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 07 00:57:43 volumio go-librespot[31883]: time="2026-02-07T00:57:43+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 07 00:57:43 volumio go-librespot[31883]: time="2026-02-07T00:57:43+07:00" level=info msg="zeroconf server listening on port 39029" Feb 07 00:57:43 volumio go-librespot[31883]: time="2026-02-07T00:57:43+07:00" level=debug msg="obtained new client token: AAC3E3Fdsw2AxcdOrvIXRoyLjsRgVNmkrAYUUiJqD7ktRJkqRUjkaB99FBu7HMuzHdM7uMeK9gT2SuV/kgnXubNxgBsMv+S+vRTNf6+IyKnBSvAoLXwaA+v7bb7k3lB6PBVZAyBAiEBCT3HChrPbPDKwiFLXze2oTVH+KYKI04K/7+kv2BRXpzDY+6V5UcsiA9VW6yL6zOX2GIZB83SJXljJvia0+ouaCm9yLUMaS30ThjSW76joWg4xzQ==" Feb 07 00:57:43 volumio go-librespot[31883]: time="2026-02-07T00:57:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 00:57:44 volumio volumio[31548]: info: Initializing connection to go-librespot Websocket Feb 07 00:57:44 volumio go-librespot[31883]: time="2026-02-07T00:57:44+07:00" level=debug msg="new websocket client" Feb 07 00:57:44 volumio volumio[31548]: info: Connection to go-librespot Websocket established Feb 07 00:57:44 volumio go-librespot[31883]: time="2026-02-07T00:57:44+07:00" level=debug msg="completed keyexchange" Feb 07 00:57:44 volumio go-librespot[31883]: time="2026-02-07T00:57:44+07:00" level=debug msg="completed challenge" Feb 07 00:57:44 volumio go-librespot[31883]: time="2026-02-07T00:57: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 07 00:57:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 00:57:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 00:57:44 volumio volumio[31548]: info: Connection to go-librespot Websocket closed Feb 07 00:57:47 volumio volumio[31548]: info: Getting Spotify volume Feb 07 00:57:47 volumio volumio[31548]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 07 00:57:47 volumio volumio[31548]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 07 00:57:47 volumio volumio[31548]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 07 00:57:47 volumio volumio[31548]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 07 00:57:47 volumio volumio[31548]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 07 00:57:47 volumio volumio[31548]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 07 00:57:47 volumio volumio[31548]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 07 00:57:47 volumio volumio[31548]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 07 00:57:47 volumio volumio[31548]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 07 00:57:47 volumio volumio[31548]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 07 00:57:47 volumio volumio[31548]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 07 00:57:47 volumio volumio[31548]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 07 00:57:47 volumio volumio[31548]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 07 00:57:47 volumio volumio[31548]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 07 00:57:47 volumio volumio[31548]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 07 00:57:47 volumio volumio[31548]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 07 00:57:47 volumio volumio[31548]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 07 00:57:47 volumio volumio[31548]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 07 00:57:47 volumio volumio[31548]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 07 00:57:47 volumio volumio[31548]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 07 00:57:47 volumio volumio[31548]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 07 00:57:47 volumio volumio[31548]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 07 00:57:47 volumio volumio[31548]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 07 00:57:47 volumio volumio[31548]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 07 00:57:47 volumio volumio[31548]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 07 00:57:47 volumio volumio[31548]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 07 00:57:47 volumio volumio[31548]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 07 00:57:47 volumio volumio[31548]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 07 00:57:47 volumio volumio[31548]: info: Adding plugin bluetooth to MyMusic Plugins Feb 07 00:57:47 volumio volumio[31548]: info: Adding plugin multiroom to MyMusic Plugins Feb 07 00:57:47 volumio volumio[31548]: info: Adding plugin metavolumio to MyMusic Plugins Feb 07 00:57:47 volumio volumio[31548]: info: Adding plugin cd_controller to MyMusic Plugins Feb 07 00:57:47 volumio volumio[31548]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 07 00:57:47 volumio volumio[31548]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 07 00:57:47 volumio volumio[31548]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 07 00:57:47 volumio volumio[31548]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 07 00:57:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 07 00:57:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:57:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:57:47 volumio go-librespot[31891]: go-librespot daemon starting... Feb 07 00:57:47 volumio go-librespot[31892]: time="2026-02-07T00:57:47+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 00:57:47 volumio go-librespot[31892]: time="2026-02-07T00:57:47+07:00" level=debug msg="app state loaded" Feb 07 00:57:47 volumio go-librespot[31892]: time="2026-02-07T00:57:47+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 00:57:47 volumio go-librespot[31892]: time="2026-02-07T00:57:47+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 00:57:47 volumio go-librespot[31892]: time="2026-02-07T00:57:47+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 07 00:57:47 volumio go-librespot[31892]: time="2026-02-07T00:57:47+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 07 00:57:47 volumio go-librespot[31892]: time="2026-02-07T00:57:47+07:00" level=info msg="zeroconf server listening on port 44703" Feb 07 00:57:48 volumio go-librespot[31892]: time="2026-02-07T00:57:48+07:00" level=debug msg="obtained new client token: AADHvsTUPN6de42SwhJXwrAB80t/W+rhRh6Ywwif/8ctKgzU6xVeSNbWkRwZ3d0bZ4ckKMM8uptMmV+4TYXFXfMPUQxNkMpvehbjfrALx65Ld8GRhH6Wf80O4u30JPERLzqwu90Rmu0MH76ET6d08c4lNleq6skQk3XBqz2C3+0fB4D266kEayRoI3lOcnjneu8X63Qq6kcPw5vMkUqk4UkQkwZv528w4jwtf3BSUhPxG5hxWbbZIGo=" Feb 07 00:57:48 volumio go-librespot[31892]: time="2026-02-07T00:57:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 00:57:48 volumio go-librespot[31892]: time="2026-02-07T00:57:48+07:00" level=debug msg="completed keyexchange" Feb 07 00:57:48 volumio go-librespot[31892]: time="2026-02-07T00:57:48+07:00" level=debug msg="completed challenge" Feb 07 00:57:48 volumio go-librespot[31892]: time="2026-02-07T00:57:48+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 07 00:57:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 00:57:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 00:57:49 volumio volumio[31548]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 07 00:57:49 volumio volumio[31548]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 07 00:57:49 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 00:57:49 volumio volumio[31548]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 00:57:49 volumio volumio[31548]: info: Starting MyVolumio Remote Streaming Endpoints Feb 07 00:57:49 volumio volumio[31548]: info: MyVolumio login type: Token Feb 07 00:57:49 volumio volumio[31548]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 07 00:57:49 volumio volumio[31548]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 07 00:57:50 volumio volumio[31548]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 07 00:57:50 volumio volumio[31548]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 07 00:57:50 volumio volumio[31548]: info: Streaming services startup Feb 07 00:57:50 volumio volumio[31548]: info: Starting Streaming Daemon Feb 07 00:57:50 volumio sudo[31916]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 07 00:57:50 volumio sudo[31916]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:57:50 volumio volumio[31548]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 07 00:57:51 volumio sudo[31916]: pam_unix(sudo:session): session closed for user root Feb 07 00:57:51 volumio volumio[31548]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 00:57:51 volumio volumio[31548]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 00:57:51 volumio volumio[31548]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 07 00:57:51 volumio volumio[31548]: errno: -111, Feb 07 00:57:51 volumio volumio[31548]: code: 'ECONNREFUSED', Feb 07 00:57:51 volumio volumio[31548]: syscall: 'connect', Feb 07 00:57:51 volumio volumio[31548]: address: '127.0.0.1', Feb 07 00:57:51 volumio volumio[31548]: port: 9879, Feb 07 00:57:51 volumio volumio[31548]: response: undefined Feb 07 00:57:51 volumio volumio[31548]: } Feb 07 00:57:51 volumio volumio[31548]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 00:57:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 07 00:57:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:57:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:57:51 volumio go-librespot[31934]: go-librespot daemon starting... Feb 07 00:57:51 volumio go-librespot[31935]: time="2026-02-07T00:57:51+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 00:57:51 volumio go-librespot[31935]: time="2026-02-07T00:57:51+07:00" level=debug msg="app state loaded" Feb 07 00:57:51 volumio go-librespot[31935]: time="2026-02-07T00:57:51+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 00:57:52 volumio go-librespot[31935]: time="2026-02-07T00:57: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 00:57:52 volumio go-librespot[31935]: time="2026-02-07T00:57:52+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 07 00:57:52 volumio go-librespot[31935]: time="2026-02-07T00:57:52+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 07 00:57:52 volumio go-librespot[31935]: time="2026-02-07T00:57:52+07:00" level=info msg="zeroconf server listening on port 45331" Feb 07 00:57:52 volumio go-librespot[31935]: time="2026-02-07T00:57:52+07:00" level=debug msg="obtained new client token: AAD8i6jDfpvnrCH+kURZNBbmsOcEIxITi+2gMNCv3YEFLVhXigj5TuOJHTys/mHHmnBLMvkPnlZvsA+QzycSLlU/2TcXwVz1YKMtL0kVW7lQV4qc3+/AP6NuhlV7f/CfWbedONB38hZNYZ79r6bllgMYNWvR9hhYY/7YODtgDxteOxYUHA512WoTZXc7UPSdbC5e3+0BmcfImYayjg/Ss3ke4PHiFfWPaw6aWewgyT+7g0gtpwTz6cLV6w==" Feb 07 00:57:52 volumio sudo[31945]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 00:56' Feb 07 00:57:52 volumio sudo[31945]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:57:52 volumio go-librespot[31935]: time="2026-02-07T00:57:52+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 00:57:52 volumio go-librespot[31935]: time="2026-02-07T00:57:52+07:00" level=debug msg="completed keyexchange" Feb 07 00:57:52 volumio go-librespot[31935]: time="2026-02-07T00:57:52+07:00" level=debug msg="completed challenge" Feb 07 00:57:52 volumio go-librespot[31935]: time="2026-02-07T00:57:52+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 07 00:57:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 00:57:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 00:57:52 volumio sudo[31945]: pam_unix(sudo:session): session closed for user root Feb 07 00:57:54 volumio volumio-remote-updater[643]: [2026-02-07 00:57:54] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 07 00:57:54 volumio volumio-remote-updater[643]: [2026-02-07 00:57:54] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 07 00:57:54 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 07 00:57:54 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 07 00:57:54 volumio systemd[1]: volumio.service: Consumed 55.100s CPU time. Feb 07 00:57:54 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 00:57:54 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 00:57:54 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 5043. Feb 07 00:57:54 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 00:57:54 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 07 00:57:54 volumio systemd[1]: volumio.service: Consumed 55.100s CPU time. Feb 07 00:57:54 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 07 00:57:54 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 00:57:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 07 00:57:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:57:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:57:56 volumio go-librespot[31977]: go-librespot daemon starting... Feb 07 00:57:56 volumio go-librespot[31978]: time="2026-02-07T00:57:56+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 00:57:56 volumio go-librespot[31978]: time="2026-02-07T00:57:56+07:00" level=debug msg="app state loaded" Feb 07 00:57:56 volumio go-librespot[31978]: time="2026-02-07T00:57:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 00:57:56 volumio go-librespot[31978]: time="2026-02-07T00:57:56+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 07 00:57:56 volumio go-librespot[31978]: time="2026-02-07T00:57:56+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 07 00:57:56 volumio go-librespot[31978]: time="2026-02-07T00:57:56+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 07 00:57:56 volumio go-librespot[31978]: time="2026-02-07T00:57:56+07:00" level=info msg="zeroconf server listening on port 40261" Feb 07 00:57:56 volumio go-librespot[31978]: time="2026-02-07T00:57:56+07:00" level=debug msg="obtained new client token: AADB+TQWTmD3OCPIcfKUok/lWA+pVmnNyo5AS9xNQSiRfthqdlW80Y8I5k3aBH5MD3UrghOi8KxdG9QCYkTmyF70ZssSvQKIArrGdjqQNY+o05gudP3/qjxf+LUiPoglidp5/W/fvKD1CwmNYpDtuofFVnve5eFnwPwEnd5ClKX8jSiZX70TlVvs93sSSLgmleT9XY4Y4je+6uwYZMM6JbJuoqGYGdhtuE4lInGtiNQ2cuPEHRWKedqTBQ==" Feb 07 00:57:56 volumio go-librespot[31978]: time="2026-02-07T00:57:56+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 07 00:57:57 volumio go-librespot[31978]: time="2026-02-07T00:57:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 07 00:57:57 volumio go-librespot[31978]: time="2026-02-07T00:57:57+07:00" level=debug msg="completed keyexchange" Feb 07 00:57:57 volumio go-librespot[31978]: time="2026-02-07T00:57:57+07:00" level=debug msg="completed challenge" Feb 07 00:57:57 volumio go-librespot[31978]: time="2026-02-07T00:57: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 07 00:57:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 00:57:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 00:57:58 volumio volumio[31962]: info: ------------------------------------------- Feb 07 00:57:58 volumio volumio[31962]: info: ----- Volumio3 ---- Feb 07 00:57:58 volumio volumio[31962]: info: ------------------------------------------- Feb 07 00:57:58 volumio volumio[31962]: info: ----- System startup ---- Feb 07 00:57:58 volumio volumio[31962]: info: ------------------------------------------- Feb 07 00:57:59 volumio volumio-remote-updater[643]: [2026-02-07 00:57:59] [connect] Successful connection Feb 07 00:57:59 volumio volumio[31962]: info: MYVOLUMIO Environment detected Feb 07 00:57:59 volumio volumio[31962]: info: Plugin folders cleanup Feb 07 00:57:59 volumio volumio[31962]: info: Scanning into folder /volumio/app/plugins/ Feb 07 00:57:59 volumio volumio[31962]: info: Scanning category audio_interface Feb 07 00:57:59 volumio volumio[31962]: info: Scanning category miscellanea Feb 07 00:57:59 volumio volumio[31962]: info: Scanning category music_service Feb 07 00:57:59 volumio volumio[31962]: info: Scanning category plugins.json Feb 07 00:57:59 volumio volumio[31962]: info: Scanning category system_controller Feb 07 00:57:59 volumio volumio[31962]: info: Scanning category user_interface Feb 07 00:57:59 volumio volumio[31962]: info: Scanning into folder /data/plugins/ Feb 07 00:57:59 volumio volumio[31962]: info: Scanning category music_service Feb 07 00:57:59 volumio volumio[31962]: info: Plugin folders cleanup completed Feb 07 00:57:59 volumio volumio[31962]: info: ------------------------------------------- Feb 07 00:57:59 volumio volumio[31962]: info: ----- Core plugins startup ---- Feb 07 00:57:59 volumio volumio[31962]: info: ------------------------------------------- Feb 07 00:57:59 volumio volumio[31962]: info: Loading plugins from folder /volumio/app/plugins/ Feb 07 00:57:59 volumio volumio[31962]: info: Adding plugin upnp to MyMusic Plugins Feb 07 00:57:59 volumio volumio[31962]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 07 00:57:59 volumio volumio[31962]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 07 00:57:59 volumio volumio[31962]: info: Loading plugins from folder /data/plugins/ Feb 07 00:57:59 volumio volumio[31962]: info: Loading plugin "system"... Feb 07 00:57:59 volumio volumio[31962]: info: Loading plugin "appearance"... Feb 07 00:58:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 07 00:58:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:58:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:58:00 volumio go-librespot[31998]: go-librespot daemon starting... Feb 07 00:58:00 volumio go-librespot[31999]: time="2026-02-07T00:58:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 00:58:00 volumio go-librespot[31999]: time="2026-02-07T00:58:00+07:00" level=debug msg="app state loaded" Feb 07 00:58:00 volumio go-librespot[31999]: time="2026-02-07T00:58:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 00:58:00 volumio go-librespot[31999]: time="2026-02-07T00:58: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 07 00:58:00 volumio go-librespot[31999]: time="2026-02-07T00:58: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 07 00:58:00 volumio go-librespot[31999]: time="2026-02-07T00:58: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 07 00:58:01 volumio go-librespot[31999]: time="2026-02-07T00:58:01+07:00" level=info msg="zeroconf server listening on port 41309" Feb 07 00:58:01 volumio go-librespot[31999]: time="2026-02-07T00:58:01+07:00" level=debug msg="obtained new client token: AABzvn7GPTBvMeSeqLOTphCDoIwQsWtUg87z81WqY75okCfh2xQzGEeaYvGRjNewBYIjOIYcUiEu9DBh4GRP9O63uRxOwu5rz2qIM58J9eo55+V6LFCYCxAtloPaDFSRbb30Xaye37alRno4Z6cjj9sQNF6rr1ZjhCb7PDa4m6UiaxJ3tQUmCVRAyUhnI1ydPtATwRKub6CBSABYHmjayGM9/1rP5VIsBS24fGxn6dLaaKba93Gs074=" Feb 07 00:58:01 volumio go-librespot[31999]: time="2026-02-07T00:58:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 00:58:01 volumio go-librespot[31999]: time="2026-02-07T00:58:01+07:00" level=debug msg="completed keyexchange" Feb 07 00:58:01 volumio go-librespot[31999]: time="2026-02-07T00:58:01+07:00" level=debug msg="completed challenge" Feb 07 00:58:01 volumio go-librespot[31999]: time="2026-02-07T00:58:01+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 07 00:58:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 00:58:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 00:58:01 volumio volumio[31962]: info: Loading plugin "network"... Feb 07 00:58:01 volumio volumio[31962]: info: Refreshing Cached IP Addresses Feb 07 00:58:01 volumio sudo[32007]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 00:58:01 volumio sudo[32007]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:58:01 volumio volumio[31962]: info: Loading plugin "services"... Feb 07 00:58:01 volumio sudo[32009]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 00:58:01 volumio sudo[32009]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:58:01 volumio volumio[31962]: info: Loading plugin "alsa_controller"... Feb 07 00:58:01 volumio sudo[32009]: pam_unix(sudo:session): session closed for user root Feb 07 00:58:01 volumio sudo[32007]: pam_unix(sudo:session): session closed for user root Feb 07 00:58:01 volumio sudo[32016]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 07 00:58:01 volumio sudo[32016]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:58:01 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 00:58:01 volumio volumio[31962]: info: Loading plugin "wizard"... Feb 07 00:58:01 volumio volumio[31962]: info: Loading plugin "networkfs"... Feb 07 00:58:02 volumio volumio[31962]: info: Starting Udev Watcher for removable devices Feb 07 00:58:02 volumio volumio[31962]: info: Ignoring mount for partition: boot Feb 07 00:58:02 volumio volumio[31962]: info: Ignoring mount for partition: volumio Feb 07 00:58:02 volumio volumio[31962]: info: Ignoring mount for partition: volumio_data Feb 07 00:58:02 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 00:58:02 volumio volumio[31962]: info: Loading plugin "volumio_command_line_client"... Feb 07 00:58:02 volumio volumio[31962]: info: Loading plugin "upnp"... Feb 07 00:58:02 volumio volumio[31962]: info: [1770400682091] Starting Upmpd Daemon Feb 07 00:58:02 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 00:58:02 volumio volumio[31962]: info: Loading plugin "my_music"... Feb 07 00:58:02 volumio volumio[31962]: info: Loading plugin "mpd"... Feb 07 00:58:02 volumio volumio[31962]: info: Loading plugin "upnp_browser"... Feb 07 00:58:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 07 00:58:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:58:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:58:04 volumio go-librespot[32040]: go-librespot daemon starting... Feb 07 00:58:04 volumio sudo[32016]: pam_unix(sudo:session): session closed for user root Feb 07 00:58:04 volumio go-librespot[32041]: time="2026-02-07T00:58:04+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 00:58:04 volumio go-librespot[32041]: time="2026-02-07T00:58:04+07:00" level=debug msg="app state loaded" Feb 07 00:58:04 volumio go-librespot[32041]: time="2026-02-07T00:58:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 00:58:05 volumio go-librespot[32041]: time="2026-02-07T00:58:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 00:58:05 volumio go-librespot[32041]: time="2026-02-07T00:58:05+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 00:58:05 volumio go-librespot[32041]: time="2026-02-07T00:58:05+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 00:58:05 volumio go-librespot[32041]: time="2026-02-07T00:58:05+07:00" level=info msg="zeroconf server listening on port 37647" Feb 07 00:58:05 volumio go-librespot[32041]: time="2026-02-07T00:58:05+07:00" level=debug msg="obtained new client token: AAAxwyR2mlp5pOf0lxvoa5c0+2kkheQNItVTZVcSDVHPF98dpbBI73de91Q7hL/FwH9Z2sAuqM/vI/oxzFrvvqMuWO8X9/9qXBOEB2+D8lqABP6Tp0qZLaDFJMBp0JMc51ScOmnFpqoldZTEiXbh60DWvJ+hP3jlrmKxuflG/xh2U0rwih1lsXUrHIFudYQOWY0mxe4tftcaHidUWG6CliEgXeuwyAY9h/ZIRLbw/t+EoXSFEBKphmw3fw==" Feb 07 00:58:05 volumio go-librespot[32041]: time="2026-02-07T00:58:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 00:58:05 volumio go-librespot[32041]: time="2026-02-07T00:58:05+07:00" level=debug msg="completed keyexchange" Feb 07 00:58:05 volumio go-librespot[32041]: time="2026-02-07T00:58:05+07:00" level=debug msg="completed challenge" Feb 07 00:58:05 volumio volumio[31962]: info: Starting UPNP Browser Feb 07 00:58:05 volumio volumio[31962]: info: Loading plugin "alarm-clock"... Feb 07 00:58:05 volumio go-librespot[32041]: time="2026-02-07T00:58: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 07 00:58:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 00:58:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 00:58:06 volumio volumio[31962]: info: Loading plugin "airplay_emulation"... Feb 07 00:58:06 volumio volumio[31962]: info: Starting Shairport Sync Feb 07 00:58:06 volumio volumio[31962]: info: Loading plugin "last_100"... Feb 07 00:58:06 volumio volumio[31962]: info: Loading plugin "webradio"... Feb 07 00:58:06 volumio volumio[31962]: info: Loading plugin "i2s_dacs"... Feb 07 00:58:06 volumio volumio[31962]: info: Loading plugin "volumiodiscovery"... Feb 07 00:58:06 volumio volumio[31962]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 00:58:06 volumio volumio[31962]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 00:58:06 volumio volumio[31962]: *** WARNING *** For more information see Feb 07 00:58:06 volumio volumio[31962]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 00:58:06 volumio volumio[31962]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 00:58:06 volumio volumio[31962]: *** WARNING *** For more information see Feb 07 00:58:06 volumio node[31962]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 00:58:06 volumio node[31962]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 00:58:06 volumio node[31962]: *** WARNING *** For more information see Feb 07 00:58:06 volumio node[31962]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 00:58:06 volumio node[31962]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 00:58:06 volumio node[31962]: *** WARNING *** For more information see Feb 07 00:58:06 volumio volumio[31962]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 07 00:58:06 volumio volumio[31962]: info: Discovery: Started advertising with name: Volumio Feb 07 00:58:06 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 00:58:06 volumio volumio[31962]: info: Loading plugin "spop"... Feb 07 00:58:08 volumio volumio[31962]: info: Loading plugin "ytcr"... Feb 07 00:58:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 07 00:58:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:58:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:58:08 volumio go-librespot[32050]: go-librespot daemon starting... Feb 07 00:58:08 volumio go-librespot[32051]: time="2026-02-07T00:58:08+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 00:58:08 volumio go-librespot[32051]: time="2026-02-07T00:58:08+07:00" level=debug msg="app state loaded" Feb 07 00:58:08 volumio go-librespot[32051]: time="2026-02-07T00:58:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 00:58:09 volumio go-librespot[32051]: time="2026-02-07T00:58:09+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 07 00:58:09 volumio go-librespot[32051]: time="2026-02-07T00:58:09+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 07 00:58:09 volumio go-librespot[32051]: time="2026-02-07T00:58:09+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 07 00:58:09 volumio go-librespot[32051]: time="2026-02-07T00:58:09+07:00" level=info msg="zeroconf server listening on port 34661" Feb 07 00:58:09 volumio go-librespot[32051]: time="2026-02-07T00:58:09+07:00" level=debug msg="obtained new client token: AAC6hdjIUTv+Vfe7n+njZ4k/1gSjEfBT+xcwoHPmXqLCgdTcMc/SCvfQ9BYvYNNpzqnHtHVAs65kqPXaph2iA1DiV0f3hbFOwHn2IIqV83wMZkqb5P+NaZQL0LV7pP4Rdm+u7rSnhiPmW0diw1IuRJDDXE8J4AUCCezynw7LfyRuL3hcWAL66J0cgLXZgtN0/muICYdQdoUdqGMzYBGnbcdqmsAc2oIbPzGhaXBNKab3tLgvdraWaO7YRQ==" Feb 07 00:58:09 volumio go-librespot[32051]: time="2026-02-07T00:58:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 00:58:09 volumio go-librespot[32051]: time="2026-02-07T00:58:09+07:00" level=debug msg="completed keyexchange" Feb 07 00:58:09 volumio go-librespot[32051]: time="2026-02-07T00:58:09+07:00" level=debug msg="completed challenge" Feb 07 00:58:10 volumio go-librespot[32051]: time="2026-02-07T00:58: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 07 00:58:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 00:58:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 00:58:10 volumio volumio[31962]: info: Loading plugin "ytmusic"... Feb 07 00:58:11 volumio volumio-remote-updater[643]: [2026-02-07 00:58:11] [connect] Successful connection Feb 07 00:58:11 volumio volumio[31962]: info: Loading plugin "outputs"... Feb 07 00:58:11 volumio volumio[31962]: info: Loading plugin "albumart"... Feb 07 00:58:12 volumio volumio[31962]: info: Plugin example_plugin is not enabled Feb 07 00:58:12 volumio volumio[31962]: info: Loading plugin "inputs"... Feb 07 00:58:12 volumio volumio[31962]: info: Loading plugin "updater_comm"... Feb 07 00:58:12 volumio volumio[31962]: info: Plugin mpdemulation is not enabled Feb 07 00:58:12 volumio volumio[31962]: info: Loading plugin "rest_api"... Feb 07 00:58:12 volumio volumio[31962]: info: Loading plugin "websocket"... Feb 07 00:58:12 volumio volumio[31962]: info: Starting Socket.io Server version 1.7.4 Feb 07 00:58:12 volumio volumio[31962]: info: Loading plugin "RoonBridge"... Feb 07 00:58:12 volumio volumio[31962]: info: Applying required configuration parameters for plugin RoonBridge Feb 07 00:58:12 volumio volumio[31962]: info: Loading i18n strings for locale en Feb 07 00:58:12 volumio volumio[31962]: Updating browse sources language Feb 07 00:58:12 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 00:58:13 volumio volumio[32072]: Forking 3 albumart workers Feb 07 00:58:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 07 00:58:13 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 00:58:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:58:13 volumio volumio[31962]: info: CoreCommandRouter::initPlayerControls Feb 07 00:58:13 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:58:13 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:58:13 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:58:13 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:58:13 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:58:13 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:58:13 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:58:13 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:58:13 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 00:58:13 volumio volumio[31962]: Express server listening on port 3000 Feb 07 00:58:13 volumio volumio[31962]: [Metrics] WebUI: 15s 902.82ms Feb 07 00:58:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:58:13 volumio go-librespot[32084]: go-librespot daemon starting... Feb 07 00:58:13 volumio volumio[31962]: info: CoreStateMachine::resetVolumioState Feb 07 00:58:13 volumio volumio[31962]: info: CoreStateMachine::getcurrentVolume Feb 07 00:58:13 volumio volumio[31962]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 00:58:13 volumio go-librespot[32097]: time="2026-02-07T00:58:13+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 00:58:13 volumio go-librespot[32097]: time="2026-02-07T00:58:13+07:00" level=debug msg="app state loaded" Feb 07 00:58:13 volumio go-librespot[32097]: time="2026-02-07T00:58:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 00:58:13 volumio sudo[32122]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 00:58:13 volumio sudo[32122]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:58:13 volumio sudo[32122]: pam_unix(sudo:session): session closed for user root Feb 07 00:58:13 volumio sudo[32126]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 00:58:13 volumio sudo[32126]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:58:13 volumio sudo[32126]: pam_unix(sudo:session): session closed for user root Feb 07 00:58:13 volumio volumio[31962]: info: Volumio Network Manager: Network status updated: 1 Feb 07 00:58:13 volumio go-librespot[32097]: time="2026-02-07T00:58:13+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 00:58:13 volumio go-librespot[32097]: time="2026-02-07T00:58:13+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 07 00:58:13 volumio go-librespot[32097]: time="2026-02-07T00:58:13+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 07 00:58:13 volumio go-librespot[32097]: time="2026-02-07T00:58:13+07:00" level=info msg="zeroconf server listening on port 45741" Feb 07 00:58:13 volumio volumio[31962]: info: VolumeController:: Volume=100 Mute =false Feb 07 00:58:13 volumio volumio[31962]: info: CoreStateMachine::pushState Feb 07 00:58:13 volumio volumio[31962]: info: CorePlayQueue::getTrack 0 Feb 07 00:58:13 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 00:58:13 volumio volumio[31962]: info: CoreCommandRouter::volumioPushState Feb 07 00:58:13 volumio volumio[31962]: info: CoreStateMachine::updateTrackBlock Feb 07 00:58:13 volumio volumio[31962]: info: CorePlayQueue::getTrackBlock Feb 07 00:58:13 volumio volumio[31962]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 00:58:14 volumio volumio-remote-updater[643]: [2026-02-07 00:58:14] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770400691 101 Feb 07 00:58:14 volumio go-librespot[32097]: time="2026-02-07T00:58:14+07:00" level=debug msg="obtained new client token: AAA41NCVktxre5KJRwswbqhGx1WUtVHEmD8qhPbJh7ZfmDa0FvrGjsQYG7An875migmc9orFdw+iU0IFDOv5UL2chmiQ6xiAEMFsWJE1697rW0brzpmRBNRsDDXSD8URtq3f0H3gF1yVruqTub8u8vUu35AIqVTA6gGs9K5v2TT3J1C8LPIM6U3XAWHq4EXgZFeuLFwNmWUwH+t9BcNUF1zaKl5o4o23U21GaIbWcGGgKfCfoN7CeJo=" Feb 07 00:58:14 volumio volumio[31962]: 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 07 00:58:14 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 00:58:14 volumio volumio[31962]: info: Reloading queue from file Feb 07 00:58:14 volumio go-librespot[32097]: time="2026-02-07T00:58:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 00:58:14 volumio volumio[31962]: info: CoreStateMachine::setRepeat null single undefined Feb 07 00:58:14 volumio volumio[31962]: info: CoreStateMachine::pushState Feb 07 00:58:14 volumio volumio[31962]: info: CorePlayQueue::getTrack 0 Feb 07 00:58:14 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 00:58:14 volumio volumio[31962]: info: CoreCommandRouter::volumioPushState Feb 07 00:58:14 volumio volumio[31962]: info: CoreStateMachine::setRandom null Feb 07 00:58:14 volumio volumio[31962]: info: CoreStateMachine::pushState Feb 07 00:58:14 volumio volumio[31962]: info: CorePlayQueue::getTrack 0 Feb 07 00:58:14 volumio volumio[31962]: info: CoreCommandRouter::volumioPushState Feb 07 00:58:14 volumio go-librespot[32097]: time="2026-02-07T00:58:14+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 07 00:58:14 volumio volumio[31962]: info: Setting Device type: Raspberry PI Feb 07 00:58:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 00:58:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 00:58:14 volumio volumio[31962]: info: Completed loading Core Plugins Feb 07 00:58:14 volumio volumio[31962]: info: Preparing to generate the ALSA configuration file Feb 07 00:58:14 volumio volumio[31962]: info: VolumeController:: Volume=100 Mute =false Feb 07 00:58:14 volumio volumio[31962]: info: CoreStateMachine::pushState Feb 07 00:58:14 volumio volumio[31962]: info: CorePlayQueue::getTrack 0 Feb 07 00:58:14 volumio volumio[31962]: info: CoreCommandRouter::volumioPushState Feb 07 00:58:14 volumio volumio[31962]: info: Asound.conf file unchanged, so no further update is needed Feb 07 00:58:14 volumio volumio[31962]: info: Output device has changed, restarting MPD Feb 07 00:58:14 volumio sudo[32142]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 07 00:58:14 volumio volumio[31962]: info: Output device has changed, restarting Shairport Sync Feb 07 00:58:14 volumio sudo[32142]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:58:14 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:58:14 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 00:58:14 volumio volumio[31962]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 00:58:14 volumio sudo[32144]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 00:58:14 volumio volumio[31962]: info: ___________ START PLUGINS ___________ Feb 07 00:58:14 volumio volumio[31962]: info: ControllerMpd::onStart: Initializing MPD Feb 07 00:58:14 volumio volumio[31962]: info: Creating MPD Configuration file Feb 07 00:58:14 volumio sudo[32144]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:58:14 volumio sudo[32144]: pam_unix(sudo:session): session closed for user root Feb 07 00:58:14 volumio sudo[32147]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 00:58:14 volumio sudo[32147]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:58:14 volumio sudo[32142]: pam_unix(sudo:session): session closed for user root Feb 07 00:58:14 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 00:58:14 volumio volumio[31962]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 00:58:14 volumio volumio[31962]: info: [1770400694653] CoreMusicLibrary::Adding element Media Servers Feb 07 00:58:14 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 00:58:14 volumio volumio[31962]: info: UPNP Browser: Client initialized successfully Feb 07 00:58:14 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 07 00:58:14 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:58:14 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 00:58:14 volumio sudo[32157]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 00:58:14 volumio sudo[32157]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:58:14 volumio sudo[32155]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 00:58:14 volumio sudo[32155]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:58:14 volumio sudo[32155]: pam_unix(sudo:session): session closed for user root Feb 07 00:58:14 volumio volumio[31962]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 00:58:14 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:58:14 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 00:58:14 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 07 00:58:14 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 00:58:14 volumio systemd[1]: mpd.service: Consumed 7.180s CPU time. Feb 07 00:58:14 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 07 00:58:14 volumio volumio[31962]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 00:58:14 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 00:58:14 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 00:58:14 volumio volumio[31962]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 00:58:14 volumio volumio[31962]: info: [1770400694920] CoreMusicLibrary::Adding element Last_100 Feb 07 00:58:14 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 00:58:14 volumio volumio[31962]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 00:58:14 volumio volumio[31962]: info: [1770400694932] CoreMusicLibrary::Adding element Webradio Feb 07 00:58:14 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 00:58:14 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 00:58:14 volumio volumio[31962]: info: Initializing BBC Radios Feb 07 00:58:15 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 00:58:15 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 00:58:15 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 07 00:58:15 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 00:58:15 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 07 00:58:15 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 00:58:15 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 00:58:15 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 00:58:15 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 00:58:15 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 00:58:15 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 00:58:15 volumio volumio[31962]: info: Creating Spotify config file Feb 07 00:58:15 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:58:15 volumio sudo[32184]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 07 00:58:15 volumio sudo[32184]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 07 00:58:15 volumio sudo[32184]: pam_unix(sudo:session): session closed for user root Feb 07 00:58:16 volumio volumio[31962]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 00:58:16 volumio volumio[31962]: info: [1770400696200] CoreMusicLibrary::Adding element YouTube Music Feb 07 00:58:16 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 00:58:16 volumio volumio[31962]: Cannot find translation for source YouTube Music Feb 07 00:58:16 volumio volumio[31962]: info: Volumio Calling Home Feb 07 00:58:16 volumio sudo[32188]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 07 00:58:16 volumio sudo[32188]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:58:16 volumio sudo[32188]: pam_unix(sudo:session): session closed for user root Feb 07 00:58:16 volumio volumio[32086]: Starting albumart workers Feb 07 00:58:16 volumio volumio[32085]: Starting albumart workers Feb 07 00:58:16 volumio volumio[32083]: Starting albumart workers Feb 07 00:58:16 volumio volumio[31962]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 07 00:58:16 volumio volumio[31962]: info: Discovery: Found device Volumio Feb 07 00:58:16 volumio volumio[31962]: info: CoreCommandRouter::volumioGetState Feb 07 00:58:16 volumio volumio[31962]: info: CorePlayQueue::getTrack 0 Feb 07 00:58:17 volumio volumio[31962]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 07 00:58:17 volumio volumio[31962]: info: Discovery: Found device Volumio Feb 07 00:58:17 volumio volumio[31962]: info: CoreCommandRouter::volumioGetState Feb 07 00:58:17 volumio volumio[31962]: info: CorePlayQueue::getTrack 0 Feb 07 00:58:17 volumio volumio[31962]: info: MPD Permissions set Feb 07 00:58:17 volumio volumio[31962]: info: MPD Permissions set Feb 07 00:58:17 volumio volumio[31962]: info: Upmpdcli Daemon Started Feb 07 00:58:17 volumio volumio[31962]: info: Volumio called home Feb 07 00:58:17 volumio volumio[31962]: info: Spotify config file written Feb 07 00:58:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 07 00:58:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:58:17 volumio sudo[32194]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 07 00:58:17 volumio sudo[32194]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:58:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:58:17 volumio go-librespot[32195]: go-librespot daemon starting... Feb 07 00:58:17 volumio go-librespot[32196]: time="2026-02-07T00:58:17+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 00:58:17 volumio go-librespot[32196]: time="2026-02-07T00:58:17+07:00" level=debug msg="app state loaded" Feb 07 00:58:17 volumio go-librespot[32196]: time="2026-02-07T00:58:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 00:58:17 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 07 00:58:17 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 07 00:58:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:58:17 volumio volumio[31962]: 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 07 00:58:17 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:58:17 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:58:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:58:17 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:58:17 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:58:17 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:58:17 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:58:17 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:58:17 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:58:17 volumio go-librespot[32204]: go-librespot daemon starting... Feb 07 00:58:17 volumio sudo[32194]: pam_unix(sudo:session): session closed for user root Feb 07 00:58:17 volumio go-librespot[32205]: time="2026-02-07T00:58:17+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 00:58:17 volumio go-librespot[32205]: time="2026-02-07T00:58:17+07:00" level=debug msg="app state loaded" Feb 07 00:58:17 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 00:58:17 volumio go-librespot[32205]: time="2026-02-07T00:58:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 00:58:17 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:58:17 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:58:17 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:58:17 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:58:17 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:58:17 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:58:17 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:58:17 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:58:17 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:58:17 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 00:58:17 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 00:58:17 volumio volumio[31962]: info: No need to fix Spotify hosts Feb 07 00:58:18 volumio go-librespot[32205]: time="2026-02-07T00:58:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 00:58:18 volumio go-librespot[32205]: time="2026-02-07T00:58:18+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 07 00:58:18 volumio go-librespot[32205]: time="2026-02-07T00:58:18+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 07 00:58:18 volumio go-librespot[32205]: time="2026-02-07T00:58:18+07:00" level=info msg="zeroconf server listening on port 46305" Feb 07 00:58:18 volumio go-librespot[32205]: time="2026-02-07T00:58:18+07:00" level=debug msg="obtained new client token: AADfkJnUOP/Amo9rMVDBEOxfvC5H6bJ85u+nN/FJAFdmeO4io90EZTWQ3fip73bqvMFuZpLjZkZNfRVceTQUx7+aDTkfiTKhxiBYZNXybGp5hSrM2WUzMrx/5gNGIT2vrmwsDse6VnMUPp53s1LL733F4mnNuJ4WYCuWxxjzAFA0ndyYgUtjsK7UWDen2c8CNUfykXR+u8bnQw66pQNc4c65esHXJQxEVtUCU8cJ2Vyb0T3Fm+K0H3RwEg==" Feb 07 00:58:18 volumio go-librespot[32205]: time="2026-02-07T00:58:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 00:58:18 volumio go-librespot[32205]: time="2026-02-07T00:58:18+07:00" level=debug msg="completed keyexchange" Feb 07 00:58:18 volumio go-librespot[32205]: time="2026-02-07T00:58:18+07:00" level=debug msg="completed challenge" Feb 07 00:58:19 volumio go-librespot[32205]: time="2026-02-07T00:58:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 07 00:58:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 00:58:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 00:58:19 volumio volumio[31962]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 07 00:58:19 volumio volumio[31962]: SPOTIFY: BQCjjRLsNq2CXvuojKexnPLAGfQm5vpMz56-IQjP3PNYrh-5ud3osgSGKaBzFFUdp1LTRHIAmj8i7eo6YNwbU_3P6aRQTpc2SzLwfH5zUgWuzsebqndIab01DLHbWkxTQcB_eZfdlMtAvAtfkqxfaEUvKBfHi7GsdJsb1beIIAVwKO8TxcC69PmJBVnRZFpOajreJ9GA2gPjZxyZzs91sjm23jDDIr44aKFHjJZpPq4R2ZnRHmsAd7ZcNKDZRQJi7Pwdb2RG6ekgsQdaEurvN44QsApyaEK1KPySYk07UY2ZWHg6ucEK_YJe Feb 07 00:58:19 volumio volumio[31962]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 07 00:58:19 volumio volumio[31962]: info: New Spotify access token = BQCjjRLsNq2CXvuojKexnPLAGfQm5vpMz56-IQjP3PNYrh-5ud3osgSGKaBzFFUdp1LTRHIAmj8i7eo6YNwbU_3P6aRQTpc2SzLwfH5zUgWuzsebqndIab01DLHbWkxTQcB_eZfdlMtAvAtfkqxfaEUvKBfHi7GsdJsb1beIIAVwKO8TxcC69PmJBVnRZFpOajreJ9GA2gPjZxyZzs91sjm23jDDIr44aKFHjJZpPq4R2ZnRHmsAd7ZcNKDZRQJi7Pwdb2RG6ekgsQdaEurvN44QsApyaEK1KPySYk07UY2ZWHg6ucEK_YJe Feb 07 00:58:19 volumio volumio[31962]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 07 00:58:19 volumio volumio[31962]: info: Starting Shairport Sync Feb 07 00:58:19 volumio volumio[31962]: info: Starting Shairport Sync Feb 07 00:58:19 volumio volumio[31962]: info: Starting Shairport Sync Feb 07 00:58:19 volumio sudo[32242]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 00:58:19 volumio sudo[32242]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:58:19 volumio sudo[32244]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 00:58:19 volumio sudo[32244]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:58:19 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 07 00:58:19 volumio sudo[32249]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 00:58:19 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 07 00:58:19 volumio sudo[32249]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:58:19 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 00:58:19 volumio systemd[1]: shairport-sync.service: Consumed 2.276s CPU time. Feb 07 00:58:19 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 00:58:19 volumio sudo[32242]: pam_unix(sudo:session): session closed for user root Feb 07 00:58:19 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 07 00:58:19 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 07 00:58:19 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 00:58:19 volumio volumio[31962]: info: Shairport-Sync Started Feb 07 00:58:19 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 00:58:19 volumio volumio[31962]: Error adding Membership: Error: addMembership EINVAL Feb 07 00:58:19 volumio sudo[32244]: pam_unix(sudo:session): session closed for user root Feb 07 00:58:19 volumio sudo[32249]: pam_unix(sudo:session): session closed for user root Feb 07 00:58:19 volumio volumio[31962]: info: CoreCommandRouter::volumioGetState Feb 07 00:58:19 volumio volumio[31962]: info: CorePlayQueue::getTrack 0 Feb 07 00:58:19 volumio volumio[31962]: info: Shairport-Sync Started Feb 07 00:58:19 volumio volumio[31962]: info: Shairport-Sync Started Feb 07 00:58:20 volumio volumio[31962]: 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 07 00:58:20 volumio volumio[31962]: info: Spotify Successfully logged in Feb 07 00:58:20 volumio volumio[31962]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 00:58:20 volumio volumio[31962]: info: [1770400700152] CoreMusicLibrary::Adding element Spotify Feb 07 00:58:20 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 00:58:20 volumio volumio[31962]: Cannot find translation for source YouTube Music Feb 07 00:58:20 volumio volumio[31962]: Cannot find translation for source Spotify Feb 07 00:58:20 volumio volumio[31962]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 07 00:58:20 volumio volumio[31962]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 00:58:21 volumio volumio[31962]: info: VolumeController:: Volume=100 Mute =false Feb 07 00:58:21 volumio volumio[31962]: info: CoreCommandRouter::volumioGetState Feb 07 00:58:21 volumio volumio[31962]: info: CorePlayQueue::getTrack 0 Feb 07 00:58:21 volumio volumio[31962]: info: CoreStateMachine::pushState Feb 07 00:58:21 volumio volumio[31962]: info: CorePlayQueue::getTrack 0 Feb 07 00:58:21 volumio volumio[31962]: info: CoreCommandRouter::volumioPushState Feb 07 00:58:22 volumio volumio[31962]: info: go-librespot daemon successfully initialized Feb 07 00:58:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 07 00:58:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:58:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:58:22 volumio go-librespot[32285]: go-librespot daemon starting... Feb 07 00:58:22 volumio go-librespot[32286]: time="2026-02-07T00:58:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 00:58:22 volumio go-librespot[32286]: time="2026-02-07T00:58:22+07:00" level=debug msg="app state loaded" Feb 07 00:58:22 volumio mpd[32186]: 2026-02-07T00:58:22 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 07 00:58:22 volumio go-librespot[32286]: time="2026-02-07T00:58:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 00:58:22 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 07 00:58:22 volumio sudo[32157]: pam_unix(sudo:session): session closed for user root Feb 07 00:58:22 volumio sudo[32147]: pam_unix(sudo:session): session closed for user root Feb 07 00:58:22 volumio volumio[31962]: error: MPD error: The expression evaluated to a falsy value: Feb 07 00:58:22 volumio volumio[31962]: assert.ok(self.idling) Feb 07 00:58:22 volumio volumio[31962]: error: The expression evaluated to a falsy value: Feb 07 00:58:22 volumio volumio[31962]: assert.ok(self.idling) Feb 07 00:58:22 volumio volumio[31962]: error: updateQueue error: null Feb 07 00:58:22 volumio volumio[31962]: info: MPD running with PID32186 Feb 07 00:58:22 volumio volumio[31962]: ,establishing connection Feb 07 00:58:22 volumio volumio[31962]: info: Completed starting Core Plugins Feb 07 00:58:22 volumio volumio[31962]: info: ------------------------------------------- Feb 07 00:58:22 volumio volumio[31962]: info: ----- MyVolumio plugins startup ---- Feb 07 00:58:22 volumio volumio[31962]: info: ------------------------------------------- Feb 07 00:58:22 volumio volumio[31962]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 07 00:58:22 volumio volumio[31962]: error: updateQueue error: null Feb 07 00:58:22 volumio go-librespot[32286]: time="2026-02-07T00:58:22+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 07 00:58:22 volumio go-librespot[32286]: time="2026-02-07T00:58:22+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 07 00:58:22 volumio go-librespot[32286]: time="2026-02-07T00:58:22+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 07 00:58:22 volumio go-librespot[32286]: time="2026-02-07T00:58:22+07:00" level=info msg="zeroconf server listening on port 36289" Feb 07 00:58:23 volumio go-librespot[32286]: time="2026-02-07T00:58:23+07:00" level=debug msg="obtained new client token: AADlVe1L335vmyNeaQ8fHqPg3oSPjYIVWM1YeOYvSUSPcbAi16bA4TdEPA71XPp98u7dlsJGrmO7b9xgCI9v/5O6le5qRLwRX5dEV0SsPtrxA2rXToUXX3PVlqH0QnD1lJvaV89iVLW+2pa1E8QTzwI2y46r705LDKMk4ERUEvIowO0PlnJwTcKrBt4yfKJDxyaw++iGNvbp0z0XB5ROicpmLACCsyDRs8/Kx45hjb75MsClq8rof2s=" Feb 07 00:58:23 volumio go-librespot[32286]: time="2026-02-07T00:58:23+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 07 00:58:23 volumio go-librespot[32286]: time="2026-02-07T00:58:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 07 00:58:23 volumio go-librespot[32286]: time="2026-02-07T00:58:23+07:00" level=debug msg="completed keyexchange" Feb 07 00:58:23 volumio go-librespot[32286]: time="2026-02-07T00:58:23+07:00" level=debug msg="completed challenge" Feb 07 00:58:23 volumio go-librespot[32286]: time="2026-02-07T00:58:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 07 00:58:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 00:58:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 00:58:25 volumio volumio[31962]: info: Initializing connection to go-librespot Websocket Feb 07 00:58:25 volumio volumio[31962]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 00:58:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 07 00:58:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:58:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:58:26 volumio go-librespot[32299]: go-librespot daemon starting... Feb 07 00:58:26 volumio go-librespot[32300]: time="2026-02-07T00:58:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 00:58:26 volumio go-librespot[32300]: time="2026-02-07T00:58:26+07:00" level=debug msg="app state loaded" Feb 07 00:58:26 volumio go-librespot[32300]: time="2026-02-07T00:58:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 00:58:27 volumio go-librespot[32300]: time="2026-02-07T00:58:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 07 00:58:27 volumio go-librespot[32300]: time="2026-02-07T00:58:27+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 07 00:58:27 volumio go-librespot[32300]: time="2026-02-07T00:58:27+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 07 00:58:27 volumio go-librespot[32300]: time="2026-02-07T00:58:27+07:00" level=info msg="zeroconf server listening on port 35949" Feb 07 00:58:27 volumio go-librespot[32300]: time="2026-02-07T00:58:27+07:00" level=debug msg="obtained new client token: AAAC7Hfrc2xtKH4PDa4fWDDWtxUoi8qCZqvRDIERGaR+OrD0uKm9ci+wrFIbxtDuS0vGABWnMNNV/YNw/7gVMPgD1A1yn4pUsJvu9bHO+ZsFVi9w7yIuCa+4yqwEDrmwR5DVrI5pQgFxOvweocWOUTm2qt7x5ptGSf8dNJi+Fr2nUnCspKXqvl6IEDK/lYsyzyhrg151zkAJWvI6sU5/WH9aDha0DGavLl8VXs9k5iF1qfL568cmdIfD3w==" Feb 07 00:58:27 volumio go-librespot[32300]: time="2026-02-07T00:58:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 00:58:27 volumio volumio[31962]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 07 00:58:27 volumio go-librespot[32300]: time="2026-02-07T00:58:27+07:00" level=debug msg="completed keyexchange" Feb 07 00:58:27 volumio go-librespot[32300]: time="2026-02-07T00:58:27+07:00" level=debug msg="completed challenge" Feb 07 00:58:27 volumio go-librespot[32300]: time="2026-02-07T00:58:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 07 00:58:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 00:58:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 00:58:28 volumio volumio[31962]: info: Initializing connection to go-librespot Websocket Feb 07 00:58:28 volumio volumio[31962]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 00:58:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 07 00:58:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:58:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:58:30 volumio go-librespot[32308]: go-librespot daemon starting... Feb 07 00:58:30 volumio go-librespot[32309]: time="2026-02-07T00:58:30+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 00:58:30 volumio go-librespot[32309]: time="2026-02-07T00:58:30+07:00" level=debug msg="app state loaded" Feb 07 00:58:30 volumio go-librespot[32309]: time="2026-02-07T00:58:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 00:58:31 volumio volumio[31962]: info: Initializing connection to go-librespot Websocket Feb 07 00:58:31 volumio go-librespot[32309]: time="2026-02-07T00:58:31+07:00" level=debug msg="new websocket client" Feb 07 00:58:31 volumio volumio[31962]: info: Connection to go-librespot Websocket established Feb 07 00:58:31 volumio go-librespot[32309]: time="2026-02-07T00:58:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 07 00:58:31 volumio go-librespot[32309]: time="2026-02-07T00:58:31+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 07 00:58:31 volumio go-librespot[32309]: time="2026-02-07T00:58:31+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 07 00:58:31 volumio go-librespot[32309]: time="2026-02-07T00:58:31+07:00" level=info msg="zeroconf server listening on port 41083" Feb 07 00:58:31 volumio volumio[31962]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 07 00:58:31 volumio volumio[31962]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 07 00:58:31 volumio volumio[31962]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 07 00:58:31 volumio volumio[31962]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 07 00:58:31 volumio volumio[31962]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 07 00:58:31 volumio volumio[31962]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 07 00:58:31 volumio volumio[31962]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 07 00:58:31 volumio volumio[31962]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 07 00:58:31 volumio volumio[31962]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 07 00:58:31 volumio volumio[31962]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 07 00:58:31 volumio volumio[31962]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 07 00:58:31 volumio volumio[31962]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 07 00:58:31 volumio volumio[31962]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 07 00:58:31 volumio volumio[31962]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 07 00:58:31 volumio volumio[31962]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 07 00:58:31 volumio volumio[31962]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 07 00:58:31 volumio volumio[31962]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 07 00:58:31 volumio volumio[31962]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 07 00:58:31 volumio volumio[31962]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 07 00:58:31 volumio volumio[31962]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 07 00:58:31 volumio volumio[31962]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 07 00:58:31 volumio volumio[31962]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 07 00:58:31 volumio volumio[31962]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 07 00:58:31 volumio volumio[31962]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 07 00:58:31 volumio volumio[31962]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 07 00:58:31 volumio volumio[31962]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 07 00:58:31 volumio volumio[31962]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 07 00:58:31 volumio volumio[31962]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 07 00:58:31 volumio volumio[31962]: info: Adding plugin bluetooth to MyMusic Plugins Feb 07 00:58:31 volumio volumio[31962]: info: Adding plugin multiroom to MyMusic Plugins Feb 07 00:58:31 volumio volumio[31962]: info: Adding plugin metavolumio to MyMusic Plugins Feb 07 00:58:31 volumio volumio[31962]: info: Adding plugin cd_controller to MyMusic Plugins Feb 07 00:58:31 volumio volumio[31962]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 07 00:58:31 volumio volumio[31962]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 07 00:58:31 volumio volumio[31962]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 07 00:58:31 volumio volumio[31962]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 07 00:58:31 volumio go-librespot[32309]: time="2026-02-07T00:58:31+07:00" level=debug msg="obtained new client token: AAC+6XNmBpZWmazCoZDgodCiWHrdcXgEuhTXWnppD/nVpe7GNiYPWikBWwxHRXqX1gU1Nesj/7KblTWTUO4cCRKFmo6sf6t0Dd9yPSWoBIul2Qa9av67H9svmUOgXdabpbZ6fsvqRajyn5PZHDdyQkDEJgJFpa8U+8hDWG6U2PzNFVYfNTUat92O2t3UIOQURtNqP/M0AgeYyjpxvgoZi7YUFPL6qddbluwbaD75QvgRqBw7toS/qvlp9w==" Feb 07 00:58:31 volumio go-librespot[32309]: time="2026-02-07T00:58:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 00:58:31 volumio go-librespot[32309]: time="2026-02-07T00:58:31+07:00" level=debug msg="completed keyexchange" Feb 07 00:58:31 volumio go-librespot[32309]: time="2026-02-07T00:58:31+07:00" level=debug msg="completed challenge" Feb 07 00:58:31 volumio go-librespot[32309]: time="2026-02-07T00:58:31+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 07 00:58:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 00:58:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 00:58:33 volumio volumio[31962]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 07 00:58:33 volumio volumio[31962]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 07 00:58:33 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 00:58:33 volumio volumio[31962]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 00:58:33 volumio volumio[31962]: info: Starting MyVolumio Remote Streaming Endpoints Feb 07 00:58:33 volumio volumio[31962]: info: MyVolumio login type: Token Feb 07 00:58:33 volumio volumio[31962]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 07 00:58:33 volumio volumio[31962]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 07 00:58:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 07 00:58:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:58:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 00:58:35 volumio go-librespot[32335]: go-librespot daemon starting... Feb 07 00:58:35 volumio go-librespot[32336]: time="2026-02-07T00:58:35+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 00:58:35 volumio go-librespot[32336]: time="2026-02-07T00:58:35+07:00" level=debug msg="app state loaded" Feb 07 00:58:35 volumio go-librespot[32336]: time="2026-02-07T00:58:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 00:58:35 volumio volumio[31962]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 07 00:58:35 volumio volumio[31962]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 07 00:58:35 volumio volumio[31962]: info: Streaming services startup Feb 07 00:58:35 volumio volumio[31962]: info: Starting Streaming Daemon Feb 07 00:58:35 volumio sudo[32343]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 07 00:58:35 volumio sudo[32343]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 00:58:35 volumio volumio[31962]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 07 00:58:35 volumio sudo[32343]: pam_unix(sudo:session): session closed for user root Feb 07 00:58:35 volumio volumio[31962]: info: Getting Spotify volume Feb 07 00:58:35 volumio volumio[31962]: info: Connection to go-librespot Websocket closed Feb 07 00:58:35 volumio volumio[31962]: error: Cannot start Volumio Streaming Daemon Feb 07 00:58:35 volumio volumio[31962]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 07 00:58:35 volumio volumio[31962]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 07 00:58:35 volumio volumio[31962]: 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 07 00:58:35 volumio go-librespot[32336]: time="2026-02-07T00:58:35+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 00:58:35 volumio go-librespot[32336]: time="2026-02-07T00:58:35+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 00:58:35 volumio go-librespot[32336]: time="2026-02-07T00:58:35+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 00:58:35 volumio go-librespot[32336]: time="2026-02-07T00:58:35+07:00" level=info msg="zeroconf server listening on port 45285" Feb 07 00:58:35 volumio volumio[31962]: info: CoreCommandRouter::volumioGetState Feb 07 00:58:35 volumio volumio[31962]: info: CorePlayQueue::getTrack 0 Feb 07 00:58:35 volumio volumio[31962]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 07 00:58:35 volumio volumio[31962]: SPOTIFY: SPOTIFY VOLUME undefined Feb 07 00:58:35 volumio volumio[31962]: SPOTIFY: VOLUMIO VOLUME 100 Feb 07 00:58:35 volumio volumio[31962]: info: Aligning Spotify Volume to Volumio Volume Feb 07 00:58:35 volumio volumio[31962]: info: CoreCommandRouter::volumioGetState Feb 07 00:58:35 volumio volumio[31962]: info: CorePlayQueue::getTrack 0 Feb 07 00:58:35 volumio volumio[31962]: info: Setting Spotify Volume from Volumio: 100 Feb 07 00:58:36 volumio go-librespot[32336]: time="2026-02-07T00:58:36+07:00" level=debug msg="obtained new client token: AAAq3mJR6klh28fq+8WZ39t57eDokezjpnCgbE62iGUHfYVX5h/3X0Za+6x+1hq1TpsnOBf7KBo1ezXGGuVMfNO8dJn8kBR6k0oUWFRxquDR13PidLzElXgnpolv02ojM3SWi6BknQUf4aVi2eVbE4cMNgDa7wxtmC7cDZVhwD2TwWuvsTtDUqR7lJHWqj0ibB1dRBUClfRTSzXvcSzDzzVtX/yHlbL+wYTFFIAAw1myC2HgrrHQQ70saQ==" Feb 07 00:58:36 volumio go-librespot[32336]: time="2026-02-07T00:58:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 00:58:36 volumio go-librespot[32336]: time="2026-02-07T00:58:36+07:00" level=debug msg="completed keyexchange" Feb 07 00:58:36 volumio go-librespot[32336]: time="2026-02-07T00:58:36+07:00" level=debug msg="completed challenge" Feb 07 00:58:36 volumio go-librespot[32336]: time="2026-02-07T00:58: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 07 00:58:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 00:58:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 00:58:36 volumio volumio[31962]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 00:58:36 volumio volumio[31962]: Error: socket hang up Feb 07 00:58:36 volumio volumio[31962]: at connResetException (node:internal/errors:720:14) Feb 07 00:58:36 volumio volumio[31962]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 07 00:58:36 volumio volumio[31962]: at Socket.emit (node:events:526:35) Feb 07 00:58:36 volumio volumio[31962]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 07 00:58:36 volumio volumio[31962]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 07 00:58:36 volumio volumio[31962]: code: 'ECONNRESET', Feb 07 00:58:36 volumio volumio[31962]: response: undefined Feb 07 00:58:36 volumio volumio[31962]: } Feb 07 00:58:36 volumio volumio[31962]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 00:58:37 volumio sudo[32365]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 00:57' Feb 07 00:58:37 volumio sudo[32365]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"