Feb 09 07:22:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 09 07:22:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:22:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:22:01 volumio go-librespot[3374]: go-librespot daemon starting... Feb 09 07:22:01 volumio go-librespot[3375]: time="2026-02-09T07:22:01+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 07:22:01 volumio go-librespot[3375]: time="2026-02-09T07:22:01+07:00" level=debug msg="app state loaded" Feb 09 07:22:01 volumio go-librespot[3375]: time="2026-02-09T07:22:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 07:22:01 volumio go-librespot[3375]: time="2026-02-09T07:22:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 07:22:01 volumio go-librespot[3375]: time="2026-02-09T07:22:01+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 07:22:01 volumio go-librespot[3375]: time="2026-02-09T07:22:01+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 07:22:01 volumio go-librespot[3375]: time="2026-02-09T07:22:01+07:00" level=info msg="zeroconf server listening on port 38769" Feb 09 07:22:01 volumio go-librespot[3375]: time="2026-02-09T07:22:01+07:00" level=debug msg="obtained new client token: AADz13Hl2dkZiwJWYQ6MOLA9O5Klhp+3pH7EHsMHPctYRh9TMrjXWftd3/75ayAEMLgZuFBLKQcK39vKB5PTygQ929ODyZl0mAGTBHBwM5bO+zRc5Qxv7VnR40d7wQEz0cRyKunv73uxciFzKX4bcnF7/RY+34Qt68TtgXJ5ohLKzllrEbGGU+Is6PIGOEy7oMp/55zIw1zuun37q4Vov5UD6AE3hk31xbSAateD7LKmoyp6/b6KOl+82Q==" Feb 09 07:22:02 volumio volumio[3041]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 09 07:22:02 volumio go-librespot[3375]: time="2026-02-09T07:22:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 07:22:02 volumio go-librespot[3375]: time="2026-02-09T07:22:02+07:00" level=debug msg="completed keyexchange" Feb 09 07:22:02 volumio go-librespot[3375]: time="2026-02-09T07:22:02+07:00" level=debug msg="completed challenge" Feb 09 07:22:02 volumio go-librespot[3375]: time="2026-02-09T07:22:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 07:22:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 07:22:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 07:22:02 volumio volumio[3041]: info: Initializing connection to go-librespot Websocket Feb 09 07:22:02 volumio volumio[3041]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 07:22:02 volumio nmbd[966]: [2026/02/09 07:22:02.662344, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Feb 09 07:22:02 volumio nmbd[966]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.1.23 for name WORKGROUP<1d>. Feb 09 07:22:02 volumio nmbd[966]: This response was from IP 192.168.1.237, reporting an IP address of 192.168.1.237. Feb 09 07:22:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 09 07:22:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:22:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:22:05 volumio go-librespot[3383]: go-librespot daemon starting... Feb 09 07:22:05 volumio go-librespot[3384]: time="2026-02-09T07:22:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 07:22:05 volumio go-librespot[3384]: time="2026-02-09T07:22:05+07:00" level=debug msg="app state loaded" Feb 09 07:22:05 volumio go-librespot[3384]: time="2026-02-09T07:22:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 07:22:05 volumio volumio[3041]: info: Initializing connection to go-librespot Websocket Feb 09 07:22:05 volumio go-librespot[3384]: time="2026-02-09T07:22:05+07:00" level=debug msg="new websocket client" Feb 09 07:22:05 volumio volumio[3041]: info: Connection to go-librespot Websocket established Feb 09 07:22:05 volumio go-librespot[3384]: time="2026-02-09T07:22: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 09 07:22:05 volumio go-librespot[3384]: time="2026-02-09T07:22: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 09 07:22:05 volumio go-librespot[3384]: time="2026-02-09T07:22: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 09 07:22:05 volumio go-librespot[3384]: time="2026-02-09T07:22:05+07:00" level=info msg="zeroconf server listening on port 37193" Feb 09 07:22:06 volumio volumio[3041]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 09 07:22:06 volumio volumio[3041]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 09 07:22:06 volumio volumio[3041]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 09 07:22:06 volumio volumio[3041]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 09 07:22:06 volumio volumio[3041]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 09 07:22:06 volumio volumio[3041]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 09 07:22:06 volumio volumio[3041]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 09 07:22:06 volumio volumio[3041]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 09 07:22:06 volumio volumio[3041]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 09 07:22:06 volumio volumio[3041]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 09 07:22:06 volumio volumio[3041]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 09 07:22:06 volumio volumio[3041]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 09 07:22:06 volumio volumio[3041]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 09 07:22:06 volumio volumio[3041]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 09 07:22:06 volumio volumio[3041]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 09 07:22:06 volumio volumio[3041]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 09 07:22:06 volumio volumio[3041]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 09 07:22:06 volumio volumio[3041]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 09 07:22:06 volumio volumio[3041]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 09 07:22:06 volumio volumio[3041]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 09 07:22:06 volumio volumio[3041]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 09 07:22:06 volumio volumio[3041]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 09 07:22:06 volumio volumio[3041]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 09 07:22:06 volumio volumio[3041]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 09 07:22:06 volumio volumio[3041]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 09 07:22:06 volumio volumio[3041]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 09 07:22:06 volumio volumio[3041]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 09 07:22:06 volumio volumio[3041]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 09 07:22:06 volumio volumio[3041]: info: Adding plugin bluetooth to MyMusic Plugins Feb 09 07:22:06 volumio volumio[3041]: info: Adding plugin multiroom to MyMusic Plugins Feb 09 07:22:06 volumio volumio[3041]: info: Adding plugin metavolumio to MyMusic Plugins Feb 09 07:22:06 volumio volumio[3041]: info: Adding plugin cd_controller to MyMusic Plugins Feb 09 07:22:06 volumio volumio[3041]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 09 07:22:06 volumio volumio[3041]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 09 07:22:06 volumio volumio[3041]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 09 07:22:06 volumio volumio[3041]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 09 07:22:06 volumio go-librespot[3384]: time="2026-02-09T07:22:06+07:00" level=debug msg="obtained new client token: AADS940uj2DndN5hmvOegzkZzUP1d7MPsP6etSW3qxNwri1JaNuVp1ptzLCGy82x+I00kc5ttuSNS2DrpD+OEElgq6kUeKhfdyOBizIXGJxNcVGf82UVUVq73Q1q5R73fhPDvEAzsbxFf+qZcuvkcKBZ20YgZILZcIREp//fZjR7O/4IPdpotrVM1L78l4LUrKfx6lEvHVKgDWtP2k9GpWb5FPdOXYOiEP855gMB2mqtqXPhTmqo1FU=" Feb 09 07:22:06 volumio go-librespot[3384]: time="2026-02-09T07:22:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 07:22:06 volumio go-librespot[3384]: time="2026-02-09T07:22:06+07:00" level=debug msg="completed keyexchange" Feb 09 07:22:06 volumio go-librespot[3384]: time="2026-02-09T07:22:06+07:00" level=debug msg="completed challenge" Feb 09 07:22:06 volumio go-librespot[3384]: time="2026-02-09T07:22:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 07:22:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 07:22:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 07:22:07 volumio volumio[3041]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 09 07:22:07 volumio volumio[3041]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 09 07:22:07 volumio volumio[3041]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 07:22:07 volumio volumio[3041]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 07:22:07 volumio volumio[3041]: info: Starting MyVolumio Remote Streaming Endpoints Feb 09 07:22:08 volumio volumio[3041]: info: MyVolumio login type: Token Feb 09 07:22:08 volumio volumio[3041]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 09 07:22:08 volumio volumio[3041]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 09 07:22:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 09 07:22:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:22:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:22:09 volumio go-librespot[3405]: go-librespot daemon starting... Feb 09 07:22:09 volumio go-librespot[3406]: time="2026-02-09T07:22:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 07:22:09 volumio go-librespot[3406]: time="2026-02-09T07:22:09+07:00" level=debug msg="app state loaded" Feb 09 07:22:09 volumio go-librespot[3406]: time="2026-02-09T07:22:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 07:22:09 volumio volumio[3041]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 09 07:22:09 volumio volumio[3041]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 09 07:22:09 volumio volumio[3041]: info: Streaming services startup Feb 09 07:22:09 volumio volumio[3041]: info: Starting Streaming Daemon Feb 09 07:22:09 volumio sudo[3413]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 09 07:22:09 volumio sudo[3413]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:22:09 volumio volumio[3041]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 09 07:22:09 volumio sudo[3413]: pam_unix(sudo:session): session closed for user root Feb 09 07:22:10 volumio volumio[3041]: info: Getting Spotify volume Feb 09 07:22:10 volumio volumio[3041]: info: Connection to go-librespot Websocket closed Feb 09 07:22:10 volumio volumio[3041]: error: Cannot start Volumio Streaming Daemon Feb 09 07:22:10 volumio volumio[3041]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 09 07:22:10 volumio volumio[3041]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 09 07:22:10 volumio volumio[3041]: 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 09 07:22:10 volumio go-librespot[3406]: time="2026-02-09T07:22:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 07:22:10 volumio go-librespot[3406]: time="2026-02-09T07:22: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 09 07:22:10 volumio go-librespot[3406]: time="2026-02-09T07:22: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 09 07:22:10 volumio go-librespot[3406]: time="2026-02-09T07:22:10+07:00" level=info msg="zeroconf server listening on port 46033" Feb 09 07:22:10 volumio volumio[3041]: info: CoreCommandRouter::volumioGetState Feb 09 07:22:10 volumio volumio[3041]: info: CorePlayQueue::getTrack 0 Feb 09 07:22:10 volumio volumio[3041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 09 07:22:10 volumio volumio[3041]: SPOTIFY: SPOTIFY VOLUME undefined Feb 09 07:22:10 volumio volumio[3041]: SPOTIFY: VOLUMIO VOLUME 100 Feb 09 07:22:10 volumio volumio[3041]: info: Aligning Spotify Volume to Volumio Volume Feb 09 07:22:10 volumio volumio[3041]: info: CoreCommandRouter::volumioGetState Feb 09 07:22:10 volumio volumio[3041]: info: CorePlayQueue::getTrack 0 Feb 09 07:22:10 volumio volumio[3041]: info: Setting Spotify Volume from Volumio: 100 Feb 09 07:22:10 volumio go-librespot[3406]: time="2026-02-09T07:22:10+07:00" level=debug msg="obtained new client token: AAB2HiQVpPLgONy+0AXwiImS2HzZMQaKut1iodvGbS9FiwJaFXDmIcwXAAL517sqxSzqXLtFN2TDYHZkH7LhPrUcTCW2VyfGU+KhrDN3PL8eLHN5F5l1c8rEgOtGq7NF7+Lj5mBT0p+vEKUy/3VjYyCYVt9inYvs/JDm5TmlInt4FXAzo0MvoQfTgddqwnNLOqi72PDi1I05iSVfSywlHozi4UAHN9qF/UyRZ0vbxk2dpXr8OdaFIBf3Rw==" Feb 09 07:22:10 volumio go-librespot[3406]: time="2026-02-09T07:22:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 07:22:10 volumio go-librespot[3406]: time="2026-02-09T07:22:10+07:00" level=debug msg="completed keyexchange" Feb 09 07:22:10 volumio go-librespot[3406]: time="2026-02-09T07:22:10+07:00" level=debug msg="completed challenge" Feb 09 07:22:10 volumio go-librespot[3406]: time="2026-02-09T07:22:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 07:22:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 07:22:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 07:22:10 volumio volumio[3041]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 07:22:10 volumio volumio[3041]: Error: socket hang up Feb 09 07:22:10 volumio volumio[3041]: at connResetException (node:internal/errors:720:14) Feb 09 07:22:10 volumio volumio[3041]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 09 07:22:10 volumio volumio[3041]: at Socket.emit (node:events:526:35) Feb 09 07:22:10 volumio volumio[3041]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 09 07:22:10 volumio volumio[3041]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 09 07:22:10 volumio volumio[3041]: code: 'ECONNRESET', Feb 09 07:22:10 volumio volumio[3041]: response: undefined Feb 09 07:22:10 volumio volumio[3041]: } Feb 09 07:22:10 volumio volumio[3041]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 07:22:12 volumio sudo[3435]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-09 07:21' Feb 09 07:22:12 volumio sudo[3435]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:22:12 volumio sudo[3435]: pam_unix(sudo:session): session closed for user root Feb 09 07:22:12 volumio volumio-remote-updater[643]: [2026-02-09 07:22:12] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 09 07:22:12 volumio volumio-remote-updater[643]: [2026-02-09 07:22:12] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 09 07:22:12 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 09 07:22:12 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 09 07:22:12 volumio systemd[1]: volumio.service: Consumed 55.506s CPU time. Feb 09 07:22:12 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 07:22:12 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 07:22:12 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8386. Feb 09 07:22:12 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 07:22:12 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 09 07:22:12 volumio systemd[1]: volumio.service: Consumed 55.506s CPU time. Feb 09 07:22:12 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 09 07:22:12 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 07:22:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 09 07:22:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:22:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:22:13 volumio go-librespot[3467]: go-librespot daemon starting... Feb 09 07:22:13 volumio go-librespot[3468]: time="2026-02-09T07:22:13+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 07:22:13 volumio go-librespot[3468]: time="2026-02-09T07:22:13+07:00" level=debug msg="app state loaded" Feb 09 07:22:13 volumio go-librespot[3468]: time="2026-02-09T07:22:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 07:22:14 volumio go-librespot[3468]: time="2026-02-09T07:22:14+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 07:22:14 volumio go-librespot[3468]: time="2026-02-09T07:22: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 09 07:22:14 volumio go-librespot[3468]: time="2026-02-09T07:22: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 09 07:22:14 volumio go-librespot[3468]: time="2026-02-09T07:22:14+07:00" level=info msg="zeroconf server listening on port 34703" Feb 09 07:22:14 volumio go-librespot[3468]: time="2026-02-09T07:22:14+07:00" level=debug msg="obtained new client token: AABYMetZrOdXgtYnia2r9aHmoJs0Fm6JymC6+0Ky4upsRkRbfD+anqu09m1pCEGKpo9WMAIyHyZKkpt4UFkHBsZC3VfB8zO5zEp7FSXVbFkDSXJN+/eeWeyR0zdL/R8iqtfiZ/KrsqIbo46sUpKlLxeiAsMzP01aBrknsDXjoWGkNcKcLrPi/UhAraJCOd/GPD6KCCM4ngS1T0qFfG62Sjps+f3KXdmPGtP9Yg62ZLmYDG5xk1Zx27lWzQ==" Feb 09 07:22:14 volumio go-librespot[3468]: time="2026-02-09T07:22:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 07:22:14 volumio go-librespot[3468]: time="2026-02-09T07:22:14+07:00" level=debug msg="completed keyexchange" Feb 09 07:22:14 volumio go-librespot[3468]: time="2026-02-09T07:22:14+07:00" level=debug msg="completed challenge" Feb 09 07:22:15 volumio go-librespot[3468]: time="2026-02-09T07:22:15+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 07:22:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 07:22:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 07:22:16 volumio volumio[3452]: info: ------------------------------------------- Feb 09 07:22:16 volumio volumio[3452]: info: ----- Volumio3 ---- Feb 09 07:22:16 volumio volumio[3452]: info: ------------------------------------------- Feb 09 07:22:16 volumio volumio[3452]: info: ----- System startup ---- Feb 09 07:22:16 volumio volumio[3452]: info: ------------------------------------------- Feb 09 07:22:17 volumio volumio-remote-updater[643]: [2026-02-09 07:22:17] [connect] Successful connection Feb 09 07:22:17 volumio volumio[3452]: info: MYVOLUMIO Environment detected Feb 09 07:22:17 volumio volumio[3452]: info: Plugin folders cleanup Feb 09 07:22:17 volumio volumio[3452]: info: Scanning into folder /volumio/app/plugins/ Feb 09 07:22:17 volumio volumio[3452]: info: Scanning category audio_interface Feb 09 07:22:17 volumio volumio[3452]: info: Scanning category miscellanea Feb 09 07:22:17 volumio volumio[3452]: info: Scanning category music_service Feb 09 07:22:17 volumio volumio[3452]: info: Scanning category plugins.json Feb 09 07:22:17 volumio volumio[3452]: info: Scanning category system_controller Feb 09 07:22:17 volumio volumio[3452]: info: Scanning category user_interface Feb 09 07:22:17 volumio volumio[3452]: info: Scanning into folder /data/plugins/ Feb 09 07:22:17 volumio volumio[3452]: info: Scanning category music_service Feb 09 07:22:17 volumio volumio[3452]: info: Plugin folders cleanup completed Feb 09 07:22:17 volumio volumio[3452]: info: ------------------------------------------- Feb 09 07:22:17 volumio volumio[3452]: info: ----- Core plugins startup ---- Feb 09 07:22:17 volumio volumio[3452]: info: ------------------------------------------- Feb 09 07:22:17 volumio volumio[3452]: info: Loading plugins from folder /volumio/app/plugins/ Feb 09 07:22:17 volumio volumio[3452]: info: Adding plugin upnp to MyMusic Plugins Feb 09 07:22:17 volumio volumio[3452]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 09 07:22:17 volumio volumio[3452]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 09 07:22:17 volumio volumio[3452]: info: Loading plugins from folder /data/plugins/ Feb 09 07:22:17 volumio volumio[3452]: info: Loading plugin "system"... Feb 09 07:22:18 volumio volumio[3452]: info: Loading plugin "appearance"... Feb 09 07:22:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 09 07:22:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:22:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:22:18 volumio go-librespot[3488]: go-librespot daemon starting... Feb 09 07:22:18 volumio go-librespot[3489]: time="2026-02-09T07:22:18+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 07:22:18 volumio go-librespot[3489]: time="2026-02-09T07:22:18+07:00" level=debug msg="app state loaded" Feb 09 07:22:18 volumio go-librespot[3489]: time="2026-02-09T07:22:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 07:22:18 volumio go-librespot[3489]: time="2026-02-09T07:22: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-gew1.spotify.com:80]" Feb 09 07:22:18 volumio go-librespot[3489]: time="2026-02-09T07:22:18+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 09 07:22:18 volumio go-librespot[3489]: time="2026-02-09T07:22:18+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 09 07:22:19 volumio go-librespot[3489]: time="2026-02-09T07:22:19+07:00" level=info msg="zeroconf server listening on port 38753" Feb 09 07:22:19 volumio go-librespot[3489]: time="2026-02-09T07:22:19+07:00" level=debug msg="obtained new client token: AAAR+KS8GNf8hGGnrJBS74tWvaiBWnw2mJ5tnz0PV3Z8aE+yi3jH+KSIGMTVuOnzOijq/7udtXo39i3GwaC6FWq6G1MYrmdMVQfQkYrbF+6cdeCqkcEOUBaRwARDeTZLLh5wiWwvW1nminPZAvuMHQMLLWTt5WjWkVwZWon0KHu0P5JRVHR5I69a8fwfG9zGR14oGv4sYn2BJlSnlZhUWcwDtyCAOMf3BCTszsE4UdDkvirRwrdXYlo=" Feb 09 07:22:19 volumio go-librespot[3489]: time="2026-02-09T07:22:19+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 09 07:22:19 volumio go-librespot[3489]: time="2026-02-09T07:22:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 09 07:22:19 volumio go-librespot[3489]: time="2026-02-09T07:22:19+07:00" level=debug msg="completed keyexchange" Feb 09 07:22:19 volumio go-librespot[3489]: time="2026-02-09T07:22:19+07:00" level=debug msg="completed challenge" Feb 09 07:22:19 volumio go-librespot[3489]: time="2026-02-09T07:22:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 07:22:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 07:22:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 07:22:19 volumio volumio[3452]: info: Loading plugin "network"... Feb 09 07:22:19 volumio volumio[3452]: info: Refreshing Cached IP Addresses Feb 09 07:22:20 volumio sudo[3498]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 07:22:20 volumio sudo[3498]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:22:20 volumio volumio[3452]: info: Loading plugin "services"... Feb 09 07:22:20 volumio sudo[3500]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 07:22:20 volumio sudo[3500]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:22:20 volumio sudo[3498]: pam_unix(sudo:session): session closed for user root Feb 09 07:22:20 volumio volumio[3452]: info: Loading plugin "alsa_controller"... Feb 09 07:22:20 volumio sudo[3500]: pam_unix(sudo:session): session closed for user root Feb 09 07:22:20 volumio sudo[3507]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 09 07:22:20 volumio sudo[3507]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:22:20 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 07:22:20 volumio volumio[3452]: info: Loading plugin "wizard"... Feb 09 07:22:20 volumio volumio[3452]: info: Loading plugin "networkfs"... Feb 09 07:22:20 volumio volumio[3452]: info: Starting Udev Watcher for removable devices Feb 09 07:22:20 volumio volumio[3452]: info: Ignoring mount for partition: boot Feb 09 07:22:20 volumio volumio[3452]: info: Ignoring mount for partition: volumio Feb 09 07:22:20 volumio volumio[3452]: info: Ignoring mount for partition: volumio_data Feb 09 07:22:20 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 07:22:20 volumio volumio[3452]: info: Loading plugin "volumio_command_line_client"... Feb 09 07:22:20 volumio volumio[3452]: info: Loading plugin "upnp"... Feb 09 07:22:20 volumio volumio[3452]: info: [1770596540374] Starting Upmpd Daemon Feb 09 07:22:20 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 07:22:20 volumio volumio[3452]: info: Loading plugin "my_music"... Feb 09 07:22:20 volumio volumio[3452]: info: Loading plugin "mpd"... Feb 09 07:22:21 volumio volumio[3452]: info: Loading plugin "upnp_browser"... Feb 09 07:22:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 09 07:22:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:22:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:22:22 volumio go-librespot[3531]: go-librespot daemon starting... Feb 09 07:22:22 volumio sudo[3507]: pam_unix(sudo:session): session closed for user root Feb 09 07:22:22 volumio go-librespot[3532]: time="2026-02-09T07:22:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 07:22:22 volumio go-librespot[3532]: time="2026-02-09T07:22:22+07:00" level=debug msg="app state loaded" Feb 09 07:22:22 volumio go-librespot[3532]: time="2026-02-09T07:22:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 07:22:23 volumio go-librespot[3532]: time="2026-02-09T07:22:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 07:22:23 volumio go-librespot[3532]: time="2026-02-09T07:22: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 09 07:22:23 volumio go-librespot[3532]: time="2026-02-09T07:22: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 09 07:22:23 volumio go-librespot[3532]: time="2026-02-09T07:22:23+07:00" level=info msg="zeroconf server listening on port 33653" Feb 09 07:22:23 volumio go-librespot[3532]: time="2026-02-09T07:22:23+07:00" level=debug msg="obtained new client token: AABVbGc1TyAFgfAUzq2fx7JBEXQ+FIxtFATQsLHDeCjdS3cCPza7SLCRRCnYl5lFKuSLHFY58p4ematmqDJy9Ocn9s6z3KxLMSq3UCGirz4YLN2feHohG4u/7vSveV4n/OeJwuc/fdaOKa93Vjeh8k+imjkt7otujSm15Gh/AMGtDdv16/9lw1fF2MgT1g63hMN+zXOF0sPTgK3FPDv/iH5DpHBLrJRRIfVwo2m3+E58zkQSUK6Lg/OYGw==" Feb 09 07:22:23 volumio go-librespot[3532]: time="2026-02-09T07:22:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 07:22:23 volumio go-librespot[3532]: time="2026-02-09T07:22:23+07:00" level=debug msg="completed keyexchange" Feb 09 07:22:23 volumio go-librespot[3532]: time="2026-02-09T07:22:23+07:00" level=debug msg="completed challenge" Feb 09 07:22:23 volumio go-librespot[3532]: time="2026-02-09T07:22: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 09 07:22:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 07:22:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 07:22:23 volumio volumio[3452]: info: Starting UPNP Browser Feb 09 07:22:23 volumio volumio[3452]: info: Loading plugin "alarm-clock"... Feb 09 07:22:24 volumio volumio[3452]: info: Loading plugin "airplay_emulation"... Feb 09 07:22:24 volumio volumio[3452]: info: Starting Shairport Sync Feb 09 07:22:24 volumio volumio[3452]: info: Loading plugin "last_100"... Feb 09 07:22:24 volumio volumio[3452]: info: Loading plugin "webradio"... Feb 09 07:22:24 volumio volumio[3452]: info: Loading plugin "i2s_dacs"... Feb 09 07:22:24 volumio volumio[3452]: info: Loading plugin "volumiodiscovery"... Feb 09 07:22:24 volumio volumio[3452]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 07:22:24 volumio volumio[3452]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 07:22:24 volumio volumio[3452]: *** WARNING *** For more information see Feb 09 07:22:24 volumio volumio[3452]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 07:22:24 volumio volumio[3452]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 07:22:24 volumio volumio[3452]: *** WARNING *** For more information see Feb 09 07:22:24 volumio node[3452]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 07:22:24 volumio node[3452]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 07:22:24 volumio node[3452]: *** WARNING *** For more information see Feb 09 07:22:24 volumio node[3452]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 07:22:24 volumio node[3452]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 07:22:24 volumio node[3452]: *** WARNING *** For more information see Feb 09 07:22:24 volumio volumio[3452]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 09 07:22:24 volumio volumio[3452]: info: Discovery: Started advertising with name: Volumio Feb 09 07:22:24 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 07:22:24 volumio volumio[3452]: info: Loading plugin "spop"... Feb 09 07:22:26 volumio volumio[3452]: info: Loading plugin "ytcr"... Feb 09 07:22:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 09 07:22:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:22:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:22:27 volumio go-librespot[3542]: go-librespot daemon starting... Feb 09 07:22:27 volumio go-librespot[3543]: time="2026-02-09T07:22:27+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 07:22:27 volumio go-librespot[3543]: time="2026-02-09T07:22:27+07:00" level=debug msg="app state loaded" Feb 09 07:22:27 volumio go-librespot[3543]: time="2026-02-09T07:22:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 07:22:27 volumio go-librespot[3543]: time="2026-02-09T07:22:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 07:22:27 volumio go-librespot[3543]: time="2026-02-09T07:22:27+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 07:22:27 volumio go-librespot[3543]: time="2026-02-09T07:22:27+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 07:22:27 volumio go-librespot[3543]: time="2026-02-09T07:22:27+07:00" level=info msg="zeroconf server listening on port 36017" Feb 09 07:22:27 volumio go-librespot[3543]: time="2026-02-09T07:22:27+07:00" level=debug msg="obtained new client token: AAAM9jaFjYIFLcEOFdP1ujCMvpEieutSqlr1oY7amLNrKm+cvCqhmE+mCfuSlHAEhdoJWhusWp98GBoU8/TKR8XhgPi2Ef9yDFHVJO7FMBL5eLcpxsmKMqGRdc8k343sRtKBQqkp4sm6OD2z6jT1cxvZJeRKlkBeC5ojxfk2oQ/rdz5Iz+1ZOQjQEzyjfMHWTIrypN6ZMJcX3v2fLRf5WkWoe8OvahixEwlGmxPBivCoKptq8qJnB/9sLA==" Feb 09 07:22:28 volumio go-librespot[3543]: time="2026-02-09T07:22:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 07:22:28 volumio go-librespot[3543]: time="2026-02-09T07:22:28+07:00" level=debug msg="completed keyexchange" Feb 09 07:22:28 volumio go-librespot[3543]: time="2026-02-09T07:22:28+07:00" level=debug msg="completed challenge" Feb 09 07:22:28 volumio go-librespot[3543]: time="2026-02-09T07:22:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 07:22:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 07:22:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 07:22:29 volumio volumio[3452]: info: Loading plugin "ytmusic"... Feb 09 07:22:30 volumio volumio-remote-updater[643]: [2026-02-09 07:22:30] [connect] Successful connection Feb 09 07:22:30 volumio volumio[3452]: info: Loading plugin "outputs"... Feb 09 07:22:30 volumio volumio[3452]: info: Loading plugin "albumart"... Feb 09 07:22:30 volumio volumio[3452]: info: Plugin example_plugin is not enabled Feb 09 07:22:30 volumio volumio[3452]: info: Loading plugin "inputs"... Feb 09 07:22:30 volumio volumio[3452]: info: Loading plugin "updater_comm"... Feb 09 07:22:30 volumio volumio[3452]: info: Plugin mpdemulation is not enabled Feb 09 07:22:30 volumio volumio[3452]: info: Loading plugin "rest_api"... Feb 09 07:22:30 volumio volumio[3452]: info: Loading plugin "websocket"... Feb 09 07:22:30 volumio volumio[3452]: info: Starting Socket.io Server version 1.7.4 Feb 09 07:22:30 volumio volumio[3452]: info: Loading plugin "RoonBridge"... Feb 09 07:22:31 volumio volumio[3452]: info: Applying required configuration parameters for plugin RoonBridge Feb 09 07:22:31 volumio volumio[3452]: info: Loading i18n strings for locale en Feb 09 07:22:31 volumio volumio[3452]: Updating browse sources language Feb 09 07:22:31 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 07:22:31 volumio volumio[3567]: Forking 3 albumart workers Feb 09 07:22:31 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 07:22:31 volumio volumio[3452]: info: CoreCommandRouter::initPlayerControls Feb 09 07:22:31 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:22:31 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:22:31 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:22:31 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:22:31 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:22:31 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:22:31 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:22:31 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:22:31 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 07:22:31 volumio volumio[3452]: Express server listening on port 3000 Feb 09 07:22:31 volumio volumio[3452]: [Metrics] WebUI: 15s 889.40ms Feb 09 07:22:31 volumio volumio[3452]: info: CoreStateMachine::resetVolumioState Feb 09 07:22:31 volumio volumio[3452]: info: CoreStateMachine::getcurrentVolume Feb 09 07:22:31 volumio volumio[3452]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 07:22:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 09 07:22:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:22:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:22:31 volumio go-librespot[3609]: go-librespot daemon starting... Feb 09 07:22:31 volumio sudo[3610]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 07:22:31 volumio sudo[3610]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:22:31 volumio sudo[3612]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 07:22:31 volumio sudo[3612]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:22:31 volumio go-librespot[3614]: time="2026-02-09T07:22:31+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 07:22:31 volumio sudo[3610]: pam_unix(sudo:session): session closed for user root Feb 09 07:22:31 volumio go-librespot[3614]: time="2026-02-09T07:22:31+07:00" level=debug msg="app state loaded" Feb 09 07:22:31 volumio sudo[3612]: pam_unix(sudo:session): session closed for user root Feb 09 07:22:31 volumio volumio[3452]: info: Volumio Network Manager: Network status updated: 1 Feb 09 07:22:31 volumio go-librespot[3614]: time="2026-02-09T07:22:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 07:22:32 volumio volumio[3452]: info: VolumeController:: Volume=100 Mute =false Feb 09 07:22:32 volumio volumio[3452]: info: CoreStateMachine::pushState Feb 09 07:22:32 volumio volumio[3452]: info: CorePlayQueue::getTrack 0 Feb 09 07:22:32 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 07:22:32 volumio volumio[3452]: info: CoreCommandRouter::volumioPushState Feb 09 07:22:32 volumio volumio[3452]: info: CoreStateMachine::updateTrackBlock Feb 09 07:22:32 volumio volumio[3452]: info: CorePlayQueue::getTrackBlock Feb 09 07:22:32 volumio volumio[3452]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 07:22:32 volumio volumio-remote-updater[643]: [2026-02-09 07:22:32] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770596550 101 Feb 09 07:22:32 volumio volumio[3452]: 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 09 07:22:32 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 07:22:32 volumio volumio[3452]: info: Reloading queue from file Feb 09 07:22:32 volumio volumio[3452]: info: CoreStateMachine::setRepeat null single undefined Feb 09 07:22:32 volumio volumio[3452]: info: CoreStateMachine::pushState Feb 09 07:22:32 volumio volumio[3452]: info: CorePlayQueue::getTrack 0 Feb 09 07:22:32 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 07:22:32 volumio volumio[3452]: info: CoreCommandRouter::volumioPushState Feb 09 07:22:32 volumio volumio[3452]: info: CoreStateMachine::setRandom null Feb 09 07:22:32 volumio volumio[3452]: info: CoreStateMachine::pushState Feb 09 07:22:32 volumio volumio[3452]: info: CorePlayQueue::getTrack 0 Feb 09 07:22:32 volumio volumio[3452]: info: CoreCommandRouter::volumioPushState Feb 09 07:22:32 volumio volumio[3452]: info: Setting Device type: Raspberry PI Feb 09 07:22:32 volumio go-librespot[3614]: time="2026-02-09T07:22:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 07:22:32 volumio go-librespot[3614]: time="2026-02-09T07:22:32+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 07:22:32 volumio go-librespot[3614]: time="2026-02-09T07:22:32+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 07:22:32 volumio go-librespot[3614]: time="2026-02-09T07:22:32+07:00" level=info msg="zeroconf server listening on port 43501" Feb 09 07:22:32 volumio volumio[3452]: info: Completed loading Core Plugins Feb 09 07:22:32 volumio volumio[3452]: info: Preparing to generate the ALSA configuration file Feb 09 07:22:32 volumio volumio[3452]: info: VolumeController:: Volume=100 Mute =false Feb 09 07:22:32 volumio volumio[3452]: info: CoreStateMachine::pushState Feb 09 07:22:32 volumio volumio[3452]: info: CorePlayQueue::getTrack 0 Feb 09 07:22:32 volumio volumio[3452]: info: CoreCommandRouter::volumioPushState Feb 09 07:22:32 volumio volumio[3452]: info: Asound.conf file unchanged, so no further update is needed Feb 09 07:22:32 volumio volumio[3452]: info: Output device has changed, restarting MPD Feb 09 07:22:32 volumio go-librespot[3614]: time="2026-02-09T07:22:32+07:00" level=debug msg="obtained new client token: AAB+kf7J2u2zUeE3gJkpHJnh7yG4IiyAUbAEV41LjKz3sjyjcX8OEbK3ZyYeqAtY8vPkddbp2GsQd8u+0X3rfxP+95TI9cUosr0OLT6WPoxHW2/xxIq4Dw31mgoXugfZNiSpaY/ITzcqqDq4lI555Imx7monvqaTvBgZ1SoL4sAdMAv+lP7n71h+o+yuZHa2WoaoM/K9O/KSpAqH6wbEA9x9ZvGg6j5ee+y7zSY6ihB/mjsM0gRT0F8dzA==" Feb 09 07:22:32 volumio volumio[3452]: info: Output device has changed, restarting Shairport Sync Feb 09 07:22:32 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:22:32 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 07:22:32 volumio sudo[3637]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 07:22:32 volumio sudo[3637]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:22:32 volumio sudo[3635]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 09 07:22:32 volumio sudo[3635]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:22:32 volumio sudo[3637]: pam_unix(sudo:session): session closed for user root Feb 09 07:22:32 volumio go-librespot[3614]: time="2026-02-09T07:22:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 07:22:32 volumio sudo[3639]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 07:22:32 volumio sudo[3639]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:22:32 volumio volumio[3452]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 07:22:32 volumio go-librespot[3614]: time="2026-02-09T07:22:32+07:00" level=debug msg="completed keyexchange" Feb 09 07:22:32 volumio volumio[3452]: info: ___________ START PLUGINS ___________ Feb 09 07:22:32 volumio go-librespot[3614]: time="2026-02-09T07:22:32+07:00" level=debug msg="completed challenge" Feb 09 07:22:32 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 09 07:22:32 volumio volumio[3452]: info: ControllerMpd::onStart: Initializing MPD Feb 09 07:22:32 volumio sudo[3635]: pam_unix(sudo:session): session closed for user root Feb 09 07:22:32 volumio volumio[3452]: info: Creating MPD Configuration file Feb 09 07:22:32 volumio go-librespot[3614]: time="2026-02-09T07:22:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 07:22:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 07:22:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 07:22:33 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 07:22:33 volumio volumio[3452]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 07:22:33 volumio volumio[3452]: info: [1770596553004] CoreMusicLibrary::Adding element Media Servers Feb 09 07:22:33 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 07:22:33 volumio sudo[3648]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 07:22:33 volumio sudo[3648]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:22:33 volumio sudo[3650]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 07:22:33 volumio sudo[3650]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:22:33 volumio sudo[3648]: pam_unix(sudo:session): session closed for user root Feb 09 07:22:33 volumio volumio[3452]: info: UPNP Browser: Client initialized successfully Feb 09 07:22:33 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 09 07:22:33 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 07:22:33 volumio systemd[1]: mpd.service: Consumed 7.102s CPU time. Feb 09 07:22:33 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 09 07:22:33 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 07:22:33 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 07:22:33 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:22:33 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 07:22:33 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 07:22:33 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 07:22:33 volumio volumio[3452]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 07:22:33 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:22:33 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 07:22:33 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 09 07:22:33 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 07:22:33 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 09 07:22:33 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 07:22:33 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 07:22:33 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 07:22:33 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 07:22:33 volumio volumio[3452]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 07:22:33 volumio volumio[3452]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 07:22:33 volumio volumio[3452]: info: [1770596553410] CoreMusicLibrary::Adding element Last_100 Feb 09 07:22:33 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 07:22:33 volumio volumio[3452]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 07:22:33 volumio volumio[3452]: info: [1770596553423] CoreMusicLibrary::Adding element Webradio Feb 09 07:22:33 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 07:22:33 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 07:22:33 volumio volumio[3452]: info: Initializing BBC Radios Feb 09 07:22:33 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 07:22:33 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 07:22:33 volumio volumio[3452]: info: Creating Spotify config file Feb 09 07:22:33 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:22:33 volumio sudo[3662]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 09 07:22:33 volumio sudo[3662]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 09 07:22:33 volumio sudo[3662]: pam_unix(sudo:session): session closed for user root Feb 09 07:22:34 volumio volumio[3452]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 07:22:34 volumio volumio[3452]: info: [1770596554742] CoreMusicLibrary::Adding element YouTube Music Feb 09 07:22:34 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 07:22:34 volumio volumio[3452]: Cannot find translation for source YouTube Music Feb 09 07:22:34 volumio volumio[3452]: info: Volumio Calling Home Feb 09 07:22:34 volumio sudo[3681]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 09 07:22:34 volumio sudo[3681]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:22:34 volumio volumio[3578]: Starting albumart workers Feb 09 07:22:35 volumio volumio[3579]: Starting albumart workers Feb 09 07:22:35 volumio sudo[3681]: pam_unix(sudo:session): session closed for user root Feb 09 07:22:35 volumio volumio[3577]: Starting albumart workers Feb 09 07:22:35 volumio volumio[3452]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 09 07:22:35 volumio volumio[3452]: info: Discovery: Found device Volumio Feb 09 07:22:35 volumio volumio[3452]: info: CoreCommandRouter::volumioGetState Feb 09 07:22:35 volumio volumio[3452]: info: CorePlayQueue::getTrack 0 Feb 09 07:22:35 volumio volumio[3452]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 09 07:22:35 volumio volumio[3452]: info: Discovery: Found device Volumio Feb 09 07:22:35 volumio volumio[3452]: info: CoreCommandRouter::volumioGetState Feb 09 07:22:35 volumio volumio[3452]: info: CorePlayQueue::getTrack 0 Feb 09 07:22:35 volumio volumio[3452]: info: MPD Permissions set Feb 09 07:22:35 volumio volumio[3452]: info: MPD Permissions set Feb 09 07:22:35 volumio volumio[3452]: info: Upmpdcli Daemon Started Feb 09 07:22:35 volumio volumio[3452]: info: Spotify config file written Feb 09 07:22:35 volumio sudo[3688]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 09 07:22:35 volumio sudo[3688]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:22:35 volumio volumio[3452]: 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 09 07:22:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:22:35 volumio volumio[3452]: info: Volumio called home Feb 09 07:22:35 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:22:35 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:22:35 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:22:35 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:22:35 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:22:35 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:22:35 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:22:35 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:22:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:22:35 volumio go-librespot[3690]: go-librespot daemon starting... Feb 09 07:22:35 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 07:22:35 volumio sudo[3688]: pam_unix(sudo:session): session closed for user root Feb 09 07:22:35 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:22:35 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:22:35 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:22:35 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:22:35 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:22:35 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:22:35 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:22:35 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:22:35 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:22:35 volumio go-librespot[3696]: time="2026-02-09T07:22:35+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 07:22:35 volumio go-librespot[3696]: time="2026-02-09T07:22:35+07:00" level=debug msg="app state loaded" Feb 09 07:22:35 volumio go-librespot[3696]: time="2026-02-09T07:22:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 07:22:35 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 07:22:36 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:22:36 volumio volumio[3452]: info: No need to fix Spotify hosts Feb 09 07:22:36 volumio go-librespot[3696]: time="2026-02-09T07:22:36+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 09 07:22:36 volumio go-librespot[3696]: time="2026-02-09T07:22:36+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 09 07:22:36 volumio go-librespot[3696]: time="2026-02-09T07:22:36+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 09 07:22:36 volumio go-librespot[3696]: time="2026-02-09T07:22:36+07:00" level=info msg="zeroconf server listening on port 37179" Feb 09 07:22:36 volumio go-librespot[3696]: time="2026-02-09T07:22:36+07:00" level=debug msg="obtained new client token: AADuEM/ygW8ZmAn2tXlImeRZs226lkWxXM2CcsajsP3u5umgBIGf7C2Vq8Z0UIXeGfLMwQZ4RmcWl/hAKRzmmYv9UY5E0pF82OIlBfHlcZL5O+RiPcVRl9xwJ0IRoIpklO7QVKneR4Qts7zBXiymJwxPa3FbmmTR9l/2KR6zoWLCw3fdF6mmoB7sE86FP9TC83LPt4CzqAyV1nwDuszy5PETQbse6+znzXpoJqvguLI7xXN/dDiOVAjJnw==" Feb 09 07:22:37 volumio go-librespot[3696]: time="2026-02-09T07:22:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 07:22:37 volumio go-librespot[3696]: time="2026-02-09T07:22:37+07:00" level=debug msg="completed keyexchange" Feb 09 07:22:37 volumio go-librespot[3696]: time="2026-02-09T07:22:37+07:00" level=debug msg="completed challenge" Feb 09 07:22:37 volumio go-librespot[3696]: time="2026-02-09T07:22:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 07:22:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 07:22:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 07:22:37 volumio volumio[3452]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 09 07:22:37 volumio volumio[3452]: SPOTIFY: BQA8cosrQPKcSbibo1OFr_HXAXFoeT9EmPA67cpCizMfMz38PSrRh7ZdJIZtEuB2tkK_JWMUR8cmDJ6ruzaOH6l6VFVO-JvaZFGAabXbiFNJrpD-cNKRy9V0BF_DvMpbEKI5o-sqTpf6cHqjHgWrrleg4WxGkS5SlaCZPyWcvbqjO7s88IkP2BLPMqCiJk21vZzghyNphNRkYxoV-52mhVi8swQWId_s3m5HS5nzuWA48YmJnjTUJEl06jdhMPoBfjgTiLgZW8wZiUZJM0j7tFyDg2h6U0yexTU304UEL9bKmy4kxFL2ewPd Feb 09 07:22:37 volumio volumio[3452]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 09 07:22:37 volumio volumio[3452]: info: New Spotify access token = BQA8cosrQPKcSbibo1OFr_HXAXFoeT9EmPA67cpCizMfMz38PSrRh7ZdJIZtEuB2tkK_JWMUR8cmDJ6ruzaOH6l6VFVO-JvaZFGAabXbiFNJrpD-cNKRy9V0BF_DvMpbEKI5o-sqTpf6cHqjHgWrrleg4WxGkS5SlaCZPyWcvbqjO7s88IkP2BLPMqCiJk21vZzghyNphNRkYxoV-52mhVi8swQWId_s3m5HS5nzuWA48YmJnjTUJEl06jdhMPoBfjgTiLgZW8wZiUZJM0j7tFyDg2h6U0yexTU304UEL9bKmy4kxFL2ewPd Feb 09 07:22:37 volumio volumio[3452]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 09 07:22:37 volumio volumio[3452]: info: Starting Shairport Sync Feb 09 07:22:37 volumio volumio[3452]: info: Starting Shairport Sync Feb 09 07:22:37 volumio volumio[3452]: info: Starting Shairport Sync Feb 09 07:22:37 volumio sudo[3729]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 07:22:37 volumio sudo[3729]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:22:37 volumio sudo[3731]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 07:22:37 volumio sudo[3731]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:22:37 volumio sudo[3733]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 07:22:37 volumio sudo[3733]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:22:38 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 09 07:22:38 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 09 07:22:38 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 07:22:38 volumio systemd[1]: shairport-sync.service: Consumed 2.300s CPU time. Feb 09 07:22:38 volumio volumio[3452]: info: CoreCommandRouter::volumioGetState Feb 09 07:22:38 volumio volumio[3452]: info: CorePlayQueue::getTrack 0 Feb 09 07:22:38 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 07:22:38 volumio sudo[3729]: pam_unix(sudo:session): session closed for user root Feb 09 07:22:38 volumio sudo[3733]: pam_unix(sudo:session): session closed for user root Feb 09 07:22:38 volumio sudo[3731]: pam_unix(sudo:session): session closed for user root Feb 09 07:22:38 volumio volumio[3452]: info: Shairport-Sync Started Feb 09 07:22:38 volumio volumio[3452]: Error adding Membership: Error: addMembership EINVAL Feb 09 07:22:38 volumio volumio[3452]: info: Shairport-Sync Started Feb 09 07:22:38 volumio volumio[3452]: info: Shairport-Sync Started Feb 09 07:22:38 volumio volumio[3452]: 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 09 07:22:38 volumio volumio[3452]: info: Spotify Successfully logged in Feb 09 07:22:38 volumio volumio[3452]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 07:22:38 volumio volumio[3452]: info: [1770596558364] CoreMusicLibrary::Adding element Spotify Feb 09 07:22:38 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 07:22:38 volumio volumio[3452]: Cannot find translation for source YouTube Music Feb 09 07:22:38 volumio volumio[3452]: Cannot find translation for source Spotify Feb 09 07:22:39 volumio volumio[3452]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 09 07:22:39 volumio volumio[3452]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 07:22:39 volumio volumio[3452]: info: VolumeController:: Volume=100 Mute =false Feb 09 07:22:39 volumio volumio[3452]: info: CoreCommandRouter::volumioGetState Feb 09 07:22:39 volumio volumio[3452]: info: CorePlayQueue::getTrack 0 Feb 09 07:22:39 volumio volumio[3452]: info: CoreStateMachine::pushState Feb 09 07:22:39 volumio volumio[3452]: info: CorePlayQueue::getTrack 0 Feb 09 07:22:39 volumio volumio[3452]: info: CoreCommandRouter::volumioPushState Feb 09 07:22:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 09 07:22:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:22:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:22:40 volumio go-librespot[3768]: go-librespot daemon starting... Feb 09 07:22:40 volumio go-librespot[3769]: time="2026-02-09T07:22:40+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 07:22:40 volumio go-librespot[3769]: time="2026-02-09T07:22:40+07:00" level=debug msg="app state loaded" Feb 09 07:22:40 volumio go-librespot[3769]: time="2026-02-09T07:22:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 07:22:40 volumio volumio[3452]: info: go-librespot daemon successfully initialized Feb 09 07:22:40 volumio mpd[3679]: 2026-02-09T07:22:40 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 09 07:22:40 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 09 07:22:40 volumio sudo[3650]: pam_unix(sudo:session): session closed for user root Feb 09 07:22:40 volumio sudo[3639]: pam_unix(sudo:session): session closed for user root Feb 09 07:22:40 volumio go-librespot[3769]: time="2026-02-09T07:22:40+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 07:22:40 volumio go-librespot[3769]: time="2026-02-09T07:22:40+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 07:22:40 volumio go-librespot[3769]: time="2026-02-09T07:22:40+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 09 07:22:40 volumio go-librespot[3769]: time="2026-02-09T07:22:40+07:00" level=info msg="zeroconf server listening on port 43199" Feb 09 07:22:41 volumio volumio[3452]: error: MPD error: The expression evaluated to a falsy value: Feb 09 07:22:41 volumio volumio[3452]: assert.ok(self.idling) Feb 09 07:22:41 volumio volumio[3452]: error: The expression evaluated to a falsy value: Feb 09 07:22:41 volumio volumio[3452]: assert.ok(self.idling) Feb 09 07:22:41 volumio volumio[3452]: info: MPD running with PID3679 Feb 09 07:22:41 volumio volumio[3452]: ,establishing connection Feb 09 07:22:41 volumio volumio[3452]: error: updateQueue error: null Feb 09 07:22:41 volumio volumio[3452]: info: Completed starting Core Plugins Feb 09 07:22:41 volumio volumio[3452]: info: ------------------------------------------- Feb 09 07:22:41 volumio volumio[3452]: info: ----- MyVolumio plugins startup ---- Feb 09 07:22:41 volumio volumio[3452]: info: ------------------------------------------- Feb 09 07:22:41 volumio volumio[3452]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 09 07:22:41 volumio volumio[3452]: error: updateQueue error: null Feb 09 07:22:41 volumio go-librespot[3769]: time="2026-02-09T07:22:41+07:00" level=debug msg="obtained new client token: AADoTtj0x1YacYeil2gQsLsodVo1TqPJ6eVU6SwKtJkgqSue0os+h/urc/JsPz0kYkTeOtXSiluHFjbEZEjvvUMSPuUsE+3QhV72YbdTJsRn4VH8Q0P4C0EJF4VpVMa6iMIsNJyeBSig4P6E4rm3fu1gwTMkr5P0NGNI73lV2iAUW0wS4qElvyVGskLo56zvN9BoUeLmH4KjDR48/19tZeurTTJb3AXHA25gJ8PM8Ka+3JQ8WRwqg2Y=" Feb 09 07:22:41 volumio go-librespot[3769]: time="2026-02-09T07:22:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 07:22:41 volumio go-librespot[3769]: time="2026-02-09T07:22:41+07:00" level=debug msg="completed keyexchange" Feb 09 07:22:41 volumio go-librespot[3769]: time="2026-02-09T07:22:41+07:00" level=debug msg="completed challenge" Feb 09 07:22:41 volumio go-librespot[3769]: time="2026-02-09T07:22:41+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 07:22:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 07:22:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 07:22:43 volumio volumio[3452]: info: Initializing connection to go-librespot Websocket Feb 09 07:22:43 volumio volumio[3452]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 07:22:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 09 07:22:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:22:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:22:44 volumio go-librespot[3781]: go-librespot daemon starting... Feb 09 07:22:44 volumio go-librespot[3782]: time="2026-02-09T07:22:44+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 07:22:44 volumio go-librespot[3782]: time="2026-02-09T07:22:44+07:00" level=debug msg="app state loaded" Feb 09 07:22:44 volumio go-librespot[3782]: time="2026-02-09T07:22:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 07:22:45 volumio go-librespot[3782]: time="2026-02-09T07:22:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 07:22:45 volumio go-librespot[3782]: time="2026-02-09T07:22:45+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 07:22:45 volumio go-librespot[3782]: time="2026-02-09T07:22:45+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 07:22:45 volumio go-librespot[3782]: time="2026-02-09T07:22:45+07:00" level=info msg="zeroconf server listening on port 33019" Feb 09 07:22:45 volumio go-librespot[3782]: time="2026-02-09T07:22:45+07:00" level=debug msg="obtained new client token: AABtzXSeHC6YI/sL9RzDlVl+O1/Jm5b06jb8QwzLPlz9ooGer7SIgyEG9fMFSe9MSmVprf1Yz9m8Mn5QADwQqrbpERVq2eRu7KMo8/uHEdST7P1g7KPvtSZEenINpJHEVjgsh41lScfuLTpmNYPqY69kDvKEO+jQMdmZrarjuX51QKCiHoBpENlBWJY91Uk4Ouv4VpDqJ7Fp4RGueTq/4WHQcRGBEYWsUsS2Xz1iamg2Pwhk05w0sMu/7Q==" Feb 09 07:22:45 volumio go-librespot[3782]: time="2026-02-09T07:22:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 07:22:45 volumio go-librespot[3782]: time="2026-02-09T07:22:45+07:00" level=debug msg="completed keyexchange" Feb 09 07:22:45 volumio go-librespot[3782]: time="2026-02-09T07:22:45+07:00" level=debug msg="completed challenge" Feb 09 07:22:45 volumio go-librespot[3782]: time="2026-02-09T07:22:45+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 07:22:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 07:22:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 07:22:45 volumio volumio[3452]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 09 07:22:46 volumio volumio[3452]: info: Initializing connection to go-librespot Websocket Feb 09 07:22:46 volumio volumio[3452]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 07:22:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 09 07:22:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:22:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:22:48 volumio go-librespot[3790]: go-librespot daemon starting... Feb 09 07:22:48 volumio go-librespot[3791]: time="2026-02-09T07:22:48+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 07:22:48 volumio go-librespot[3791]: time="2026-02-09T07:22:48+07:00" level=debug msg="app state loaded" Feb 09 07:22:48 volumio go-librespot[3791]: time="2026-02-09T07:22:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 07:22:49 volumio go-librespot[3791]: time="2026-02-09T07:22:49+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 09 07:22:49 volumio go-librespot[3791]: time="2026-02-09T07:22:49+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 09 07:22:49 volumio go-librespot[3791]: time="2026-02-09T07:22:49+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 09 07:22:49 volumio go-librespot[3791]: time="2026-02-09T07:22:49+07:00" level=info msg="zeroconf server listening on port 45679" Feb 09 07:22:49 volumio volumio[3452]: info: Initializing connection to go-librespot Websocket Feb 09 07:22:49 volumio go-librespot[3791]: time="2026-02-09T07:22:49+07:00" level=debug msg="new websocket client" Feb 09 07:22:49 volumio volumio[3452]: info: Connection to go-librespot Websocket established Feb 09 07:22:49 volumio go-librespot[3791]: time="2026-02-09T07:22:49+07:00" level=debug msg="obtained new client token: AABbwzJK36dw1rZPOKmInoDRqiCM2zAGAxuvKH47HfgkL6hDPJi51Q5e3mhDnUY+QSGoXhqs05OKa0aOcdvYqB8ODXtkE1IJxcBJf5KuWbLPNdNOBClK+9kcxqAVQWEuLC7LQ1cidz2viSMiApgXBbhS6z+rWkg21AG2IlTKal8QhADXfGaQxlfBNM1x5S96/fkKnob0onA886wsNHDDUV3jA3qViKA+dVQkO1aY0M0P4cR8qeoFV3JESA==" Feb 09 07:22:49 volumio go-librespot[3791]: time="2026-02-09T07:22:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 07:22:49 volumio volumio[3452]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 09 07:22:49 volumio volumio[3452]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 09 07:22:49 volumio volumio[3452]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 09 07:22:49 volumio volumio[3452]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 09 07:22:49 volumio volumio[3452]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 09 07:22:49 volumio volumio[3452]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 09 07:22:49 volumio volumio[3452]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 09 07:22:49 volumio volumio[3452]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 09 07:22:49 volumio volumio[3452]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 09 07:22:49 volumio volumio[3452]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 09 07:22:49 volumio volumio[3452]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 09 07:22:49 volumio volumio[3452]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 09 07:22:49 volumio volumio[3452]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 09 07:22:49 volumio volumio[3452]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 09 07:22:49 volumio volumio[3452]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 09 07:22:49 volumio volumio[3452]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 09 07:22:49 volumio volumio[3452]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 09 07:22:49 volumio volumio[3452]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 09 07:22:49 volumio volumio[3452]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 09 07:22:49 volumio volumio[3452]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 09 07:22:49 volumio volumio[3452]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 09 07:22:49 volumio volumio[3452]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 09 07:22:49 volumio volumio[3452]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 09 07:22:49 volumio volumio[3452]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 09 07:22:49 volumio volumio[3452]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 09 07:22:49 volumio volumio[3452]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 09 07:22:49 volumio volumio[3452]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 09 07:22:49 volumio volumio[3452]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 09 07:22:49 volumio volumio[3452]: info: Adding plugin bluetooth to MyMusic Plugins Feb 09 07:22:49 volumio volumio[3452]: info: Adding plugin multiroom to MyMusic Plugins Feb 09 07:22:49 volumio volumio[3452]: info: Adding plugin metavolumio to MyMusic Plugins Feb 09 07:22:49 volumio volumio[3452]: info: Adding plugin cd_controller to MyMusic Plugins Feb 09 07:22:49 volumio volumio[3452]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 09 07:22:49 volumio volumio[3452]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 09 07:22:49 volumio volumio[3452]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 09 07:22:49 volumio volumio[3452]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 09 07:22:49 volumio go-librespot[3791]: time="2026-02-09T07:22:49+07:00" level=debug msg="completed keyexchange" Feb 09 07:22:49 volumio go-librespot[3791]: time="2026-02-09T07:22:49+07:00" level=debug msg="completed challenge" Feb 09 07:22:49 volumio go-librespot[3791]: time="2026-02-09T07:22:49+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 07:22:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 07:22:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 07:22:51 volumio volumio[3452]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 09 07:22:51 volumio volumio[3452]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 09 07:22:51 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 07:22:51 volumio volumio[3452]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 07:22:51 volumio volumio[3452]: info: Starting MyVolumio Remote Streaming Endpoints Feb 09 07:22:51 volumio volumio[3452]: info: MyVolumio login type: Token Feb 09 07:22:51 volumio volumio[3452]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 09 07:22:51 volumio volumio[3452]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 09 07:22:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 09 07:22:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:22:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:22:53 volumio go-librespot[3812]: go-librespot daemon starting... Feb 09 07:22:53 volumio go-librespot[3813]: time="2026-02-09T07:22:53+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 07:22:53 volumio go-librespot[3813]: time="2026-02-09T07:22:53+07:00" level=debug msg="app state loaded" Feb 09 07:22:53 volumio go-librespot[3813]: time="2026-02-09T07:22:53+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 07:22:53 volumio volumio[3452]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 09 07:22:53 volumio volumio[3452]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 09 07:22:53 volumio volumio[3452]: info: Streaming services startup Feb 09 07:22:53 volumio volumio[3452]: info: Starting Streaming Daemon Feb 09 07:22:53 volumio sudo[3823]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 09 07:22:53 volumio volumio[3452]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 09 07:22:53 volumio sudo[3823]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:22:53 volumio sudo[3823]: pam_unix(sudo:session): session closed for user root Feb 09 07:22:53 volumio volumio[3452]: info: Getting Spotify volume Feb 09 07:22:53 volumio go-librespot[3813]: time="2026-02-09T07:22:53+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 07:22:53 volumio go-librespot[3813]: time="2026-02-09T07:22:53+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 07:22:53 volumio go-librespot[3813]: time="2026-02-09T07:22:53+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 07:22:53 volumio volumio[3452]: info: Connection to go-librespot Websocket closed Feb 09 07:22:53 volumio volumio[3452]: error: Cannot start Volumio Streaming Daemon Feb 09 07:22:53 volumio volumio[3452]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 09 07:22:53 volumio volumio[3452]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 09 07:22:53 volumio go-librespot[3813]: time="2026-02-09T07:22:53+07:00" level=info msg="zeroconf server listening on port 39877" Feb 09 07:22:53 volumio volumio[3452]: 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 09 07:22:54 volumio volumio[3452]: info: CoreCommandRouter::volumioGetState Feb 09 07:22:54 volumio volumio[3452]: info: CorePlayQueue::getTrack 0 Feb 09 07:22:54 volumio go-librespot[3813]: time="2026-02-09T07:22:54+07:00" level=debug msg="obtained new client token: AACwGQpLhBfJlCRGGVCrICbYCgLPOEDEdbzvgQjwgv9c4N2asxGRjY0xs/s6LXV2wT0fF3Ah1iX9aV9hGw0hVsHWHlzo7qJezTF4wCb2rAMe9VcZDRJRkGI4zjuPu47JdjITY2f6oMy1Vav+qXe+q251JwjTKjey6DfzPosVs0IQ1dhtvutNO1+MkwpNFK25orCkxY5qYGiHcadC4NvTiMRJjoUUXe5hkp2CxZIaetd06x0XVXFaIAONDg==" Feb 09 07:22:54 volumio volumio[3452]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 09 07:22:54 volumio volumio[3452]: SPOTIFY: SPOTIFY VOLUME undefined Feb 09 07:22:54 volumio volumio[3452]: SPOTIFY: VOLUMIO VOLUME 100 Feb 09 07:22:54 volumio volumio[3452]: info: Aligning Spotify Volume to Volumio Volume Feb 09 07:22:54 volumio volumio[3452]: info: CoreCommandRouter::volumioGetState Feb 09 07:22:54 volumio volumio[3452]: info: CorePlayQueue::getTrack 0 Feb 09 07:22:54 volumio volumio[3452]: info: Setting Spotify Volume from Volumio: 100 Feb 09 07:22:54 volumio go-librespot[3813]: time="2026-02-09T07:22:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 07:22:54 volumio go-librespot[3813]: time="2026-02-09T07:22:54+07:00" level=debug msg="completed keyexchange" Feb 09 07:22:54 volumio go-librespot[3813]: time="2026-02-09T07:22:54+07:00" level=debug msg="completed challenge" Feb 09 07:22:54 volumio go-librespot[3813]: time="2026-02-09T07:22:54+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 09 07:22:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 07:22:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 07:22:54 volumio volumio[3452]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 07:22:54 volumio volumio[3452]: Error: socket hang up Feb 09 07:22:54 volumio volumio[3452]: at connResetException (node:internal/errors:720:14) Feb 09 07:22:54 volumio volumio[3452]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 09 07:22:54 volumio volumio[3452]: at Socket.emit (node:events:526:35) Feb 09 07:22:54 volumio volumio[3452]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 09 07:22:54 volumio volumio[3452]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 09 07:22:54 volumio volumio[3452]: code: 'ECONNRESET', Feb 09 07:22:54 volumio volumio[3452]: response: undefined Feb 09 07:22:54 volumio volumio[3452]: } Feb 09 07:22:54 volumio volumio[3452]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 07:22:55 volumio sudo[3843]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-09 07:21' Feb 09 07:22:55 volumio sudo[3843]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:22:56 volumio sudo[3843]: pam_unix(sudo:session): session closed for user root Feb 09 07:22:56 volumio volumio-remote-updater[643]: [2026-02-09 07:22:56] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 09 07:22:56 volumio volumio-remote-updater[643]: [2026-02-09 07:22:56] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 09 07:22:56 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 09 07:22:56 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 09 07:22:56 volumio systemd[1]: volumio.service: Consumed 55.570s CPU time. Feb 09 07:22:56 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 07:22:56 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 07:22:56 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8387. Feb 09 07:22:56 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 07:22:56 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 09 07:22:56 volumio systemd[1]: volumio.service: Consumed 55.570s CPU time. Feb 09 07:22:56 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 09 07:22:56 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 07:22:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 09 07:22:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:22:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:22:57 volumio go-librespot[3874]: go-librespot daemon starting... Feb 09 07:22:57 volumio go-librespot[3875]: time="2026-02-09T07:22:57+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 07:22:57 volumio go-librespot[3875]: time="2026-02-09T07:22:57+07:00" level=debug msg="app state loaded" Feb 09 07:22:57 volumio go-librespot[3875]: time="2026-02-09T07:22:57+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 07:22:58 volumio go-librespot[3875]: time="2026-02-09T07:22:58+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 09 07:22:58 volumio go-librespot[3875]: time="2026-02-09T07:22:58+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 09 07:22:58 volumio go-librespot[3875]: time="2026-02-09T07:22:58+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 09 07:22:58 volumio go-librespot[3875]: time="2026-02-09T07:22:58+07:00" level=info msg="zeroconf server listening on port 32809" Feb 09 07:22:58 volumio go-librespot[3875]: time="2026-02-09T07:22:58+07:00" level=debug msg="obtained new client token: AABptDweSuvM0oxy7Vqx/dFPoBnlXmKsbMbycvfDnmlXSgHbY7UHhecx9RTyL9klZq1T81kOkatn2luaTbqIip1ZOhk9ouR6bFKdRokjg1lYnZEHP0NTWpj4gviIpbkjvg3ZC3qTg5zTHWo2v4NJUDeg71fwymVtderHdvw3unk5JSNwTlgvPVEgKIhjPGHA2gvduedpcZTvt8onxRdNaApqKv0HqkEJDpcSJYE0DwZ5zyC037q9LYWumw==" Feb 09 07:22:58 volumio go-librespot[3875]: time="2026-02-09T07:22:58+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 07:22:58 volumio go-librespot[3875]: time="2026-02-09T07:22:58+07:00" level=debug msg="completed keyexchange" Feb 09 07:22:58 volumio go-librespot[3875]: time="2026-02-09T07:22:58+07:00" level=debug msg="completed challenge" Feb 09 07:22:58 volumio go-librespot[3875]: time="2026-02-09T07:22:58+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 09 07:22:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 07:22:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 07:23:00 volumio volumio[3859]: info: ------------------------------------------- Feb 09 07:23:00 volumio volumio[3859]: info: ----- Volumio3 ---- Feb 09 07:23:00 volumio volumio[3859]: info: ------------------------------------------- Feb 09 07:23:00 volumio volumio[3859]: info: ----- System startup ---- Feb 09 07:23:00 volumio volumio[3859]: info: ------------------------------------------- Feb 09 07:23:01 volumio volumio-remote-updater[643]: [2026-02-09 07:23:01] [connect] Successful connection Feb 09 07:23:01 volumio volumio[3859]: info: MYVOLUMIO Environment detected Feb 09 07:23:01 volumio volumio[3859]: info: Plugin folders cleanup Feb 09 07:23:01 volumio volumio[3859]: info: Scanning into folder /volumio/app/plugins/ Feb 09 07:23:01 volumio volumio[3859]: info: Scanning category audio_interface Feb 09 07:23:01 volumio volumio[3859]: info: Scanning category miscellanea Feb 09 07:23:01 volumio volumio[3859]: info: Scanning category music_service Feb 09 07:23:01 volumio volumio[3859]: info: Scanning category plugins.json Feb 09 07:23:01 volumio volumio[3859]: info: Scanning category system_controller Feb 09 07:23:01 volumio volumio[3859]: info: Scanning category user_interface Feb 09 07:23:01 volumio volumio[3859]: info: Scanning into folder /data/plugins/ Feb 09 07:23:01 volumio volumio[3859]: info: Scanning category music_service Feb 09 07:23:01 volumio volumio[3859]: info: Plugin folders cleanup completed Feb 09 07:23:01 volumio volumio[3859]: info: ------------------------------------------- Feb 09 07:23:01 volumio volumio[3859]: info: ----- Core plugins startup ---- Feb 09 07:23:01 volumio volumio[3859]: info: ------------------------------------------- Feb 09 07:23:01 volumio volumio[3859]: info: Loading plugins from folder /volumio/app/plugins/ Feb 09 07:23:01 volumio volumio[3859]: info: Adding plugin upnp to MyMusic Plugins Feb 09 07:23:01 volumio volumio[3859]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 09 07:23:01 volumio volumio[3859]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 09 07:23:01 volumio volumio[3859]: info: Loading plugins from folder /data/plugins/ Feb 09 07:23:01 volumio volumio[3859]: info: Loading plugin "system"... Feb 09 07:23:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 09 07:23:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:23:01 volumio volumio[3859]: info: Loading plugin "appearance"... Feb 09 07:23:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:23:01 volumio go-librespot[3892]: go-librespot daemon starting... Feb 09 07:23:01 volumio go-librespot[3896]: time="2026-02-09T07:23:01+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 07:23:01 volumio go-librespot[3896]: time="2026-02-09T07:23:01+07:00" level=debug msg="app state loaded" Feb 09 07:23:01 volumio go-librespot[3896]: time="2026-02-09T07:23:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 07:23:02 volumio go-librespot[3896]: time="2026-02-09T07:23:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 07:23:02 volumio go-librespot[3896]: time="2026-02-09T07:23:02+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 09 07:23:02 volumio go-librespot[3896]: time="2026-02-09T07:23:02+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 09 07:23:02 volumio go-librespot[3896]: time="2026-02-09T07:23:02+07:00" level=info msg="zeroconf server listening on port 41631" Feb 09 07:23:02 volumio go-librespot[3896]: time="2026-02-09T07:23:02+07:00" level=debug msg="obtained new client token: AAA1b2WMIKacWIG1TXPXYUlJUHMHfNwZoqhjgWYYJ8suTxXoA6tvL+L2fk7EFZUknqLyYyiq23dq922fybSza+7M/JGz7QXNSsczPcy/y/Oso8Tlhw8YGZVE6gtpDPYjez50YAZfnlgFAFdNIyWhCsH7442XvEtvYmMpp4V7+HXNfyh2DRJlxwN0uyqTEkVWsJR6aW4AKZWJennHt2L9nl+LavLpYc1k/xaYsMbdAhMqT1aHwbsMTrhXjQ==" Feb 09 07:23:02 volumio go-librespot[3896]: time="2026-02-09T07:23:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 07:23:02 volumio go-librespot[3896]: time="2026-02-09T07:23:02+07:00" level=debug msg="completed keyexchange" Feb 09 07:23:02 volumio go-librespot[3896]: time="2026-02-09T07:23:02+07:00" level=debug msg="completed challenge" Feb 09 07:23:02 volumio go-librespot[3896]: time="2026-02-09T07:23: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 09 07:23:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 07:23:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 07:23:03 volumio volumio[3859]: info: Loading plugin "network"... Feb 09 07:23:03 volumio volumio[3859]: info: Refreshing Cached IP Addresses Feb 09 07:23:03 volumio sudo[3904]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 07:23:03 volumio sudo[3904]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:23:03 volumio sudo[3906]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 07:23:03 volumio sudo[3906]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:23:03 volumio volumio[3859]: info: Loading plugin "services"... Feb 09 07:23:03 volumio sudo[3904]: pam_unix(sudo:session): session closed for user root Feb 09 07:23:03 volumio sudo[3906]: pam_unix(sudo:session): session closed for user root Feb 09 07:23:03 volumio volumio[3859]: info: Loading plugin "alsa_controller"... Feb 09 07:23:03 volumio sudo[3914]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 09 07:23:03 volumio sudo[3914]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:23:04 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 07:23:04 volumio volumio[3859]: info: Loading plugin "wizard"... Feb 09 07:23:04 volumio volumio[3859]: info: Loading plugin "networkfs"... Feb 09 07:23:04 volumio volumio[3859]: info: Starting Udev Watcher for removable devices Feb 09 07:23:04 volumio volumio[3859]: info: Ignoring mount for partition: boot Feb 09 07:23:04 volumio volumio[3859]: info: Ignoring mount for partition: volumio Feb 09 07:23:04 volumio volumio[3859]: info: Ignoring mount for partition: volumio_data Feb 09 07:23:04 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 07:23:04 volumio volumio[3859]: info: Loading plugin "volumio_command_line_client"... Feb 09 07:23:04 volumio volumio[3859]: info: Loading plugin "upnp"... Feb 09 07:23:04 volumio volumio[3859]: info: [1770596584213] Starting Upmpd Daemon Feb 09 07:23:04 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 07:23:04 volumio volumio[3859]: info: Loading plugin "my_music"... Feb 09 07:23:04 volumio volumio[3859]: info: Loading plugin "mpd"... Feb 09 07:23:04 volumio volumio[3859]: info: Loading plugin "upnp_browser"... Feb 09 07:23:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 09 07:23:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:23:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:23:06 volumio go-librespot[3937]: go-librespot daemon starting... Feb 09 07:23:06 volumio go-librespot[3938]: time="2026-02-09T07:23:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 07:23:06 volumio go-librespot[3938]: time="2026-02-09T07:23:06+07:00" level=debug msg="app state loaded" Feb 09 07:23:06 volumio go-librespot[3938]: time="2026-02-09T07:23:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 07:23:06 volumio go-librespot[3938]: time="2026-02-09T07:23:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 07:23:06 volumio go-librespot[3938]: time="2026-02-09T07:23:06+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 09 07:23:06 volumio go-librespot[3938]: time="2026-02-09T07:23:06+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 09 07:23:06 volumio go-librespot[3938]: time="2026-02-09T07:23:06+07:00" level=info msg="zeroconf server listening on port 40271" Feb 09 07:23:06 volumio sudo[3914]: pam_unix(sudo:session): session closed for user root Feb 09 07:23:06 volumio go-librespot[3938]: time="2026-02-09T07:23:06+07:00" level=debug msg="obtained new client token: AAAzA9/CubQ6khQd8DH50SsT4E3SPYAIrsTXrMH7Cq4uP+Bjv0WQ3Tlv3RiTnQEclervw+yADXNsiojFb2b5jwZ02eXzSO2Crzkpj0z04I+kPY0VlczqXXidibaMutyRGG4QDYlWxHQpDEhA+BZXZEN41HyL+eeXVL0QJ5q9/fnT0oK05+mZ+ogXJCFws1cp9wt0cvsbUmqxx9NDOn2au8V04DXBEkwdLwqywR1FoIhrSKFkogD9GzR9mg==" Feb 09 07:23:07 volumio go-librespot[3938]: time="2026-02-09T07:23:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 07:23:07 volumio go-librespot[3938]: time="2026-02-09T07:23:07+07:00" level=debug msg="completed keyexchange" Feb 09 07:23:07 volumio go-librespot[3938]: time="2026-02-09T07:23:07+07:00" level=debug msg="completed challenge" Feb 09 07:23:07 volumio go-librespot[3938]: time="2026-02-09T07:23:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 07:23:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 07:23:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 07:23:07 volumio volumio[3859]: info: Starting UPNP Browser Feb 09 07:23:07 volumio volumio[3859]: info: Loading plugin "alarm-clock"... Feb 09 07:23:08 volumio volumio[3859]: info: Loading plugin "airplay_emulation"... Feb 09 07:23:08 volumio volumio[3859]: info: Starting Shairport Sync Feb 09 07:23:08 volumio volumio[3859]: info: Loading plugin "last_100"... Feb 09 07:23:08 volumio volumio[3859]: info: Loading plugin "webradio"... Feb 09 07:23:08 volumio volumio[3859]: info: Loading plugin "i2s_dacs"... Feb 09 07:23:08 volumio volumio[3859]: info: Loading plugin "volumiodiscovery"... Feb 09 07:23:08 volumio volumio[3859]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 07:23:08 volumio volumio[3859]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 07:23:08 volumio volumio[3859]: *** WARNING *** For more information see Feb 09 07:23:08 volumio volumio[3859]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 07:23:08 volumio volumio[3859]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 07:23:08 volumio volumio[3859]: *** WARNING *** For more information see Feb 09 07:23:08 volumio node[3859]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 07:23:08 volumio node[3859]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 07:23:08 volumio node[3859]: *** WARNING *** For more information see Feb 09 07:23:08 volumio node[3859]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 07:23:08 volumio node[3859]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 07:23:08 volumio node[3859]: *** WARNING *** For more information see Feb 09 07:23:08 volumio volumio[3859]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 09 07:23:08 volumio volumio[3859]: info: Discovery: Started advertising with name: Volumio Feb 09 07:23:08 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 07:23:08 volumio volumio[3859]: info: Loading plugin "spop"... Feb 09 07:23:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Feb 09 07:23:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:23:10 volumio volumio[3859]: info: Loading plugin "ytcr"... Feb 09 07:23:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:23:10 volumio go-librespot[3948]: go-librespot daemon starting... Feb 09 07:23:10 volumio go-librespot[3949]: time="2026-02-09T07:23:10+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 07:23:10 volumio go-librespot[3949]: time="2026-02-09T07:23:10+07:00" level=debug msg="app state loaded" Feb 09 07:23:10 volumio go-librespot[3949]: time="2026-02-09T07:23:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 07:23:11 volumio go-librespot[3949]: time="2026-02-09T07:23:11+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 09 07:23:11 volumio go-librespot[3949]: time="2026-02-09T07:23:11+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 09 07:23:11 volumio go-librespot[3949]: time="2026-02-09T07:23:11+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 09 07:23:11 volumio go-librespot[3949]: time="2026-02-09T07:23:11+07:00" level=info msg="zeroconf server listening on port 40237" Feb 09 07:23:11 volumio go-librespot[3949]: time="2026-02-09T07:23:11+07:00" level=debug msg="obtained new client token: AADOBpuV0S24EfkuJa/hYjSKFJNxh3lHn3aPgatkUaiYi8IdX095kT3fsmBlwisSc3tJcNkDkQRnwUFjFxdTdsPvnmIgqQx0HyVRQC7saAi1dDZhgitjfFSN+sXSRK9jTM+D90xk76f0p5EC2som37Tw/fvGI6CwW1EAH2yoOIm52PXxXDNi7BTEeCuCOqKN6T0VWQf2BL/tyuWarxhI78i6h5hogAYPxUhRgV52V/SesefuneOAfIMJDg==" Feb 09 07:23:11 volumio go-librespot[3949]: time="2026-02-09T07:23:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 07:23:11 volumio go-librespot[3949]: time="2026-02-09T07:23:11+07:00" level=debug msg="completed keyexchange" Feb 09 07:23:11 volumio go-librespot[3949]: time="2026-02-09T07:23:11+07:00" level=debug msg="completed challenge" Feb 09 07:23:11 volumio go-librespot[3949]: time="2026-02-09T07:23:11+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 07:23:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 07:23:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 07:23:13 volumio volumio[3859]: info: Loading plugin "ytmusic"... Feb 09 07:23:13 volumio volumio-remote-updater[643]: [2026-02-09 07:23:13] [connect] Successful connection Feb 09 07:23:14 volumio volumio[3859]: info: Loading plugin "outputs"... Feb 09 07:23:14 volumio volumio[3859]: info: Loading plugin "albumart"... Feb 09 07:23:14 volumio volumio[3859]: info: Plugin example_plugin is not enabled Feb 09 07:23:14 volumio volumio[3859]: info: Loading plugin "inputs"... Feb 09 07:23:14 volumio volumio[3859]: info: Loading plugin "updater_comm"... Feb 09 07:23:14 volumio volumio[3859]: info: Plugin mpdemulation is not enabled Feb 09 07:23:14 volumio volumio[3859]: info: Loading plugin "rest_api"... Feb 09 07:23:14 volumio volumio[3859]: info: Loading plugin "websocket"... Feb 09 07:23:14 volumio volumio[3859]: info: Starting Socket.io Server version 1.7.4 Feb 09 07:23:14 volumio volumio[3859]: info: Loading plugin "RoonBridge"... Feb 09 07:23:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Feb 09 07:23:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:23:14 volumio volumio[3859]: info: Applying required configuration parameters for plugin RoonBridge Feb 09 07:23:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:23:14 volumio go-librespot[3981]: go-librespot daemon starting... Feb 09 07:23:14 volumio volumio[3859]: info: Loading i18n strings for locale en Feb 09 07:23:14 volumio go-librespot[3982]: time="2026-02-09T07:23:14+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 07:23:14 volumio go-librespot[3982]: time="2026-02-09T07:23:14+07:00" level=debug msg="app state loaded" Feb 09 07:23:14 volumio go-librespot[3982]: time="2026-02-09T07:23:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 07:23:14 volumio volumio[3859]: Updating browse sources language Feb 09 07:23:15 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 07:23:15 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 07:23:15 volumio volumio[3859]: info: CoreCommandRouter::initPlayerControls Feb 09 07:23:15 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:23:15 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:23:15 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:23:15 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:23:15 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:23:15 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:23:15 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:23:15 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:23:15 volumio volumio[3971]: Forking 3 albumart workers Feb 09 07:23:15 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 07:23:15 volumio volumio[3859]: Express server listening on port 3000 Feb 09 07:23:15 volumio volumio[3859]: [Metrics] WebUI: 15s 970.80ms Feb 09 07:23:15 volumio volumio[3859]: info: CoreStateMachine::resetVolumioState Feb 09 07:23:15 volumio volumio[3859]: info: CoreStateMachine::getcurrentVolume Feb 09 07:23:15 volumio volumio[3859]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 07:23:15 volumio sudo[4022]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 07:23:15 volumio sudo[4022]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:23:15 volumio sudo[4024]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 07:23:15 volumio sudo[4024]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:23:15 volumio sudo[4024]: pam_unix(sudo:session): session closed for user root Feb 09 07:23:15 volumio sudo[4022]: pam_unix(sudo:session): session closed for user root Feb 09 07:23:15 volumio go-librespot[3982]: time="2026-02-09T07:23:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 07:23:15 volumio go-librespot[3982]: time="2026-02-09T07:23:15+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 09 07:23:15 volumio go-librespot[3982]: time="2026-02-09T07:23:15+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 09 07:23:15 volumio go-librespot[3982]: time="2026-02-09T07:23:15+07:00" level=info msg="zeroconf server listening on port 44169" Feb 09 07:23:15 volumio volumio[3859]: info: Volumio Network Manager: Network status updated: 1 Feb 09 07:23:15 volumio go-librespot[3982]: time="2026-02-09T07:23:15+07:00" level=debug msg="obtained new client token: AACq4cmc9kc2ue60PLrUC/AfZa69DLKYukruFd7KD/gmLqNE56GQeBnhjV4hLjux6RtRSh8KBvr0kDxGMdi7gu4Iu1/oCAtDZd+8tzdsoh1XbqsgY5Z94NWCCdW3/hHkKhNB6nZqawIFgqSnc5jFylcaBrSJ93ZkpYlNLB/r75nze1Wkc/TU5vs0jLty2HAWudxE/daLB//Lgyho90rjtybXWEBx/gVBiwXWwVuCurMhpTKJUtznYMLU7Q==" Feb 09 07:23:16 volumio volumio[3859]: info: VolumeController:: Volume=100 Mute =false Feb 09 07:23:16 volumio volumio[3859]: info: CoreStateMachine::pushState Feb 09 07:23:16 volumio volumio[3859]: info: CorePlayQueue::getTrack 0 Feb 09 07:23:16 volumio go-librespot[3982]: time="2026-02-09T07:23:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 07:23:16 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 07:23:16 volumio volumio[3859]: info: CoreCommandRouter::volumioPushState Feb 09 07:23:16 volumio volumio[3859]: info: CoreStateMachine::updateTrackBlock Feb 09 07:23:16 volumio volumio[3859]: info: CorePlayQueue::getTrackBlock Feb 09 07:23:16 volumio volumio[3859]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 07:23:16 volumio volumio-remote-updater[643]: [2026-02-09 07:23:16] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770596593 101 Feb 09 07:23:16 volumio volumio[3859]: 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 09 07:23:16 volumio go-librespot[3982]: time="2026-02-09T07:23:16+07:00" level=debug msg="completed keyexchange" Feb 09 07:23:16 volumio go-librespot[3982]: time="2026-02-09T07:23:16+07:00" level=debug msg="completed challenge" Feb 09 07:23:16 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 07:23:16 volumio volumio[3859]: info: Reloading queue from file Feb 09 07:23:16 volumio go-librespot[3982]: time="2026-02-09T07:23:16+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 09 07:23:16 volumio volumio[3859]: info: CoreStateMachine::setRepeat null single undefined Feb 09 07:23:16 volumio volumio[3859]: info: CoreStateMachine::pushState Feb 09 07:23:16 volumio volumio[3859]: info: CorePlayQueue::getTrack 0 Feb 09 07:23:16 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 07:23:16 volumio volumio[3859]: info: CoreCommandRouter::volumioPushState Feb 09 07:23:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 07:23:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 07:23:16 volumio volumio[3859]: info: CoreStateMachine::setRandom null Feb 09 07:23:16 volumio volumio[3859]: info: CoreStateMachine::pushState Feb 09 07:23:16 volumio volumio[3859]: info: CorePlayQueue::getTrack 0 Feb 09 07:23:16 volumio volumio[3859]: info: CoreCommandRouter::volumioPushState Feb 09 07:23:16 volumio volumio[3859]: info: Setting Device type: Raspberry PI Feb 09 07:23:16 volumio volumio[3859]: info: Completed loading Core Plugins Feb 09 07:23:16 volumio volumio[3859]: info: Preparing to generate the ALSA configuration file Feb 09 07:23:16 volumio volumio[3859]: info: VolumeController:: Volume=100 Mute =false Feb 09 07:23:16 volumio volumio[3859]: info: CoreStateMachine::pushState Feb 09 07:23:16 volumio volumio[3859]: info: CorePlayQueue::getTrack 0 Feb 09 07:23:16 volumio volumio[3859]: info: CoreCommandRouter::volumioPushState Feb 09 07:23:16 volumio volumio[3859]: info: Asound.conf file unchanged, so no further update is needed Feb 09 07:23:16 volumio volumio[3859]: info: Output device has changed, restarting MPD Feb 09 07:23:16 volumio volumio[3859]: info: Output device has changed, restarting Shairport Sync Feb 09 07:23:16 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:23:16 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 07:23:16 volumio sudo[4041]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 09 07:23:16 volumio sudo[4041]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:23:16 volumio volumio[3859]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 07:23:16 volumio sudo[4043]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 07:23:16 volumio volumio[3859]: info: ___________ START PLUGINS ___________ Feb 09 07:23:16 volumio sudo[4045]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 07:23:16 volumio sudo[4043]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:23:16 volumio sudo[4045]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:23:16 volumio sudo[4043]: pam_unix(sudo:session): session closed for user root Feb 09 07:23:16 volumio volumio[3859]: info: ControllerMpd::onStart: Initializing MPD Feb 09 07:23:16 volumio volumio[3859]: info: Creating MPD Configuration file Feb 09 07:23:16 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 07:23:16 volumio volumio[3859]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 07:23:16 volumio volumio[3859]: info: [1770596596815] CoreMusicLibrary::Adding element Media Servers Feb 09 07:23:16 volumio sudo[4056]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 07:23:16 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 09 07:23:16 volumio sudo[4056]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:23:16 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 07:23:16 volumio sudo[4041]: pam_unix(sudo:session): session closed for user root Feb 09 07:23:16 volumio sudo[4054]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 07:23:16 volumio sudo[4054]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:23:16 volumio volumio[3859]: info: UPNP Browser: Client initialized successfully Feb 09 07:23:16 volumio sudo[4054]: pam_unix(sudo:session): session closed for user root Feb 09 07:23:16 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:23:17 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 07:23:17 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 09 07:23:17 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 07:23:17 volumio systemd[1]: mpd.service: Consumed 7.154s CPU time. Feb 09 07:23:17 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 09 07:23:17 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 07:23:17 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 07:23:17 volumio volumio[3859]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 07:23:17 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:23:17 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 07:23:17 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 07:23:17 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 07:23:17 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 09 07:23:17 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 07:23:17 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 09 07:23:17 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 07:23:17 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 07:23:17 volumio volumio[3859]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 07:23:17 volumio volumio[3859]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 07:23:17 volumio volumio[3859]: info: [1770596597164] CoreMusicLibrary::Adding element Last_100 Feb 09 07:23:17 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 07:23:17 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 07:23:17 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 07:23:17 volumio volumio[3859]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 07:23:17 volumio volumio[3859]: info: [1770596597205] CoreMusicLibrary::Adding element Webradio Feb 09 07:23:17 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 07:23:17 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 07:23:17 volumio volumio[3859]: info: Initializing BBC Radios Feb 09 07:23:17 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 07:23:17 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 07:23:17 volumio volumio[3859]: info: Creating Spotify config file Feb 09 07:23:17 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:23:17 volumio sudo[4070]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 09 07:23:17 volumio sudo[4070]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 09 07:23:17 volumio sudo[4070]: pam_unix(sudo:session): session closed for user root Feb 09 07:23:18 volumio volumio[3993]: Starting albumart workers Feb 09 07:23:18 volumio volumio[3859]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 07:23:18 volumio volumio[3859]: info: [1770596598547] CoreMusicLibrary::Adding element YouTube Music Feb 09 07:23:18 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 07:23:18 volumio volumio[3859]: Cannot find translation for source YouTube Music Feb 09 07:23:18 volumio volumio[3859]: info: Volumio Calling Home Feb 09 07:23:18 volumio sudo[4087]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 09 07:23:18 volumio sudo[4087]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:23:18 volumio volumio[3990]: Starting albumart workers Feb 09 07:23:18 volumio sudo[4087]: pam_unix(sudo:session): session closed for user root Feb 09 07:23:19 volumio volumio[3988]: Starting albumart workers Feb 09 07:23:19 volumio volumio[3859]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 09 07:23:19 volumio volumio[3859]: info: Discovery: Found device Volumio Feb 09 07:23:19 volumio volumio[3859]: info: CoreCommandRouter::volumioGetState Feb 09 07:23:19 volumio volumio[3859]: info: CorePlayQueue::getTrack 0 Feb 09 07:23:19 volumio volumio[3859]: info: MPD Permissions set Feb 09 07:23:19 volumio volumio[3859]: info: MPD Permissions set Feb 09 07:23:19 volumio volumio[3859]: info: Upmpdcli Daemon Started Feb 09 07:23:19 volumio volumio[3859]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 09 07:23:19 volumio volumio[3859]: info: Discovery: Found device Volumio Feb 09 07:23:19 volumio volumio[3859]: info: CoreCommandRouter::volumioGetState Feb 09 07:23:19 volumio volumio[3859]: info: CorePlayQueue::getTrack 0 Feb 09 07:23:19 volumio volumio[3859]: info: Spotify config file written Feb 09 07:23:19 volumio volumio[3859]: 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 09 07:23:19 volumio sudo[4093]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 09 07:23:19 volumio sudo[4093]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:23:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Feb 09 07:23:19 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:23:19 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:23:19 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:23:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:23:19 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:23:19 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:23:19 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:23:19 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:23:19 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:23:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:23:19 volumio go-librespot[4095]: go-librespot daemon starting... Feb 09 07:23:19 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 09 07:23:19 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 07:23:19 volumio systemd[1]: go-librespot-daemon.service: Killing process 4102 (go-librespot) with signal SIGKILL. Feb 09 07:23:19 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:23:19 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 09 07:23:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:23:19 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:23:19 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:23:19 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:23:19 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:23:19 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:23:19 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:23:19 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:23:19 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:23:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:23:19 volumio go-librespot[4107]: go-librespot daemon starting... Feb 09 07:23:19 volumio sudo[4093]: pam_unix(sudo:session): session closed for user root Feb 09 07:23:19 volumio go-librespot[4110]: time="2026-02-09T07:23:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 07:23:19 volumio go-librespot[4110]: time="2026-02-09T07:23:19+07:00" level=debug msg="app state loaded" Feb 09 07:23:19 volumio go-librespot[4110]: time="2026-02-09T07:23:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 07:23:19 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 07:23:19 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:23:19 volumio volumio[3859]: info: No need to fix Spotify hosts Feb 09 07:23:20 volumio go-librespot[4110]: time="2026-02-09T07:23:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 07:23:20 volumio go-librespot[4110]: time="2026-02-09T07:23:20+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 09 07:23:20 volumio go-librespot[4110]: time="2026-02-09T07:23:20+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 09 07:23:20 volumio go-librespot[4110]: time="2026-02-09T07:23:20+07:00" level=info msg="zeroconf server listening on port 41055" Feb 09 07:23:20 volumio volumio[3859]: info: Volumio called home Feb 09 07:23:20 volumio go-librespot[4110]: time="2026-02-09T07:23:20+07:00" level=debug msg="obtained new client token: AAABmGCD6O5f9jIkGcsAAnM/LcLBBxMlhB7obt2TJIwHPwXcOO8sy9bIILqc7O67YA9iYoAgT3QN3lLOghv9PKjVxCjf1Jf3yTzWTwMoG7AH4hZP9A8ab7WKkJVkIemdZ2VeFP4r5Nf6jPxGhMZDJSGCXrAbz238sX5HiFHdCEcdS7+SUemiTAMXG7wSN6A7sx2pNZe2+Hl4kkHuDSs/mNB9KHMYpQspk/bVFOrv5euVpjqoUVUaDfdEkg==" Feb 09 07:23:20 volumio go-librespot[4110]: time="2026-02-09T07:23:20+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 09 07:23:21 volumio go-librespot[4110]: time="2026-02-09T07:23:21+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Feb 09 07:23:21 volumio go-librespot[4110]: time="2026-02-09T07:23:21+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:80, retrying with a different AP" error="dial tcp 104.199.241.202:80: connect: connection refused" Feb 09 07:23:21 volumio volumio[3859]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 09 07:23:21 volumio volumio[3859]: SPOTIFY: BQDW00ChSBLWrr-Tei84GgrvqxH_94Ntb6XmSpNq1vF8dVyR10CY0nzrpnOoKN898tEnSo_c5mROHE2rtaRL9mNu9yXexOFHD_yAqEq5Vc2apl6RaS-ALmCHk6-CDpZE2DfU-VIvPc6eIydU8l2fgXfKGmzq9pBx3RR5ubuTsu6W5OXe2PcKNZf6rcszz0IMAH0yilkyKZVcNBINXAa87qPmnj86A0FAJmaKhdf0PjDWtUyVlGOkgWlP6r_g6a9uOvsz5pMWqut4MRFm-Mng4SE9Sz3iCLTOf6GKkKbZ18hkNv0LalRJ2d4Z Feb 09 07:23:21 volumio volumio[3859]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 09 07:23:21 volumio volumio[3859]: info: New Spotify access token = BQDW00ChSBLWrr-Tei84GgrvqxH_94Ntb6XmSpNq1vF8dVyR10CY0nzrpnOoKN898tEnSo_c5mROHE2rtaRL9mNu9yXexOFHD_yAqEq5Vc2apl6RaS-ALmCHk6-CDpZE2DfU-VIvPc6eIydU8l2fgXfKGmzq9pBx3RR5ubuTsu6W5OXe2PcKNZf6rcszz0IMAH0yilkyKZVcNBINXAa87qPmnj86A0FAJmaKhdf0PjDWtUyVlGOkgWlP6r_g6a9uOvsz5pMWqut4MRFm-Mng4SE9Sz3iCLTOf6GKkKbZ18hkNv0LalRJ2d4Z Feb 09 07:23:21 volumio volumio[3859]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 09 07:23:21 volumio volumio[3859]: info: Starting Shairport Sync Feb 09 07:23:21 volumio volumio[3859]: info: Starting Shairport Sync Feb 09 07:23:21 volumio go-librespot[4110]: time="2026-02-09T07:23:21+07:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Feb 09 07:23:21 volumio volumio[3859]: info: Starting Shairport Sync Feb 09 07:23:21 volumio sudo[4139]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 07:23:21 volumio sudo[4139]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:23:21 volumio sudo[4141]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 07:23:21 volumio sudo[4141]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:23:21 volumio sudo[4143]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 07:23:21 volumio sudo[4143]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:23:21 volumio go-librespot[4110]: time="2026-02-09T07:23:21+07:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 09 07:23:21 volumio volumio[3859]: info: CoreCommandRouter::volumioGetState Feb 09 07:23:21 volumio volumio[3859]: info: CorePlayQueue::getTrack 0 Feb 09 07:23:21 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 09 07:23:21 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 09 07:23:21 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 07:23:21 volumio systemd[1]: shairport-sync.service: Consumed 2.234s CPU time. Feb 09 07:23:21 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 07:23:21 volumio sudo[4139]: pam_unix(sudo:session): session closed for user root Feb 09 07:23:21 volumio sudo[4143]: pam_unix(sudo:session): session closed for user root Feb 09 07:23:21 volumio sudo[4141]: pam_unix(sudo:session): session closed for user root Feb 09 07:23:21 volumio go-librespot[4110]: time="2026-02-09T07:23:21+07:00" level=debug msg="completed keyexchange" Feb 09 07:23:21 volumio go-librespot[4110]: time="2026-02-09T07:23:21+07:00" level=debug msg="completed challenge" Feb 09 07:23:21 volumio volumio[3859]: info: Shairport-Sync Started Feb 09 07:23:21 volumio volumio[3859]: Error adding Membership: Error: addMembership EINVAL Feb 09 07:23:21 volumio volumio[3859]: info: Shairport-Sync Started Feb 09 07:23:21 volumio volumio[3859]: info: Shairport-Sync Started Feb 09 07:23:22 volumio go-librespot[4110]: time="2026-02-09T07:23:22+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 07:23:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 07:23:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 07:23:22 volumio volumio[3859]: 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 09 07:23:22 volumio volumio[3859]: info: Spotify Successfully logged in Feb 09 07:23:22 volumio volumio[3859]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 07:23:22 volumio volumio[3859]: info: [1770596602188] CoreMusicLibrary::Adding element Spotify Feb 09 07:23:22 volumio volumio[3859]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 07:23:22 volumio volumio[3859]: Cannot find translation for source YouTube Music Feb 09 07:23:22 volumio volumio[3859]: Cannot find translation for source Spotify Feb 09 07:23:22 volumio volumio[3859]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 09 07:23:22 volumio volumio[3859]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 07:23:23 volumio volumio[3859]: info: VolumeController:: Volume=100 Mute =false Feb 09 07:23:23 volumio volumio[3859]: info: CoreCommandRouter::volumioGetState Feb 09 07:23:23 volumio volumio[3859]: info: CorePlayQueue::getTrack 0 Feb 09 07:23:23 volumio volumio[3859]: info: CoreStateMachine::pushState Feb 09 07:23:23 volumio volumio[3859]: info: CorePlayQueue::getTrack 0 Feb 09 07:23:23 volumio volumio[3859]: info: CoreCommandRouter::volumioPushState Feb 09 07:23:24 volumio volumio[3859]: info: go-librespot daemon successfully initialized Feb 09 07:23:24 volumio mpd[4085]: 2026-02-09T07:23:24 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 09 07:23:24 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 09 07:23:24 volumio sudo[4045]: pam_unix(sudo:session): session closed for user root Feb 09 07:23:24 volumio sudo[4056]: pam_unix(sudo:session): session closed for user root Feb 09 07:23:24 volumio volumio[3859]: error: MPD error: The expression evaluated to a falsy value: Feb 09 07:23:24 volumio volumio[3859]: assert.ok(self.idling) Feb 09 07:23:24 volumio volumio[3859]: error: The expression evaluated to a falsy value: Feb 09 07:23:24 volumio volumio[3859]: assert.ok(self.idling) Feb 09 07:23:24 volumio volumio[3859]: error: updateQueue error: null Feb 09 07:23:24 volumio volumio[3859]: info: MPD running with PID4085 Feb 09 07:23:24 volumio volumio[3859]: ,establishing connection Feb 09 07:23:25 volumio volumio[3859]: info: Completed starting Core Plugins Feb 09 07:23:25 volumio volumio[3859]: info: ------------------------------------------- Feb 09 07:23:25 volumio volumio[3859]: info: ----- MyVolumio plugins startup ---- Feb 09 07:23:25 volumio volumio[3859]: info: ------------------------------------------- Feb 09 07:23:25 volumio volumio[3859]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 09 07:23:25 volumio volumio[3859]: error: updateQueue error: null Feb 09 07:23:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 09 07:23:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:23:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:23:25 volumio go-librespot[4183]: go-librespot daemon starting... Feb 09 07:23:25 volumio go-librespot[4184]: time="2026-02-09T07:23:25+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 07:23:25 volumio go-librespot[4184]: time="2026-02-09T07:23:25+07:00" level=debug msg="app state loaded" Feb 09 07:23:25 volumio go-librespot[4184]: time="2026-02-09T07:23:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 07:23:25 volumio go-librespot[4184]: time="2026-02-09T07:23:25+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 07:23:25 volumio go-librespot[4184]: time="2026-02-09T07:23:25+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 09 07:23:25 volumio go-librespot[4184]: time="2026-02-09T07:23:25+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 09 07:23:25 volumio go-librespot[4184]: time="2026-02-09T07:23:25+07:00" level=info msg="zeroconf server listening on port 39461" Feb 09 07:23:26 volumio go-librespot[4184]: time="2026-02-09T07:23:26+07:00" level=debug msg="obtained new client token: AAA/4wLeKuQMCpGlMRsqc53fIsIMug2Ov20qJaFz5GCUnt2LSGSwZnGfvE/Hv69BgyOO6zIGS9xSXuus9MwS6kztVFvLMtjpb6SVwme/FnawyvU6RVFYBPhiOKvHZvSsmEsFtMAE2kfndYciB8nkn2ZF7p4WjRzW48Uz58Fgqt/0/VYCI+fy1Ne5CyeeZdVD+9CB4o9jb/Vzu2HC+F2amPpLVXYYmu3yjwroq6DoJuuBCt72O4C1bwM=" Feb 09 07:23:26 volumio go-librespot[4184]: time="2026-02-09T07:23:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 07:23:26 volumio go-librespot[4184]: time="2026-02-09T07:23:26+07:00" level=debug msg="completed keyexchange" Feb 09 07:23:26 volumio go-librespot[4184]: time="2026-02-09T07:23:26+07:00" level=debug msg="completed challenge" Feb 09 07:23:26 volumio go-librespot[4184]: time="2026-02-09T07:23:26+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 07:23:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 07:23:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 07:23:27 volumio volumio[3859]: info: Initializing connection to go-librespot Websocket Feb 09 07:23:27 volumio volumio[3859]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 07:23:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 09 07:23:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:23:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:23:29 volumio go-librespot[4193]: go-librespot daemon starting... Feb 09 07:23:29 volumio go-librespot[4194]: time="2026-02-09T07:23:29+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 07:23:29 volumio go-librespot[4194]: time="2026-02-09T07:23:29+07:00" level=debug msg="app state loaded" Feb 09 07:23:29 volumio go-librespot[4194]: time="2026-02-09T07:23:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 07:23:29 volumio volumio[3859]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 09 07:23:30 volumio go-librespot[4194]: time="2026-02-09T07:23:30+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 07:23:30 volumio go-librespot[4194]: time="2026-02-09T07:23:30+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 09 07:23:30 volumio go-librespot[4194]: time="2026-02-09T07:23:30+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 09 07:23:30 volumio go-librespot[4194]: time="2026-02-09T07:23:30+07:00" level=info msg="zeroconf server listening on port 33207" Feb 09 07:23:30 volumio volumio[3859]: info: Initializing connection to go-librespot Websocket Feb 09 07:23:30 volumio go-librespot[4194]: time="2026-02-09T07:23:30+07:00" level=debug msg="new websocket client" Feb 09 07:23:30 volumio volumio[3859]: info: Connection to go-librespot Websocket established Feb 09 07:23:30 volumio go-librespot[4194]: time="2026-02-09T07:23:30+07:00" level=debug msg="obtained new client token: AAAEvJLiUjWPJB8ch+oeZkIH+ccjYU5EWO4Emd03VCKbPxSS/uqQaU0bXT41ULBvhtWy0OT4QYl12/iyeg9uRdwOaNKAsMg4XMLYOBYJJq3WHiWk2pMnHXbidqdLWjaA3jYWA847PYwJeLDODM73Ywf5Z/qQnOgqHqJGjM99qD7IFJ+meu/ZyScSMlRhUatjgirMtCz08Dw9o1wwTaXe5VEXTJPqVa2WyDJIPNm5QK0yIguQF4FhYsBwEg==" Feb 09 07:23:30 volumio go-librespot[4194]: time="2026-02-09T07:23:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 07:23:30 volumio go-librespot[4194]: time="2026-02-09T07:23:30+07:00" level=debug msg="completed keyexchange" Feb 09 07:23:30 volumio go-librespot[4194]: time="2026-02-09T07:23:30+07:00" level=debug msg="completed challenge" Feb 09 07:23:30 volumio go-librespot[4194]: time="2026-02-09T07:23:30+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 07:23:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 07:23:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 07:23:30 volumio volumio[3859]: info: Connection to go-librespot Websocket closed Feb 09 07:23:33 volumio volumio[3859]: info: Getting Spotify volume Feb 09 07:23:33 volumio volumio[3859]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 07:23:33 volumio volumio[3859]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 07:23:33 volumio volumio[3859]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 09 07:23:33 volumio volumio[3859]: errno: -111, Feb 09 07:23:33 volumio volumio[3859]: code: 'ECONNREFUSED', Feb 09 07:23:33 volumio volumio[3859]: syscall: 'connect', Feb 09 07:23:33 volumio volumio[3859]: address: '127.0.0.1', Feb 09 07:23:33 volumio volumio[3859]: port: 9879, Feb 09 07:23:33 volumio volumio[3859]: response: undefined Feb 09 07:23:33 volumio volumio[3859]: } Feb 09 07:23:33 volumio volumio[3859]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 07:23:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 09 07:23:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:23:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 07:23:33 volumio go-librespot[4213]: go-librespot daemon starting... Feb 09 07:23:33 volumio go-librespot[4214]: time="2026-02-09T07:23:33+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 07:23:33 volumio go-librespot[4214]: time="2026-02-09T07:23:33+07:00" level=debug msg="app state loaded" Feb 09 07:23:33 volumio go-librespot[4214]: time="2026-02-09T07:23:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 07:23:34 volumio go-librespot[4214]: time="2026-02-09T07:23: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 09 07:23:34 volumio go-librespot[4214]: time="2026-02-09T07:23: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 09 07:23:34 volumio go-librespot[4214]: time="2026-02-09T07:23: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 09 07:23:34 volumio go-librespot[4214]: time="2026-02-09T07:23:34+07:00" level=info msg="zeroconf server listening on port 37853" Feb 09 07:23:34 volumio go-librespot[4214]: time="2026-02-09T07:23:34+07:00" level=debug msg="obtained new client token: AABwrR7dy74raLuTD6S4B5Y2Ix2XhZ5AKZFISogb7ya5Yj7pqWgtnzLb+FHziPuStqpqgtIhJxaPOPVAm2Nr8dUvHDBhA76HRuXk679CQ1bnrkPJI8t7VXbAWosZhBLJh3Q3HwHX2oY78zkun0XEvezu3VNlCOhpDfm2y/qJDUSmQyeNT6fWGVhulAtx6yMWmSGv3fJXE+uT+BIfNYjVBu+qUI0TDLuXvj7HtPMyfm+rjMT/basMo4A4tg==" Feb 09 07:23:34 volumio go-librespot[4214]: time="2026-02-09T07:23:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 07:23:34 volumio sudo[4237]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-09 07:22' Feb 09 07:23:34 volumio sudo[4237]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 07:23:34 volumio go-librespot[4214]: time="2026-02-09T07:23:34+07:00" level=debug msg="completed keyexchange" Feb 09 07:23:34 volumio go-librespot[4214]: time="2026-02-09T07:23:34+07:00" level=debug msg="completed challenge" Feb 09 07:23:34 volumio go-librespot[4214]: time="2026-02-09T07:23:34+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 09 07:23:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 07:23:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. 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"