Feb 18 23:43:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 18 23:43:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:00 volumio go-librespot[11063]: go-librespot daemon starting... Feb 18 23:43:00 volumio go-librespot[11064]: time="2026-02-18T23:43:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:43:00 volumio go-librespot[11064]: time="2026-02-18T23:43:00+07:00" level=debug msg="app state loaded" Feb 18 23:43:00 volumio go-librespot[11064]: time="2026-02-18T23:43:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:43:01 volumio volumio[10701]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 23:43:01 volumio volumio[10701]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 23:43:01 volumio volumio[10701]: info: Streaming services startup Feb 18 23:43:01 volumio volumio[10701]: info: Starting Streaming Daemon Feb 18 23:43:01 volumio sudo[11073]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 23:43:01 volumio sudo[11073]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:01 volumio volumio[10701]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 23:43:01 volumio go-librespot[11064]: time="2026-02-18T23:43: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:43:01 volumio go-librespot[11064]: time="2026-02-18T23:43:01+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 18 23:43:01 volumio go-librespot[11064]: time="2026-02-18T23:43:01+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 18 23:43:01 volumio sudo[11073]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:01 volumio go-librespot[11064]: time="2026-02-18T23:43:01+07:00" level=info msg="zeroconf server listening on port 35195" Feb 18 23:43:01 volumio volumio[10701]: info: Getting Spotify volume Feb 18 23:43:01 volumio volumio[10701]: info: Connection to go-librespot Websocket closed Feb 18 23:43:01 volumio volumio[10701]: error: Cannot start Volumio Streaming Daemon Feb 18 23:43:01 volumio volumio[10701]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 23:43:01 volumio volumio[10701]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 23:43:01 volumio volumio[10701]: 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 18 23:43:01 volumio go-librespot[11064]: time="2026-02-18T23:43:01+07:00" level=debug msg="obtained new client token: AABE/7bd+yTHlBR+TnrkR7np6zdasBP8YE2ov0eLmzrTLQCwjLdfpLClHe1ZrtOY/cymUkCSAGSC3TKV2jYWai5TKuCeyeR71YVAq7TcncEMAtdKaoxMLuXhqHpo+Enkh6WkYSpVNYJGE6Ztbo14Egkfln27UpsTjAD+CaVIoWNbjgIcB4j3IubN3nP55XzFYSlHsVL0GbRDQN2nQTCeMVc3lRAbYqdP0WFsWQeluXP5gWfKqk1ZU8EW1A==" Feb 18 23:43:01 volumio go-librespot[11064]: time="2026-02-18T23:43:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:43:01 volumio volumio[10701]: info: CoreCommandRouter::volumioGetState Feb 18 23:43:01 volumio volumio[10701]: info: CorePlayQueue::getTrack 0 Feb 18 23:43:01 volumio volumio[10701]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 18 23:43:01 volumio volumio[10701]: SPOTIFY: SPOTIFY VOLUME undefined Feb 18 23:43:01 volumio volumio[10701]: SPOTIFY: VOLUMIO VOLUME 100 Feb 18 23:43:01 volumio volumio[10701]: info: Aligning Spotify Volume to Volumio Volume Feb 18 23:43:01 volumio volumio[10701]: info: CoreCommandRouter::volumioGetState Feb 18 23:43:01 volumio volumio[10701]: info: CorePlayQueue::getTrack 0 Feb 18 23:43:01 volumio volumio[10701]: info: Setting Spotify Volume from Volumio: 100 Feb 18 23:43:01 volumio go-librespot[11064]: time="2026-02-18T23:43:01+07:00" level=debug msg="completed keyexchange" Feb 18 23:43:01 volumio go-librespot[11064]: time="2026-02-18T23:43:01+07:00" level=debug msg="completed challenge" Feb 18 23:43:01 volumio go-librespot[11064]: time="2026-02-18T23:43:01+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 23:43:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:43:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:43:01 volumio volumio[10701]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 23:43:01 volumio volumio[10701]: Error: socket hang up Feb 18 23:43:01 volumio volumio[10701]: at connResetException (node:internal/errors:720:14) Feb 18 23:43:01 volumio volumio[10701]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 18 23:43:01 volumio volumio[10701]: at Socket.emit (node:events:526:35) Feb 18 23:43:01 volumio volumio[10701]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 18 23:43:01 volumio volumio[10701]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 18 23:43:01 volumio volumio[10701]: code: 'ECONNRESET', Feb 18 23:43:01 volumio volumio[10701]: response: undefined Feb 18 23:43:01 volumio volumio[10701]: } Feb 18 23:43:01 volumio volumio[10701]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 23:43:03 volumio sudo[11094]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 23:42' Feb 18 23:43:03 volumio sudo[11094]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:03 volumio sudo[11094]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:03 volumio volumio-remote-updater[25144]: [2026-02-18 23:43:03] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 18 23:43:03 volumio volumio-remote-updater[25144]: [2026-02-18 23:43:03] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 18 23:43:03 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:43:03 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 18 23:43:03 volumio systemd[1]: volumio.service: Consumed 55.239s CPU time. Feb 18 23:43:03 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 23:43:03 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 23:43:03 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 22610. Feb 18 23:43:03 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 23:43:03 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 18 23:43:03 volumio systemd[1]: volumio.service: Consumed 55.239s CPU time. Feb 18 23:43:03 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 18 23:43:03 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 23:43:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 18 23:43:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:04 volumio go-librespot[11122]: go-librespot daemon starting... Feb 18 23:43:04 volumio go-librespot[11123]: time="2026-02-18T23:43:04+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:43:04 volumio go-librespot[11123]: time="2026-02-18T23:43:04+07:00" level=debug msg="app state loaded" Feb 18 23:43:04 volumio go-librespot[11123]: time="2026-02-18T23:43:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:43:05 volumio go-librespot[11123]: time="2026-02-18T23:43:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 23:43:05 volumio go-librespot[11123]: time="2026-02-18T23:43:05+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 18 23:43:05 volumio go-librespot[11123]: time="2026-02-18T23:43:05+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 18 23:43:05 volumio go-librespot[11123]: time="2026-02-18T23:43:05+07:00" level=info msg="zeroconf server listening on port 34143" Feb 18 23:43:05 volumio go-librespot[11123]: time="2026-02-18T23:43:05+07:00" level=debug msg="obtained new client token: AADZDnamVosSG2tYcU/Ipvoc0KtAOZyZd5bcqewC2vHy4FQFudJcwgQkybpRR9u513ZyWVCd9aeepdtIDNKitmJmS3B2JsVv8jFIJS82Kir5pIbzbFr7Wka9Cl+zrUkagi14cZTDPCt8r74LFiDaTxIKf+W5hLHS2TXPLZokETytcdeQOxrGtJv2mA/KI6XXf1/J/WssRbBudFH20Mpvs3MFyst8pXXtkoeuXtw+nlpWy2pxPE8vFhQ3ag==" Feb 18 23:43:05 volumio go-librespot[11123]: time="2026-02-18T23:43:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:43:05 volumio go-librespot[11123]: time="2026-02-18T23:43:05+07:00" level=debug msg="completed keyexchange" Feb 18 23:43:05 volumio go-librespot[11123]: time="2026-02-18T23:43:05+07:00" level=debug msg="completed challenge" Feb 18 23:43:06 volumio go-librespot[11123]: time="2026-02-18T23:43: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 18 23:43:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:43:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:43:07 volumio volumio[11106]: info: ------------------------------------------- Feb 18 23:43:07 volumio volumio[11106]: info: ----- Volumio3 ---- Feb 18 23:43:07 volumio volumio[11106]: info: ------------------------------------------- Feb 18 23:43:07 volumio volumio[11106]: info: ----- System startup ---- Feb 18 23:43:07 volumio volumio[11106]: info: ------------------------------------------- Feb 18 23:43:08 volumio volumio-remote-updater[25144]: [2026-02-18 23:43:08] [connect] Successful connection Feb 18 23:43:08 volumio volumio[11106]: info: MYVOLUMIO Environment detected Feb 18 23:43:08 volumio volumio[11106]: info: Plugin folders cleanup Feb 18 23:43:08 volumio volumio[11106]: info: Scanning into folder /volumio/app/plugins/ Feb 18 23:43:08 volumio volumio[11106]: info: Scanning category audio_interface Feb 18 23:43:08 volumio volumio[11106]: info: Scanning category miscellanea Feb 18 23:43:08 volumio volumio[11106]: info: Scanning category music_service Feb 18 23:43:08 volumio volumio[11106]: info: Scanning category plugins.json Feb 18 23:43:08 volumio volumio[11106]: info: Scanning category system_controller Feb 18 23:43:08 volumio volumio[11106]: info: Scanning category user_interface Feb 18 23:43:08 volumio volumio[11106]: info: Scanning into folder /data/plugins/ Feb 18 23:43:08 volumio volumio[11106]: info: Scanning category music_service Feb 18 23:43:08 volumio volumio[11106]: info: Plugin folders cleanup completed Feb 18 23:43:08 volumio volumio[11106]: info: ------------------------------------------- Feb 18 23:43:08 volumio volumio[11106]: info: ----- Core plugins startup ---- Feb 18 23:43:08 volumio volumio[11106]: info: ------------------------------------------- Feb 18 23:43:08 volumio volumio[11106]: info: Loading plugins from folder /volumio/app/plugins/ Feb 18 23:43:08 volumio volumio[11106]: info: Adding plugin upnp to MyMusic Plugins Feb 18 23:43:08 volumio volumio[11106]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 18 23:43:08 volumio volumio[11106]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 18 23:43:08 volumio volumio[11106]: info: Loading plugins from folder /data/plugins/ Feb 18 23:43:08 volumio volumio[11106]: info: Loading plugin "system"... Feb 18 23:43:09 volumio volumio[11106]: info: Loading plugin "appearance"... Feb 18 23:43:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 18 23:43:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:09 volumio go-librespot[11142]: go-librespot daemon starting... Feb 18 23:43:09 volumio go-librespot[11143]: time="2026-02-18T23:43:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:43:09 volumio go-librespot[11143]: time="2026-02-18T23:43:09+07:00" level=debug msg="app state loaded" Feb 18 23:43:09 volumio go-librespot[11143]: time="2026-02-18T23:43:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:43:09 volumio go-librespot[11143]: time="2026-02-18T23:43:09+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:43:09 volumio go-librespot[11143]: time="2026-02-18T23:43:09+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 18 23:43:09 volumio go-librespot[11143]: time="2026-02-18T23:43:09+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 18 23:43:09 volumio go-librespot[11143]: time="2026-02-18T23:43:09+07:00" level=info msg="zeroconf server listening on port 39633" Feb 18 23:43:10 volumio go-librespot[11143]: time="2026-02-18T23:43:10+07:00" level=debug msg="obtained new client token: AABUDKl2pPAC7Nw88JdtnsLJpz2AcJ2jh4K6hjbKEBfmnuDF6OsAkuk9HH+v2PGhwnco+QCzex1UJq7XBIrYcQ1vHeVNv9R31M46Zm2eFGJ1AFH5TZhvm7QB92cRYQJ/mHav4TER3Jg3ujIzeG6Nf8XWmtj31KN76Sob5mT2s0jp/WnlGCkMQMX2cf39utrQ8UI/bAk0WVsPBsAtDIghrI16tKAhylruMGtkPODVjkCybd/OI4y4Ezg=" Feb 18 23:43:10 volumio go-librespot[11143]: time="2026-02-18T23:43:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:43:10 volumio go-librespot[11143]: time="2026-02-18T23:43:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 23:43:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:43:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:43:10 volumio volumio[11106]: info: Loading plugin "network"... Feb 18 23:43:11 volumio volumio[11106]: info: Refreshing Cached IP Addresses Feb 18 23:43:11 volumio sudo[11152]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 23:43:11 volumio sudo[11152]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:11 volumio sudo[11154]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 23:43:11 volumio sudo[11154]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:11 volumio volumio[11106]: info: Loading plugin "services"... Feb 18 23:43:11 volumio sudo[11154]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:11 volumio sudo[11152]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:11 volumio volumio[11106]: info: Loading plugin "alsa_controller"... Feb 18 23:43:11 volumio sudo[11161]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 18 23:43:11 volumio sudo[11161]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:11 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 23:43:11 volumio volumio[11106]: info: Loading plugin "wizard"... Feb 18 23:43:11 volumio volumio[11106]: info: Loading plugin "networkfs"... Feb 18 23:43:11 volumio volumio[11106]: info: Starting Udev Watcher for removable devices Feb 18 23:43:11 volumio volumio[11106]: info: Ignoring mount for partition: boot Feb 18 23:43:11 volumio volumio[11106]: info: Ignoring mount for partition: volumio Feb 18 23:43:11 volumio volumio[11106]: info: Ignoring mount for partition: volumio_data Feb 18 23:43:11 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 23:43:11 volumio volumio[11106]: info: Loading plugin "volumio_command_line_client"... Feb 18 23:43:11 volumio volumio[11106]: info: Loading plugin "upnp"... Feb 18 23:43:11 volumio volumio[11106]: info: [1771432991416] Starting Upmpd Daemon Feb 18 23:43:11 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 23:43:11 volumio volumio[11106]: info: Loading plugin "my_music"... Feb 18 23:43:11 volumio volumio[11106]: info: Loading plugin "mpd"... Feb 18 23:43:12 volumio volumio[11106]: info: Loading plugin "upnp_browser"... Feb 18 23:43:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 18 23:43:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:13 volumio go-librespot[11185]: go-librespot daemon starting... Feb 18 23:43:13 volumio go-librespot[11186]: time="2026-02-18T23:43:13+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:43:13 volumio go-librespot[11186]: time="2026-02-18T23:43:13+07:00" level=debug msg="app state loaded" Feb 18 23:43:13 volumio go-librespot[11186]: time="2026-02-18T23:43:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:43:13 volumio sudo[11161]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:14 volumio go-librespot[11186]: time="2026-02-18T23:43:14+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:43:14 volumio go-librespot[11186]: time="2026-02-18T23:43:14+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 23:43:14 volumio go-librespot[11186]: time="2026-02-18T23:43:14+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 23:43:14 volumio go-librespot[11186]: time="2026-02-18T23:43:14+07:00" level=info msg="zeroconf server listening on port 41511" Feb 18 23:43:14 volumio go-librespot[11186]: time="2026-02-18T23:43:14+07:00" level=debug msg="obtained new client token: AAC6/gWhEtfBFYgjgxgseGckH6Ys2XbrN+O5HXpKKSeIgytlzcu6xz5bQ4dr+SltOzrSBkxi4yLDBKmyb2Qhk9dXyGD5zX5yJQqjoCfwdSIrr3AFSQQPnZxobsrDhXA2lawu15w66aZDvVUjCy1zpv6NM6C2nDNzEmfJz7uot/MOZozB1EE/7DDExtQgNwNL43x8+AOj4aONYUWU6NNiL1SuGgQlvLYOX2gfBuJGYj0d9vqXyG2VaPA3ZA==" Feb 18 23:43:14 volumio go-librespot[11186]: time="2026-02-18T23:43:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:43:14 volumio go-librespot[11186]: time="2026-02-18T23:43:14+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 23:43:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:43:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:43:15 volumio volumio[11106]: info: Starting UPNP Browser Feb 18 23:43:15 volumio volumio[11106]: info: Loading plugin "alarm-clock"... Feb 18 23:43:15 volumio volumio[11106]: info: Loading plugin "airplay_emulation"... Feb 18 23:43:15 volumio volumio[11106]: info: Starting Shairport Sync Feb 18 23:43:15 volumio volumio[11106]: info: Loading plugin "last_100"... Feb 18 23:43:15 volumio volumio[11106]: info: Loading plugin "webradio"... Feb 18 23:43:15 volumio volumio[11106]: info: Loading plugin "i2s_dacs"... Feb 18 23:43:15 volumio volumio[11106]: info: Loading plugin "volumiodiscovery"... Feb 18 23:43:15 volumio volumio[11106]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 23:43:15 volumio volumio[11106]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 23:43:15 volumio node[11106]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 23:43:15 volumio volumio[11106]: *** WARNING *** For more information see Feb 18 23:43:15 volumio volumio[11106]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 23:43:15 volumio volumio[11106]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 23:43:15 volumio volumio[11106]: *** WARNING *** For more information see Feb 18 23:43:15 volumio node[11106]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 23:43:15 volumio node[11106]: *** WARNING *** For more information see Feb 18 23:43:15 volumio node[11106]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 23:43:15 volumio node[11106]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 23:43:15 volumio node[11106]: *** WARNING *** For more information see Feb 18 23:43:15 volumio volumio[11106]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 18 23:43:15 volumio volumio[11106]: info: Discovery: Started advertising with name: Volumio Feb 18 23:43:15 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 23:43:15 volumio volumio[11106]: info: Loading plugin "spop"... Feb 18 23:43:17 volumio volumio[11106]: info: Loading plugin "ytcr"... Feb 18 23:43:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 18 23:43:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:17 volumio go-librespot[11196]: go-librespot daemon starting... Feb 18 23:43:17 volumio go-librespot[11197]: time="2026-02-18T23:43:17+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:43:17 volumio go-librespot[11197]: time="2026-02-18T23:43:17+07:00" level=debug msg="app state loaded" Feb 18 23:43:17 volumio go-librespot[11197]: time="2026-02-18T23:43:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:43:18 volumio go-librespot[11197]: time="2026-02-18T23:43:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:43:18 volumio go-librespot[11197]: time="2026-02-18T23:43:18+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 23:43:18 volumio go-librespot[11197]: time="2026-02-18T23:43:18+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 23:43:18 volumio go-librespot[11197]: time="2026-02-18T23:43:18+07:00" level=info msg="zeroconf server listening on port 40897" Feb 18 23:43:18 volumio go-librespot[11197]: time="2026-02-18T23:43:18+07:00" level=debug msg="obtained new client token: AABF/hqeCnSnrkek29sfQ0AfFyX0jvlve+gJh+e9tshLH/a8zWyDI41V8RPwB9i2P+casj3lf43xeUMVA0iQD9eZtyyostK481aea8rA30t8kZzgca0crVbAgQGtPAevTx3sBqCotzEnqAw8AYN+HQGG8LLn8yDmRERZLYDU2zM4pMITNv5Qd79myHKX179iX5L+jx58TERLgWFffT0sp0CNZubslEleWyS3bXamgTFDULEgi2N5Msp+dg==" Feb 18 23:43:18 volumio go-librespot[11197]: time="2026-02-18T23:43:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:43:18 volumio go-librespot[11197]: time="2026-02-18T23:43:18+07:00" level=debug msg="completed keyexchange" Feb 18 23:43:18 volumio go-librespot[11197]: time="2026-02-18T23:43:18+07:00" level=debug msg="completed challenge" Feb 18 23:43:18 volumio go-librespot[11197]: time="2026-02-18T23:43:18+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 23:43:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:43:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:43:20 volumio volumio[11106]: info: Loading plugin "ytmusic"... Feb 18 23:43:21 volumio volumio-remote-updater[25144]: [2026-02-18 23:43:21] [connect] Successful connection Feb 18 23:43:21 volumio volumio[11106]: info: Loading plugin "outputs"... Feb 18 23:43:21 volumio volumio[11106]: info: Loading plugin "albumart"... Feb 18 23:43:21 volumio volumio[11106]: info: Plugin example_plugin is not enabled Feb 18 23:43:21 volumio volumio[11106]: info: Loading plugin "inputs"... Feb 18 23:43:21 volumio volumio[11106]: info: Loading plugin "updater_comm"... Feb 18 23:43:21 volumio volumio[11106]: info: Plugin mpdemulation is not enabled Feb 18 23:43:21 volumio volumio[11106]: info: Loading plugin "rest_api"... Feb 18 23:43:21 volumio volumio[11106]: info: Loading plugin "websocket"... Feb 18 23:43:21 volumio volumio[11106]: info: Starting Socket.io Server version 1.7.4 Feb 18 23:43:21 volumio volumio[11106]: info: Loading plugin "RoonBridge"... Feb 18 23:43:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 18 23:43:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:22 volumio go-librespot[11230]: go-librespot daemon starting... Feb 18 23:43:22 volumio go-librespot[11231]: time="2026-02-18T23:43:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:43:22 volumio go-librespot[11231]: time="2026-02-18T23:43:22+07:00" level=debug msg="app state loaded" Feb 18 23:43:22 volumio go-librespot[11231]: time="2026-02-18T23:43:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:43:22 volumio volumio[11106]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 23:43:22 volumio volumio[11106]: info: Loading i18n strings for locale en Feb 18 23:43:22 volumio volumio[11106]: Updating browse sources language Feb 18 23:43:22 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 23:43:22 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 23:43:22 volumio volumio[11106]: info: CoreCommandRouter::initPlayerControls Feb 18 23:43:22 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:22 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:22 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:22 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:22 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:22 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:22 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:22 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:22 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 23:43:22 volumio volumio[11220]: Forking 3 albumart workers Feb 18 23:43:22 volumio volumio[11106]: Express server listening on port 3000 Feb 18 23:43:22 volumio volumio[11106]: [Metrics] WebUI: 16s 115.53ms Feb 18 23:43:22 volumio volumio[11106]: info: CoreStateMachine::resetVolumioState Feb 18 23:43:22 volumio volumio[11106]: info: CoreStateMachine::getcurrentVolume Feb 18 23:43:22 volumio volumio[11106]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 23:43:22 volumio go-librespot[11231]: time="2026-02-18T23:43:22+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:43:22 volumio go-librespot[11231]: time="2026-02-18T23:43:22+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 18 23:43:22 volumio go-librespot[11231]: time="2026-02-18T23:43:22+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 18 23:43:22 volumio sudo[11272]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 23:43:22 volumio sudo[11272]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:22 volumio volumio[11106]: info: Volumio Network Manager: Network status updated: 1 Feb 18 23:43:22 volumio go-librespot[11231]: time="2026-02-18T23:43:22+07:00" level=info msg="zeroconf server listening on port 35597" Feb 18 23:43:22 volumio sudo[11272]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:22 volumio sudo[11270]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 23:43:22 volumio sudo[11270]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:22 volumio sudo[11270]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:23 volumio go-librespot[11231]: time="2026-02-18T23:43:23+07:00" level=debug msg="obtained new client token: AABt1lGEGnGGKi++yoGaGS29gPmKjfr4+PdApgNBy6Fl94ziIu8iqcfSLzDbgktzakV2ui/TM3rviY9kQfyGDnuwu/YG/zU9wQ+eQSGvLBaIPeWscMAWwH1QZSxl1ORIoMnUF9fXpcb5dLgJx+aaSsEpngX+qlszot+NxbgQgs9mV8+kB7FMwnjvaIU979+o7404jldIqD40YBfmJ9u5/CNz3x2s4D8Pt3E/Igun1VojtyouWVXzukM=" Feb 18 23:43:23 volumio volumio-remote-updater[25144]: [2026-02-18 23:43:23] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771433001 101 Feb 18 23:43:23 volumio volumio[11106]: 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 18 23:43:23 volumio volumio[11106]: info: VolumeController:: Volume=100 Mute =false Feb 18 23:43:23 volumio volumio[11106]: info: CoreStateMachine::pushState Feb 18 23:43:23 volumio volumio[11106]: info: CorePlayQueue::getTrack 0 Feb 18 23:43:23 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 23:43:23 volumio volumio[11106]: info: CoreCommandRouter::volumioPushState Feb 18 23:43:23 volumio go-librespot[11231]: time="2026-02-18T23:43:23+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 18 23:43:23 volumio volumio[11106]: info: CoreStateMachine::updateTrackBlock Feb 18 23:43:23 volumio volumio[11106]: info: CorePlayQueue::getTrackBlock Feb 18 23:43:23 volumio volumio[11106]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 23:43:23 volumio go-librespot[11231]: time="2026-02-18T23:43:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 18 23:43:23 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:43:23 volumio volumio[11106]: info: Reloading queue from file Feb 18 23:43:23 volumio volumio[11106]: info: CoreStateMachine::setRepeat null single undefined Feb 18 23:43:23 volumio volumio[11106]: info: CoreStateMachine::pushState Feb 18 23:43:23 volumio volumio[11106]: info: CorePlayQueue::getTrack 0 Feb 18 23:43:23 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 23:43:23 volumio volumio[11106]: info: CoreCommandRouter::volumioPushState Feb 18 23:43:23 volumio volumio[11106]: info: CoreStateMachine::setRandom null Feb 18 23:43:23 volumio volumio[11106]: info: CoreStateMachine::pushState Feb 18 23:43:23 volumio go-librespot[11231]: time="2026-02-18T23:43:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 23:43:23 volumio volumio[11106]: info: CorePlayQueue::getTrack 0 Feb 18 23:43:23 volumio volumio[11106]: info: CoreCommandRouter::volumioPushState Feb 18 23:43:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:43:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:43:23 volumio volumio[11106]: info: Setting Device type: Raspberry PI Feb 18 23:43:23 volumio volumio[11106]: info: Completed loading Core Plugins Feb 18 23:43:23 volumio volumio[11106]: info: Preparing to generate the ALSA configuration file Feb 18 23:43:23 volumio volumio[11106]: info: VolumeController:: Volume=100 Mute =false Feb 18 23:43:23 volumio volumio[11106]: info: CoreStateMachine::pushState Feb 18 23:43:23 volumio volumio[11106]: info: CorePlayQueue::getTrack 0 Feb 18 23:43:23 volumio volumio[11106]: info: CoreCommandRouter::volumioPushState Feb 18 23:43:23 volumio volumio[11106]: info: Asound.conf file unchanged, so no further update is needed Feb 18 23:43:23 volumio volumio[11106]: info: Output device has changed, restarting MPD Feb 18 23:43:23 volumio volumio[11106]: info: Output device has changed, restarting Shairport Sync Feb 18 23:43:23 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:23 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:43:23 volumio sudo[11288]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 23:43:23 volumio sudo[11288]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:23 volumio sudo[11292]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 23:43:23 volumio sudo[11292]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:23 volumio sudo[11290]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 23:43:23 volumio sudo[11290]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:23 volumio sudo[11290]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:23 volumio sudo[11288]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:23 volumio volumio[11106]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 23:43:23 volumio volumio[11106]: info: ___________ START PLUGINS ___________ Feb 18 23:43:23 volumio volumio[11106]: info: ControllerMpd::onStart: Initializing MPD Feb 18 23:43:23 volumio volumio[11106]: info: Creating MPD Configuration file Feb 18 23:43:23 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 23:43:23 volumio sudo[11301]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 23:43:23 volumio sudo[11301]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:23 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 23:43:23 volumio volumio[11106]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 23:43:23 volumio volumio[11106]: info: [1771433003965] CoreMusicLibrary::Adding element Media Servers Feb 18 23:43:23 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 23:43:24 volumio sudo[11301]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:24 volumio volumio[11106]: info: UPNP Browser: Client initialized successfully Feb 18 23:43:24 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 23:43:24 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 23:43:24 volumio systemd[1]: mpd.service: Consumed 7.167s CPU time. Feb 18 23:43:24 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 23:43:24 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 23:43:24 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 23:43:24 volumio sudo[11304]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 23:43:24 volumio sudo[11304]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:24 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:24 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:43:24 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 23:43:24 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 23:43:24 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 23:43:24 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 23:43:24 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 23:43:24 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 23:43:24 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 23:43:24 volumio volumio[11106]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 23:43:24 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:24 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:43:24 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 23:43:24 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 23:43:24 volumio volumio[11106]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 23:43:24 volumio volumio[11106]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 23:43:24 volumio volumio[11106]: info: [1771433004323] CoreMusicLibrary::Adding element Last_100 Feb 18 23:43:24 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 23:43:24 volumio volumio[11106]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 23:43:24 volumio volumio[11106]: info: [1771433004348] CoreMusicLibrary::Adding element Webradio Feb 18 23:43:24 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 23:43:24 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 23:43:24 volumio volumio[11106]: info: Initializing BBC Radios Feb 18 23:43:24 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 23:43:24 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:43:24 volumio volumio[11106]: info: Creating Spotify config file Feb 18 23:43:24 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:24 volumio sudo[11317]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 23:43:24 volumio sudo[11317]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 23:43:24 volumio sudo[11317]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:25 volumio volumio[11243]: Starting albumart workers Feb 18 23:43:25 volumio volumio[11106]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 23:43:25 volumio volumio[11106]: info: [1771433005919] CoreMusicLibrary::Adding element YouTube Music Feb 18 23:43:25 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 23:43:25 volumio volumio[11106]: Cannot find translation for source YouTube Music Feb 18 23:43:25 volumio volumio[11106]: info: Volumio Calling Home Feb 18 23:43:26 volumio sudo[11334]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 23:43:26 volumio sudo[11334]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:26 volumio volumio[11239]: Starting albumart workers Feb 18 23:43:26 volumio sudo[11334]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:26 volumio volumio[11242]: Starting albumart workers Feb 18 23:43:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 18 23:43:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:26 volumio volumio[11106]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 23:43:26 volumio volumio[11106]: info: Discovery: Found device Volumio Feb 18 23:43:26 volumio volumio[11106]: info: CoreCommandRouter::volumioGetState Feb 18 23:43:26 volumio volumio[11106]: info: CorePlayQueue::getTrack 0 Feb 18 23:43:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:26 volumio go-librespot[11339]: go-librespot daemon starting... Feb 18 23:43:26 volumio volumio[11106]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 23:43:26 volumio volumio[11106]: info: Discovery: Found device Volumio Feb 18 23:43:26 volumio volumio[11106]: info: CoreCommandRouter::volumioGetState Feb 18 23:43:26 volumio volumio[11106]: info: CorePlayQueue::getTrack 0 Feb 18 23:43:26 volumio go-librespot[11340]: time="2026-02-18T23:43:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:43:26 volumio go-librespot[11340]: time="2026-02-18T23:43:26+07:00" level=debug msg="app state loaded" Feb 18 23:43:26 volumio go-librespot[11340]: time="2026-02-18T23:43:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:43:26 volumio volumio[11106]: info: MPD Permissions set Feb 18 23:43:26 volumio volumio[11106]: info: MPD Permissions set Feb 18 23:43:26 volumio volumio[11106]: info: Upmpdcli Daemon Started Feb 18 23:43:26 volumio volumio[11106]: info: Volumio called home Feb 18 23:43:26 volumio volumio[11106]: info: Spotify config file written Feb 18 23:43:27 volumio sudo[11347]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 23:43:27 volumio sudo[11347]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:27 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 18 23:43:27 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 18 23:43:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:27 volumio go-librespot[11351]: go-librespot daemon starting... Feb 18 23:43:27 volumio sudo[11347]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:27 volumio go-librespot[11352]: time="2026-02-18T23:43:27+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:43:27 volumio go-librespot[11352]: time="2026-02-18T23:43:27+07:00" level=debug msg="app state loaded" Feb 18 23:43:27 volumio go-librespot[11352]: time="2026-02-18T23:43:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:43:27 volumio volumio[11106]: 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 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: No need to fix Spotify hosts Feb 18 23:43:28 volumio go-librespot[11352]: time="2026-02-18T23:43:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:43:28 volumio go-librespot[11352]: time="2026-02-18T23:43:28+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 18 23:43:28 volumio go-librespot[11352]: time="2026-02-18T23:43:28+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 18 23:43:28 volumio go-librespot[11352]: time="2026-02-18T23:43:28+07:00" level=info msg="zeroconf server listening on port 35699" Feb 18 23:43:28 volumio go-librespot[11352]: time="2026-02-18T23:43:28+07:00" level=debug msg="obtained new client token: AADq+QGTqZJJRmY+l4J6L9v1wvcn79qKoFpulZ6QdjYCgSmTpmgt14TDI0WCiC+DH1Q6Y5KTADdo/JhgmWQ7qMLslvGeH2CrdFp/GKGsQdlP5T43KRsgZ/pQwxNAs65x9EnPuBdEqRkwQpVSSdb11KZRwYg8D76FpuZidxpp6It6owOUrBKL7GqxmNCXMXQ1YB8SyknbCM3GFd+Yg6qN1Gxw6LDs3Wb7q82rBVwQDGLJYTZKxqMiRo2XJA==" Feb 18 23:43:28 volumio go-librespot[11352]: time="2026-02-18T23:43:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:43:28 volumio go-librespot[11352]: time="2026-02-18T23:43:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 23:43:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:43:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:43:29 volumio volumio[11106]: info: Starting Shairport Sync Feb 18 23:43:29 volumio volumio[11106]: info: Starting Shairport Sync Feb 18 23:43:29 volumio volumio[11106]: info: Starting Shairport Sync Feb 18 23:43:29 volumio sudo[11389]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 23:43:29 volumio sudo[11389]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:29 volumio sudo[11391]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 23:43:29 volumio sudo[11391]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:29 volumio sudo[11393]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 23:43:29 volumio sudo[11393]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:29 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 23:43:29 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 23:43:29 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 23:43:29 volumio systemd[1]: shairport-sync.service: Consumed 2.343s CPU time. Feb 18 23:43:29 volumio volumio[11106]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 23:43:29 volumio volumio[11106]: SPOTIFY: BQDEkrIROURZb5Hj0Jr4RFySre3RVt7ceGBqv22Ea9y9kDJqLuMuYM_F9K-7nXrqA1ZZpWqCxSDX7qOt1-9PY-VHSlt7ygXSZZdWeY26r7nTeuPIXApuEXJlViH-V86shDukACOil_2EKNfMzam6H4cWAtfO6RoojpN3lLxn_9pxKGXBNQttVv6Hpnro7i0rp1jU3zvBfQSEy88KYjHVZxQviLILVRaZqqbIxLn64__yv0irdGCZKyYQCAuZhnaQPr3gijrWSHWlttC89redDHR1-nftMqcGNhXnJ1Nnf1rDtAhkDnH6mbdK Feb 18 23:43:29 volumio volumio[11106]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 23:43:29 volumio volumio[11106]: info: New Spotify access token = BQDEkrIROURZb5Hj0Jr4RFySre3RVt7ceGBqv22Ea9y9kDJqLuMuYM_F9K-7nXrqA1ZZpWqCxSDX7qOt1-9PY-VHSlt7ygXSZZdWeY26r7nTeuPIXApuEXJlViH-V86shDukACOil_2EKNfMzam6H4cWAtfO6RoojpN3lLxn_9pxKGXBNQttVv6Hpnro7i0rp1jU3zvBfQSEy88KYjHVZxQviLILVRaZqqbIxLn64__yv0irdGCZKyYQCAuZhnaQPr3gijrWSHWlttC89redDHR1-nftMqcGNhXnJ1Nnf1rDtAhkDnH6mbdK Feb 18 23:43:29 volumio volumio[11106]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 23:43:29 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 23:43:29 volumio sudo[11393]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:29 volumio sudo[11391]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:29 volumio sudo[11389]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:29 volumio volumio[11106]: info: Shairport-Sync Started Feb 18 23:43:29 volumio volumio[11106]: Error adding Membership: Error: addMembership EINVAL Feb 18 23:43:29 volumio volumio[11106]: info: Shairport-Sync Started Feb 18 23:43:29 volumio volumio[11106]: info: Shairport-Sync Started Feb 18 23:43:29 volumio volumio[11106]: info: CoreCommandRouter::volumioGetState Feb 18 23:43:29 volumio volumio[11106]: info: CorePlayQueue::getTrack 0 Feb 18 23:43:29 volumio volumio[11106]: 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 18 23:43:29 volumio volumio[11106]: info: Spotify Successfully logged in Feb 18 23:43:29 volumio volumio[11106]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 23:43:29 volumio volumio[11106]: info: [1771433009970] CoreMusicLibrary::Adding element Spotify Feb 18 23:43:29 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 23:43:29 volumio volumio[11106]: Cannot find translation for source YouTube Music Feb 18 23:43:29 volumio volumio[11106]: Cannot find translation for source Spotify Feb 18 23:43:30 volumio volumio[11106]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 23:43:30 volumio volumio[11106]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 23:43:30 volumio volumio[11106]: info: VolumeController:: Volume=100 Mute =false Feb 18 23:43:30 volumio volumio[11106]: info: CoreCommandRouter::volumioGetState Feb 18 23:43:30 volumio volumio[11106]: info: CorePlayQueue::getTrack 0 Feb 18 23:43:30 volumio volumio[11106]: info: CoreStateMachine::pushState Feb 18 23:43:30 volumio volumio[11106]: info: CorePlayQueue::getTrack 0 Feb 18 23:43:30 volumio volumio[11106]: info: CoreCommandRouter::volumioPushState Feb 18 23:43:31 volumio mpd[11332]: 2026-02-18T23:43:31 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 23:43:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 18 23:43:31 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 23:43:31 volumio sudo[11292]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:31 volumio sudo[11304]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:31 volumio go-librespot[11431]: go-librespot daemon starting... Feb 18 23:43:31 volumio go-librespot[11434]: time="2026-02-18T23:43:31+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:43:31 volumio go-librespot[11434]: time="2026-02-18T23:43:31+07:00" level=debug msg="app state loaded" Feb 18 23:43:31 volumio go-librespot[11434]: time="2026-02-18T23:43:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:43:32 volumio volumio[11106]: error: MPD error: The expression evaluated to a falsy value: Feb 18 23:43:32 volumio volumio[11106]: assert.ok(self.idling) Feb 18 23:43:32 volumio volumio[11106]: error: The expression evaluated to a falsy value: Feb 18 23:43:32 volumio volumio[11106]: assert.ok(self.idling) Feb 18 23:43:32 volumio volumio[11106]: info: go-librespot daemon successfully initialized Feb 18 23:43:32 volumio volumio[11106]: info: MPD running with PID11332 Feb 18 23:43:32 volumio volumio[11106]: ,establishing connection Feb 18 23:43:32 volumio volumio[11106]: error: updateQueue error: null Feb 18 23:43:32 volumio volumio[11106]: info: Completed starting Core Plugins Feb 18 23:43:32 volumio volumio[11106]: info: ------------------------------------------- Feb 18 23:43:32 volumio volumio[11106]: info: ----- MyVolumio plugins startup ---- Feb 18 23:43:32 volumio volumio[11106]: info: ------------------------------------------- Feb 18 23:43:32 volumio volumio[11106]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 23:43:32 volumio volumio[11106]: error: updateQueue error: null Feb 18 23:43:32 volumio go-librespot[11434]: time="2026-02-18T23:43: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:43:32 volumio go-librespot[11434]: time="2026-02-18T23:43:32+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 18 23:43:32 volumio go-librespot[11434]: time="2026-02-18T23:43:32+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 18 23:43:32 volumio go-librespot[11434]: time="2026-02-18T23:43:32+07:00" level=info msg="zeroconf server listening on port 42107" Feb 18 23:43:32 volumio go-librespot[11434]: time="2026-02-18T23:43:32+07:00" level=debug msg="obtained new client token: AADje9AQRFrBqwWjcgJArguxT1zqrN3y2yRjPKZcLu7BNDeFA9QUSfCW8N252zYv4mqOxiAPkkyTIz8EtdeoHKh5Oqz727nIJCzzsxX+Bg2S46oNuDW5F4p0zdL1bTyARyrEyQ/jMpARJt/DHCJrwDFDq3fRVhS4VjwO8DzscKwaDwMbFuRpu/r2VlF9Jj2dD1PpEuZfbTKgnufyDvZkfpHTGf1MGeHuBxKCPVHMvcjihnh1g1/fzLXa4A==" Feb 18 23:43:32 volumio go-librespot[11434]: time="2026-02-18T23:43:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:43:32 volumio go-librespot[11434]: time="2026-02-18T23:43:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 23:43:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:43:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:43:35 volumio volumio[11106]: info: Initializing connection to go-librespot Websocket Feb 18 23:43:35 volumio volumio[11106]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 23:43:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 18 23:43:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:36 volumio go-librespot[11443]: go-librespot daemon starting... Feb 18 23:43:36 volumio go-librespot[11444]: time="2026-02-18T23:43:36+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:43:36 volumio go-librespot[11444]: time="2026-02-18T23:43:36+07:00" level=debug msg="app state loaded" Feb 18 23:43:36 volumio go-librespot[11444]: time="2026-02-18T23:43:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:43:36 volumio go-librespot[11444]: time="2026-02-18T23:43: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 18 23:43:36 volumio go-librespot[11444]: time="2026-02-18T23:43: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 18 23:43:36 volumio go-librespot[11444]: time="2026-02-18T23:43: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 18 23:43:36 volumio go-librespot[11444]: time="2026-02-18T23:43:36+07:00" level=info msg="zeroconf server listening on port 39299" Feb 18 23:43:36 volumio go-librespot[11444]: time="2026-02-18T23:43:36+07:00" level=debug msg="obtained new client token: AAD17S2jDLYMQ2jAXS6T/XFhwhT9C9z2uLt1eG470K+iM3MuvN41c+O8zDpTjLjuSreLnW2N4H+q3aYSXqIXb178dGrOx18BQXAVTnuoazeHGgVvd+0SGlbCNHqRlbVolTuUESWHs8FyYsu06nv78Kn7yU8WZ854nZIeMJ6x9zdLWoPVGbReIm/IAygSJS7s38p5j8r0Lja47BBrROd5tqwXUFS5JSngca276I6yEQX0UJHqlMDMKc37Og==" Feb 18 23:43:36 volumio volumio[11106]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 23:43:36 volumio go-librespot[11444]: time="2026-02-18T23:43:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:43:37 volumio go-librespot[11444]: time="2026-02-18T23:43:37+07:00" level=debug msg="completed keyexchange" Feb 18 23:43:37 volumio go-librespot[11444]: time="2026-02-18T23:43:37+07:00" level=debug msg="completed challenge" Feb 18 23:43:37 volumio go-librespot[11444]: time="2026-02-18T23:43: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 18 23:43:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:43:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:43:38 volumio volumio[11106]: info: Initializing connection to go-librespot Websocket Feb 18 23:43:38 volumio volumio[11106]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 23:43:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 18 23:43:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:40 volumio go-librespot[11452]: go-librespot daemon starting... Feb 18 23:43:40 volumio go-librespot[11453]: time="2026-02-18T23:43:40+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:43:40 volumio go-librespot[11453]: time="2026-02-18T23:43:40+07:00" level=debug msg="app state loaded" Feb 18 23:43:40 volumio go-librespot[11453]: time="2026-02-18T23:43:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:43:40 volumio go-librespot[11453]: time="2026-02-18T23:43: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 18 23:43:40 volumio go-librespot[11453]: time="2026-02-18T23:43: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 18 23:43:40 volumio go-librespot[11453]: time="2026-02-18T23:43: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 18 23:43:40 volumio go-librespot[11453]: time="2026-02-18T23:43:40+07:00" level=info msg="zeroconf server listening on port 39325" Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 23:43:40 volumio volumio[11106]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 23:43:41 volumio volumio[11106]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 23:43:41 volumio volumio[11106]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 23:43:41 volumio volumio[11106]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 23:43:41 volumio volumio[11106]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 23:43:41 volumio volumio[11106]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 23:43:41 volumio volumio[11106]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 23:43:41 volumio volumio[11106]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 23:43:41 volumio go-librespot[11453]: time="2026-02-18T23:43:41+07:00" level=debug msg="obtained new client token: AAAjMEMm4vcJXROGeUMvVYi5GLQEtWs/v/kR1oZwE4h7So5qxevYMEPfsLgsBsTtMKQ+akMvsv7uCqJP4X+Dqvfow2vrkM1g8ryssQWAQRiCU0CFQDurkAx06T4leIL6Q2GlmjqiJ56+ADGzjv85W8bdhpwnx1nXezFKW6Sc6WToA5tQ3jN3sa+I6SwCNbOfiy/95NG2xsR/b/IImpO7B1MYu/Na1XyZzXrrD/y8i4s57CiS7EuOTqY=" Feb 18 23:43:41 volumio go-librespot[11453]: time="2026-02-18T23:43:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:43:41 volumio go-librespot[11453]: time="2026-02-18T23:43:41+07:00" level=debug msg="completed keyexchange" Feb 18 23:43:41 volumio go-librespot[11453]: time="2026-02-18T23:43:41+07:00" level=debug msg="completed challenge" Feb 18 23:43:41 volumio go-librespot[11453]: time="2026-02-18T23:43: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 18 23:43:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:43:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:43:42 volumio volumio[11106]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 23:43:42 volumio volumio[11106]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 23:43:42 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:43:42 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:43:42 volumio volumio[11106]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 23:43:42 volumio volumio[11106]: info: MyVolumio login type: Token Feb 18 23:43:42 volumio volumio[11106]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 23:43:42 volumio volumio[11106]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 23:43:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 18 23:43:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:44 volumio go-librespot[11474]: go-librespot daemon starting... Feb 18 23:43:44 volumio go-librespot[11475]: time="2026-02-18T23:43:44+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:43:44 volumio go-librespot[11475]: time="2026-02-18T23:43:44+07:00" level=debug msg="app state loaded" Feb 18 23:43:44 volumio go-librespot[11475]: time="2026-02-18T23:43:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:43:44 volumio volumio[11106]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 23:43:44 volumio volumio[11106]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 23:43:44 volumio volumio[11106]: info: Streaming services startup Feb 18 23:43:44 volumio volumio[11106]: info: Starting Streaming Daemon Feb 18 23:43:44 volumio sudo[11482]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 23:43:44 volumio sudo[11482]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:44 volumio volumio[11106]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 23:43:44 volumio sudo[11482]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:44 volumio volumio[11106]: info: Initializing connection to go-librespot Websocket Feb 18 23:43:44 volumio volumio[11106]: error: Cannot start Volumio Streaming Daemon Feb 18 23:43:44 volumio volumio[11106]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 23:43:44 volumio volumio[11106]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 23:43:44 volumio go-librespot[11475]: time="2026-02-18T23:43:44+07:00" level=debug msg="new websocket client" Feb 18 23:43:44 volumio volumio[11106]: info: Connection to go-librespot Websocket established Feb 18 23:43:45 volumio go-librespot[11475]: time="2026-02-18T23:43: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:43:45 volumio go-librespot[11475]: time="2026-02-18T23:43:45+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 18 23:43:45 volumio go-librespot[11475]: time="2026-02-18T23:43:45+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 18 23:43:45 volumio go-librespot[11475]: time="2026-02-18T23:43:45+07:00" level=info msg="zeroconf server listening on port 42887" Feb 18 23:43:45 volumio go-librespot[11475]: time="2026-02-18T23:43:45+07:00" level=debug msg="obtained new client token: AADRH0oQcCQNyQ5gvIzFVBIVtIJnLSoWKh3Vk2c1b1nPtqbg/RBb6POjtIn5wDbnangW+90isU3qXy17P+CrwmjQAnxtzgM0TXjamu79Ontw2yPUYOfZ0jaFpYtaf7DNYqKCmfy6C3uQxspfG+T7IfaVgU9dU83GGdM4J8ipLB/AFbj4LWIqOqu7Mb0f8Q2k1oQjGBPkt69ukdeHU6CPWbsmi8eOxc3USe7f/qPqQ93Jfe9C5wk9YP9y6Q==" Feb 18 23:43:45 volumio go-librespot[11475]: time="2026-02-18T23:43:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:43:45 volumio go-librespot[11475]: time="2026-02-18T23:43:45+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 23:43:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:43:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:43:45 volumio volumio[11106]: info: Connection to go-librespot Websocket closed Feb 18 23:43:45 volumio volumio[11106]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 18 23:43:47 volumio volumio[11106]: info: MyVolumio token set successfully Feb 18 23:43:47 volumio volumio[11106]: info: MYVOLUMIO: Adding device Feb 18 23:43:47 volumio volumio[11106]: info: MYVOLUMIO: Evaluating Server Feb 18 23:43:47 volumio volumio[11106]: info: MyVolumio status changed Feb 18 23:43:47 volumio volumio[11106]: info: Streaming services startup Feb 18 23:43:47 volumio volumio[11106]: info: Starting Streaming Daemon Feb 18 23:43:47 volumio volumio[11106]: info: Removing browser output: myVolumio user plan is not superstar Feb 18 23:43:47 volumio volumio[11106]: info: Removing audio output: Feb 18 23:43:47 volumio volumio[11106]: info: Stoppping Tunnel 1 Feb 18 23:43:47 volumio sudo[11510]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 23:43:47 volumio sudo[11510]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:47 volumio sudo[11510]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:47 volumio sudo[11513]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 18 23:43:47 volumio sudo[11513]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:47 volumio volumio[11106]: error: Cannot start Volumio Streaming Daemon Feb 18 23:43:47 volumio volumio[11106]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 23:43:47 volumio volumio[11106]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 23:43:47 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 23:43:47 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 23:43:47 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 23:43:47 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 23:43:47 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 23:43:47 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 23:43:47 volumio volumio[11106]: info: Setting Geolocation for MyVolumio to as1 Feb 18 23:43:47 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:43:47 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:43:47 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:43:47 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 23:43:47 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 23:43:47 volumio sudo[11513]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:47 volumio volumio[11106]: info: Remote SSH Stopped Feb 18 23:43:48 volumio volumio[11106]: info: Getting Spotify volume Feb 18 23:43:48 volumio volumio[11106]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 23:43:48 volumio volumio[11106]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 23:43:48 volumio volumio[11106]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 18 23:43:48 volumio volumio[11106]: errno: -111, Feb 18 23:43:48 volumio volumio[11106]: code: 'ECONNREFUSED', Feb 18 23:43:48 volumio volumio[11106]: syscall: 'connect', Feb 18 23:43:48 volumio volumio[11106]: address: '127.0.0.1', Feb 18 23:43:48 volumio volumio[11106]: port: 9879, Feb 18 23:43:48 volumio volumio[11106]: response: undefined Feb 18 23:43:48 volumio volumio[11106]: } Feb 18 23:43:48 volumio volumio[11106]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 23:43:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 18 23:43:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:48 volumio go-librespot[11527]: go-librespot daemon starting... Feb 18 23:43:48 volumio go-librespot[11528]: time="2026-02-18T23:43:48+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:43:48 volumio go-librespot[11528]: time="2026-02-18T23:43:48+07:00" level=debug msg="app state loaded" Feb 18 23:43:48 volumio go-librespot[11528]: time="2026-02-18T23:43:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:43:49 volumio go-librespot[11528]: time="2026-02-18T23:43: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:43:49 volumio go-librespot[11528]: time="2026-02-18T23:43:49+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 18 23:43:49 volumio go-librespot[11528]: time="2026-02-18T23:43:49+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 18 23:43:49 volumio go-librespot[11528]: time="2026-02-18T23:43:49+07:00" level=info msg="zeroconf server listening on port 41963" Feb 18 23:43:49 volumio sudo[11537]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 23:42' Feb 18 23:43:49 volumio sudo[11537]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:49 volumio go-librespot[11528]: time="2026-02-18T23:43:49+07:00" level=debug msg="obtained new client token: AACP8/v2BLVlVzcmMmJiqTAe3bU51D2sAmDRpSQGk03aESX2MUQCbgydfWvCp3wLakP+1OFFRT3k8PV0+I1u1M3rm5osl/cadMdEyLOtqmermYIgZNwxNzA1xZtusJxXnq/Voq3N0FQOUMgaOGzQWxzGtLsAowNIQVyl8pB/U5C9QRqjcB5BbFFn+T2IaoN+QGdQGrYdfvU1DItsYSighwt1gkiOW8WR+hWfGavZBWv4vO1tCtfIM3jdFw==" Feb 18 23:43:49 volumio go-librespot[11528]: time="2026-02-18T23:43:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:43:49 volumio sudo[11537]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:49 volumio go-librespot[11528]: time="2026-02-18T23:43:49+07:00" level=debug msg="completed keyexchange" Feb 18 23:43:49 volumio go-librespot[11528]: time="2026-02-18T23:43:49+07:00" level=debug msg="completed challenge" Feb 18 23:43:50 volumio go-librespot[11528]: time="2026-02-18T23:43:50+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 18 23:43:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:43:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:43:51 volumio volumio-remote-updater[25144]: [2026-02-18 23:43:51] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Feb 18 23:43:51 volumio volumio-remote-updater[25144]: [2026-02-18 23:43:51] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Feb 18 23:43:51 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:43:51 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 18 23:43:51 volumio systemd[1]: volumio.service: Consumed 57.349s CPU time. Feb 18 23:43:51 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 23:43:51 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 23:43:51 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 22611. Feb 18 23:43:51 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 23:43:51 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 18 23:43:51 volumio systemd[1]: volumio.service: Consumed 57.349s CPU time. Feb 18 23:43:51 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 18 23:43:51 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 23:43:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 18 23:43:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:53 volumio go-librespot[11575]: go-librespot daemon starting... Feb 18 23:43:53 volumio go-librespot[11576]: time="2026-02-18T23:43:53+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:43:53 volumio go-librespot[11576]: time="2026-02-18T23:43:53+07:00" level=debug msg="app state loaded" Feb 18 23:43:53 volumio go-librespot[11576]: time="2026-02-18T23:43:53+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:43:53 volumio go-librespot[11576]: time="2026-02-18T23:43: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:43:53 volumio go-librespot[11576]: time="2026-02-18T23:43:53+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 18 23:43:53 volumio go-librespot[11576]: time="2026-02-18T23:43:53+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 18 23:43:53 volumio go-librespot[11576]: time="2026-02-18T23:43:53+07:00" level=info msg="zeroconf server listening on port 43203" Feb 18 23:43:53 volumio go-librespot[11576]: time="2026-02-18T23:43:53+07:00" level=debug msg="obtained new client token: AABcaxH5A1w6C6Zu2hfNxaLYpOvgHL2LOKCrd/iBqJ1D4GivJ6ffNHD/vBUa2O8brCN5y6vQyGbVcEeY6TdVa5dfRJliKe7KfOGJmxWZq1bJC2CDw3kCyaGySPgERnE7aBFFbKAiyPvpnRPb9MFdjSI8mOAZs4DUh7YlTHxaMSyyg3crGlvMu7HuMTXb4mvH+O4rTNhNQA46HvnrAyasR6CmHRwqC19V6vR1iQSXB8WIinV6TJjxkudL2Q==" Feb 18 23:43:54 volumio go-librespot[11576]: time="2026-02-18T23:43:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:43:54 volumio go-librespot[11576]: time="2026-02-18T23:43:54+07:00" level=debug msg="completed keyexchange" Feb 18 23:43:54 volumio go-librespot[11576]: time="2026-02-18T23:43:54+07:00" level=debug msg="completed challenge" Feb 18 23:43:54 volumio go-librespot[11576]: time="2026-02-18T23:43: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 18 23:43:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:43:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:43:55 volumio volumio[11560]: info: ------------------------------------------- Feb 18 23:43:55 volumio volumio[11560]: info: ----- Volumio3 ---- Feb 18 23:43:55 volumio volumio[11560]: info: ------------------------------------------- Feb 18 23:43:55 volumio volumio[11560]: info: ----- System startup ---- Feb 18 23:43:55 volumio volumio[11560]: info: ------------------------------------------- Feb 18 23:43:56 volumio volumio-remote-updater[25144]: [2026-02-18 23:43:56] [connect] Successful connection Feb 18 23:43:56 volumio volumio[11560]: info: MYVOLUMIO Environment detected Feb 18 23:43:56 volumio volumio[11560]: info: Plugin folders cleanup Feb 18 23:43:56 volumio volumio[11560]: info: Scanning into folder /volumio/app/plugins/ Feb 18 23:43:56 volumio volumio[11560]: info: Scanning category audio_interface Feb 18 23:43:56 volumio volumio[11560]: info: Scanning category miscellanea Feb 18 23:43:56 volumio volumio[11560]: info: Scanning category music_service Feb 18 23:43:56 volumio volumio[11560]: info: Scanning category plugins.json Feb 18 23:43:56 volumio volumio[11560]: info: Scanning category system_controller Feb 18 23:43:56 volumio volumio[11560]: info: Scanning category user_interface Feb 18 23:43:56 volumio volumio[11560]: info: Scanning into folder /data/plugins/ Feb 18 23:43:56 volumio volumio[11560]: info: Scanning category music_service Feb 18 23:43:56 volumio volumio[11560]: info: Plugin folders cleanup completed Feb 18 23:43:56 volumio volumio[11560]: info: ------------------------------------------- Feb 18 23:43:56 volumio volumio[11560]: info: ----- Core plugins startup ---- Feb 18 23:43:56 volumio volumio[11560]: info: ------------------------------------------- Feb 18 23:43:56 volumio volumio[11560]: info: Loading plugins from folder /volumio/app/plugins/ Feb 18 23:43:56 volumio volumio[11560]: info: Adding plugin upnp to MyMusic Plugins Feb 18 23:43:56 volumio volumio[11560]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 18 23:43:56 volumio volumio[11560]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 18 23:43:56 volumio volumio[11560]: info: Loading plugins from folder /data/plugins/ Feb 18 23:43:56 volumio volumio[11560]: info: Loading plugin "system"... Feb 18 23:43:56 volumio volumio[11560]: info: Loading plugin "appearance"... Feb 18 23:43:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 18 23:43:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:57 volumio go-librespot[11596]: go-librespot daemon starting... Feb 18 23:43:57 volumio go-librespot[11597]: time="2026-02-18T23:43:57+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:43:57 volumio go-librespot[11597]: time="2026-02-18T23:43:57+07:00" level=debug msg="app state loaded" Feb 18 23:43:57 volumio go-librespot[11597]: time="2026-02-18T23:43:57+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:43:57 volumio go-librespot[11597]: time="2026-02-18T23:43:57+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:43:57 volumio go-librespot[11597]: time="2026-02-18T23:43:57+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 18 23:43:57 volumio go-librespot[11597]: time="2026-02-18T23:43:57+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 18 23:43:57 volumio go-librespot[11597]: time="2026-02-18T23:43:57+07:00" level=info msg="zeroconf server listening on port 45725" Feb 18 23:43:58 volumio go-librespot[11597]: time="2026-02-18T23:43:58+07:00" level=debug msg="obtained new client token: AACta7EKkkTOQ6aYecG3OjgTJFZbXa5kdrMg9yI2XAJYUAGFg29OBC5Gq66otlZlj7DYIPwiYNC3eGvx2KAZ8FJv3VxN+yDXxBAn6OZQuLEL3Ho9197obs72AIxSHRu+6VleLuj1U7tXuOctE3ZNNF7dwUyES8vr8oDOfJFJ12iJPxVg0MukcpnWMsCN/GQCyJTfqmZQo5r6W/x087tWef4Yh3bndnHl7dJWWcelWoqj9f5BOhSco2k=" Feb 18 23:43:58 volumio go-librespot[11597]: time="2026-02-18T23:43:58+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:43:58 volumio go-librespot[11597]: time="2026-02-18T23:43:58+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 23:43:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:43:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:43:58 volumio volumio[11560]: info: Loading plugin "network"... Feb 18 23:43:58 volumio volumio[11560]: info: Refreshing Cached IP Addresses Feb 18 23:43:58 volumio sudo[11606]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 23:43:58 volumio sudo[11606]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:58 volumio volumio[11560]: info: Loading plugin "services"... Feb 18 23:43:58 volumio sudo[11608]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 23:43:58 volumio sudo[11608]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:58 volumio sudo[11606]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:58 volumio volumio[11560]: info: Loading plugin "alsa_controller"... Feb 18 23:43:58 volumio sudo[11608]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:58 volumio sudo[11616]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 18 23:43:58 volumio sudo[11616]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:59 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 23:43:59 volumio volumio[11560]: info: Loading plugin "wizard"... Feb 18 23:43:59 volumio volumio[11560]: info: Loading plugin "networkfs"... Feb 18 23:43:59 volumio volumio[11560]: info: Starting Udev Watcher for removable devices Feb 18 23:43:59 volumio volumio[11560]: info: Ignoring mount for partition: boot Feb 18 23:43:59 volumio volumio[11560]: info: Ignoring mount for partition: volumio Feb 18 23:43:59 volumio volumio[11560]: info: Ignoring mount for partition: volumio_data Feb 18 23:43:59 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 23:43:59 volumio volumio[11560]: info: Loading plugin "volumio_command_line_client"... Feb 18 23:43:59 volumio volumio[11560]: info: Loading plugin "upnp"... Feb 18 23:43:59 volumio volumio[11560]: info: [1771433039234] Starting Upmpd Daemon Feb 18 23:43:59 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 23:43:59 volumio volumio[11560]: info: Loading plugin "my_music"... Feb 18 23:43:59 volumio volumio[11560]: info: Loading plugin "mpd"... Feb 18 23:43:59 volumio volumio[11560]: info: Loading plugin "upnp_browser"... Feb 18 23:44:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 18 23:44:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:44:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:44:01 volumio go-librespot[11640]: go-librespot daemon starting... Feb 18 23:44:01 volumio go-librespot[11641]: time="2026-02-18T23:44:01+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:44:01 volumio go-librespot[11641]: time="2026-02-18T23:44:01+07:00" level=debug msg="app state loaded" Feb 18 23:44:01 volumio sudo[11616]: pam_unix(sudo:session): session closed for user root Feb 18 23:44:01 volumio go-librespot[11641]: time="2026-02-18T23:44:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:44:02 volumio go-librespot[11641]: time="2026-02-18T23:44:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:44:02 volumio go-librespot[11641]: time="2026-02-18T23:44:02+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 23:44:02 volumio go-librespot[11641]: time="2026-02-18T23:44:02+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 23:44:02 volumio go-librespot[11641]: time="2026-02-18T23:44:02+07:00" level=info msg="zeroconf server listening on port 34077" Feb 18 23:44:02 volumio go-librespot[11641]: time="2026-02-18T23:44:02+07:00" level=debug msg="obtained new client token: AADERtaP/etux7DssfjtNSIHniecJDF6/5mc+o4zEPnlfbnHKAcNUpAw0cM494CcojQvR6qpSY0hF+/3ly9qImg+OO8Zt435lgBxPRsll46MmVZDWq+KAjU/im5tGILhCwIL7ZNR4Vej+UrQuKwvmM2a0mu4u2JCV/UBuuJVpVX9w0KjUUwBZ2OcfgYKObagPjXLHsSrQ3fo/C/6IggUo2TG0BRNzm157W63Hw4yxalKlDC1vrLSqzpATw==" Feb 18 23:44:02 volumio go-librespot[11641]: time="2026-02-18T23:44:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:44:02 volumio go-librespot[11641]: time="2026-02-18T23:44:02+07:00" level=debug msg="completed keyexchange" Feb 18 23:44:02 volumio go-librespot[11641]: time="2026-02-18T23:44:02+07:00" level=debug msg="completed challenge" Feb 18 23:44:02 volumio go-librespot[11641]: time="2026-02-18T23:44: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 18 23:44:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:44:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:44:02 volumio volumio[11560]: info: Starting UPNP Browser Feb 18 23:44:02 volumio volumio[11560]: info: Loading plugin "alarm-clock"... Feb 18 23:44:03 volumio volumio[11560]: info: Loading plugin "airplay_emulation"... Feb 18 23:44:03 volumio volumio[11560]: info: Starting Shairport Sync Feb 18 23:44:03 volumio volumio[11560]: info: Loading plugin "last_100"... Feb 18 23:44:03 volumio volumio[11560]: info: Loading plugin "webradio"... Feb 18 23:44:03 volumio volumio[11560]: info: Loading plugin "i2s_dacs"... Feb 18 23:44:03 volumio volumio[11560]: info: Loading plugin "volumiodiscovery"... Feb 18 23:44:03 volumio volumio[11560]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 23:44:03 volumio volumio[11560]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 23:44:03 volumio volumio[11560]: *** WARNING *** For more information see Feb 18 23:44:03 volumio volumio[11560]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 23:44:03 volumio volumio[11560]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 23:44:03 volumio volumio[11560]: *** WARNING *** For more information see Feb 18 23:44:03 volumio node[11560]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 23:44:03 volumio node[11560]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 23:44:03 volumio node[11560]: *** WARNING *** For more information see Feb 18 23:44:03 volumio node[11560]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 23:44:03 volumio node[11560]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 23:44:03 volumio node[11560]: *** WARNING *** For more information see Feb 18 23:44:03 volumio volumio[11560]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 18 23:44:03 volumio volumio[11560]: info: Discovery: Started advertising with name: Volumio Feb 18 23:44:03 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 23:44:03 volumio volumio[11560]: info: Loading plugin "spop"... Feb 18 23:44:05 volumio volumio[11560]: info: Loading plugin "ytcr"... Feb 18 23:44:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 18 23:44:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:44:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:44:05 volumio go-librespot[11650]: go-librespot daemon starting... Feb 18 23:44:05 volumio go-librespot[11651]: time="2026-02-18T23:44:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:44:05 volumio go-librespot[11651]: time="2026-02-18T23:44:05+07:00" level=debug msg="app state loaded" Feb 18 23:44:05 volumio go-librespot[11651]: time="2026-02-18T23:44:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:44:06 volumio go-librespot[11651]: time="2026-02-18T23:44:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 23:44:06 volumio go-librespot[11651]: time="2026-02-18T23:44:06+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 23:44:06 volumio go-librespot[11651]: time="2026-02-18T23:44:06+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 23:44:06 volumio go-librespot[11651]: time="2026-02-18T23:44:06+07:00" level=info msg="zeroconf server listening on port 38063" Feb 18 23:44:06 volumio go-librespot[11651]: time="2026-02-18T23:44:06+07:00" level=debug msg="obtained new client token: AACLEY6K7Wdwa8s7NnQbW9ueIrkThINl3+cKqsIGejmwjcKrYRTSyLWXExZM4h9XnHYe7MmbnA2XSadyLX2CEMm2RvUAJmAGAb05jFOOVg78uxorY6aI6EvKtRVRISsqlNJEFitw4Te1nolgCLGXP/GN2idYp2S0nYKUMjCQ6jHZFdjcOmdkEQcbF1v3Zp9Ge3aOd9evy7znWhrFkQY+GYg2qR7nb+B4Rqrut/OMBdpEgElu38GxrpFP7g==" Feb 18 23:44:06 volumio go-librespot[11651]: time="2026-02-18T23:44:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:44:06 volumio go-librespot[11651]: time="2026-02-18T23:44:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 23:44:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:44:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:44:08 volumio volumio[11560]: info: Loading plugin "ytmusic"... Feb 18 23:44:08 volumio volumio-remote-updater[25144]: [2026-02-18 23:44:08] [connect] Successful connection Feb 18 23:44:09 volumio volumio[11560]: info: Loading plugin "outputs"... Feb 18 23:44:09 volumio volumio[11560]: info: Loading plugin "albumart"... Feb 18 23:44:09 volumio volumio[11560]: info: Plugin example_plugin is not enabled Feb 18 23:44:09 volumio volumio[11560]: info: Loading plugin "inputs"... Feb 18 23:44:09 volumio volumio[11560]: info: Loading plugin "updater_comm"... Feb 18 23:44:09 volumio volumio[11560]: info: Plugin mpdemulation is not enabled Feb 18 23:44:09 volumio volumio[11560]: info: Loading plugin "rest_api"... Feb 18 23:44:09 volumio volumio[11560]: info: Loading plugin "websocket"... Feb 18 23:44:09 volumio volumio[11560]: info: Starting Socket.io Server version 1.7.4 Feb 18 23:44:09 volumio volumio[11560]: info: Loading plugin "RoonBridge"... Feb 18 23:44:09 volumio volumio[11560]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 23:44:09 volumio volumio[11560]: info: Loading i18n strings for locale en Feb 18 23:44:09 volumio volumio[11560]: Updating browse sources language Feb 18 23:44:09 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 23:44:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 18 23:44:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:44:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:44:10 volumio go-librespot[11682]: go-librespot daemon starting... Feb 18 23:44:10 volumio go-librespot[11683]: time="2026-02-18T23:44:10+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:44:10 volumio go-librespot[11683]: time="2026-02-18T23:44:10+07:00" level=debug msg="app state loaded" Feb 18 23:44:10 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 23:44:10 volumio volumio[11560]: info: CoreCommandRouter::initPlayerControls Feb 18 23:44:10 volumio go-librespot[11683]: time="2026-02-18T23:44:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:44:10 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:44:10 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:44:10 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:44:10 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:44:10 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:44:10 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:44:10 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:44:10 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:44:10 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 23:44:10 volumio volumio[11560]: Express server listening on port 3000 Feb 18 23:44:10 volumio volumio[11560]: [Metrics] WebUI: 15s 883.83ms Feb 18 23:44:10 volumio volumio[11672]: Forking 3 albumart workers Feb 18 23:44:10 volumio volumio[11560]: info: CoreStateMachine::resetVolumioState Feb 18 23:44:10 volumio volumio[11560]: info: CoreStateMachine::getcurrentVolume Feb 18 23:44:10 volumio volumio[11560]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 23:44:10 volumio volumio[11560]: info: Volumio Network Manager: Network status updated: 1 Feb 18 23:44:10 volumio sudo[11706]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 23:44:10 volumio sudo[11706]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:44:10 volumio sudo[11715]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 23:44:10 volumio sudo[11706]: pam_unix(sudo:session): session closed for user root Feb 18 23:44:10 volumio sudo[11715]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:44:10 volumio sudo[11715]: pam_unix(sudo:session): session closed for user root Feb 18 23:44:10 volumio go-librespot[11683]: time="2026-02-18T23:44: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:44:10 volumio go-librespot[11683]: time="2026-02-18T23:44:10+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 18 23:44:10 volumio go-librespot[11683]: time="2026-02-18T23:44:10+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 18 23:44:10 volumio go-librespot[11683]: time="2026-02-18T23:44:10+07:00" level=info msg="zeroconf server listening on port 34691" Feb 18 23:44:10 volumio volumio[11560]: info: VolumeController:: Volume=100 Mute =false Feb 18 23:44:10 volumio volumio[11560]: info: CoreStateMachine::pushState Feb 18 23:44:10 volumio volumio[11560]: info: CorePlayQueue::getTrack 0 Feb 18 23:44:10 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 23:44:10 volumio volumio[11560]: info: CoreCommandRouter::volumioPushState Feb 18 23:44:10 volumio volumio[11560]: info: CoreStateMachine::updateTrackBlock Feb 18 23:44:10 volumio volumio[11560]: info: CorePlayQueue::getTrackBlock Feb 18 23:44:10 volumio volumio[11560]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 23:44:11 volumio volumio-remote-updater[25144]: [2026-02-18 23:44:11] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771433048 101 Feb 18 23:44:11 volumio volumio[11560]: 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 18 23:44:11 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:44:11 volumio go-librespot[11683]: time="2026-02-18T23:44:11+07:00" level=debug msg="obtained new client token: AADNcFyiImOAT5rgJfgUSsIpeJBx9ffhrImGWUygeOPgKiHjKaQ17FRpsW1n7GNGtRZYJQr4khNstW7W8S6bjWRQoiV9CDKd1/43HIKVLQIkSMl9/2pAryiKSuGBP0HBhF9SKjMWEwpTiS8jzyX51oi4FT0krHOSQoCJ4rqZ0BXtez8TBqUO0xkqWIt3QOYm2Sn0Y2xgbuNE9eRkHqsexF47g3ziMtfrWuGBXjX5j+UWN3v5UZYdnlE=" Feb 18 23:44:11 volumio volumio[11560]: info: Reloading queue from file Feb 18 23:44:11 volumio volumio[11560]: info: CoreStateMachine::setRepeat null single undefined Feb 18 23:44:11 volumio volumio[11560]: info: CoreStateMachine::pushState Feb 18 23:44:11 volumio volumio[11560]: info: CorePlayQueue::getTrack 0 Feb 18 23:44:11 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 23:44:11 volumio volumio[11560]: info: CoreCommandRouter::volumioPushState Feb 18 23:44:11 volumio volumio[11560]: info: CoreStateMachine::setRandom null Feb 18 23:44:11 volumio volumio[11560]: info: CoreStateMachine::pushState Feb 18 23:44:11 volumio volumio[11560]: info: CorePlayQueue::getTrack 0 Feb 18 23:44:11 volumio volumio[11560]: info: CoreCommandRouter::volumioPushState Feb 18 23:44:11 volumio volumio[11560]: info: Setting Device type: Raspberry PI Feb 18 23:44:11 volumio go-librespot[11683]: time="2026-02-18T23:44:11+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 18 23:44:11 volumio volumio[11560]: info: Completed loading Core Plugins Feb 18 23:44:11 volumio volumio[11560]: info: Preparing to generate the ALSA configuration file Feb 18 23:44:11 volumio go-librespot[11683]: time="2026-02-18T23:44:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 18 23:44:11 volumio volumio[11560]: info: VolumeController:: Volume=100 Mute =false Feb 18 23:44:11 volumio volumio[11560]: info: CoreStateMachine::pushState Feb 18 23:44:11 volumio volumio[11560]: info: CorePlayQueue::getTrack 0 Feb 18 23:44:11 volumio volumio[11560]: info: CoreCommandRouter::volumioPushState Feb 18 23:44:11 volumio go-librespot[11683]: time="2026-02-18T23:44:11+07:00" level=debug msg="completed keyexchange" Feb 18 23:44:11 volumio go-librespot[11683]: time="2026-02-18T23:44:11+07:00" level=debug msg="completed challenge" Feb 18 23:44:11 volumio volumio[11560]: info: Asound.conf file unchanged, so no further update is needed Feb 18 23:44:11 volumio volumio[11560]: info: Output device has changed, restarting MPD Feb 18 23:44:11 volumio sudo[11742]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 23:44:11 volumio sudo[11742]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:44:11 volumio go-librespot[11683]: time="2026-02-18T23:44: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 18 23:44:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:44:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:44:11 volumio volumio[11560]: info: Output device has changed, restarting Shairport Sync Feb 18 23:44:11 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:44:11 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:44:11 volumio sudo[11745]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 23:44:11 volumio sudo[11745]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:44:11 volumio sudo[11745]: pam_unix(sudo:session): session closed for user root Feb 18 23:44:11 volumio sudo[11747]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 23:44:11 volumio sudo[11747]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:44:11 volumio sudo[11742]: pam_unix(sudo:session): session closed for user root Feb 18 23:44:11 volumio volumio[11560]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 23:44:11 volumio volumio[11560]: info: ___________ START PLUGINS ___________ Feb 18 23:44:11 volumio volumio[11560]: info: ControllerMpd::onStart: Initializing MPD Feb 18 23:44:11 volumio volumio[11560]: info: Creating MPD Configuration file Feb 18 23:44:11 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 23:44:11 volumio sudo[11755]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 23:44:11 volumio sudo[11755]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:44:11 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 23:44:11 volumio volumio[11560]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 23:44:11 volumio sudo[11755]: pam_unix(sudo:session): session closed for user root Feb 18 23:44:11 volumio volumio[11560]: info: [1771433051928] CoreMusicLibrary::Adding element Media Servers Feb 18 23:44:11 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 23:44:11 volumio sudo[11757]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 23:44:11 volumio sudo[11757]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:44:11 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 23:44:11 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 23:44:11 volumio systemd[1]: mpd.service: Consumed 7.192s CPU time. Feb 18 23:44:11 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 23:44:11 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 23:44:11 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 23:44:11 volumio volumio[11560]: info: UPNP Browser: Client initialized successfully Feb 18 23:44:12 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:44:12 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:44:12 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 23:44:12 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 23:44:12 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 23:44:12 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 23:44:12 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 23:44:12 volumio volumio[11560]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 23:44:12 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:44:12 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:44:12 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 23:44:12 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 23:44:12 volumio volumio[11560]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 23:44:12 volumio volumio[11560]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 23:44:12 volumio volumio[11560]: info: [1771433052262] CoreMusicLibrary::Adding element Last_100 Feb 18 23:44:12 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 23:44:12 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 23:44:12 volumio volumio[11560]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 23:44:12 volumio volumio[11560]: info: [1771433052275] CoreMusicLibrary::Adding element Webradio Feb 18 23:44:12 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 23:44:12 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 23:44:12 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 23:44:12 volumio volumio[11560]: info: Initializing BBC Radios Feb 18 23:44:12 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 23:44:12 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:44:12 volumio volumio[11560]: info: Creating Spotify config file Feb 18 23:44:12 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:44:12 volumio sudo[11771]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 23:44:12 volumio sudo[11771]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 23:44:12 volumio sudo[11771]: pam_unix(sudo:session): session closed for user root Feb 18 23:44:13 volumio volumio[11560]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 23:44:13 volumio volumio[11560]: info: [1771433053389] CoreMusicLibrary::Adding element YouTube Music Feb 18 23:44:13 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 23:44:13 volumio volumio[11560]: Cannot find translation for source YouTube Music Feb 18 23:44:13 volumio volumio[11560]: info: Volumio Calling Home Feb 18 23:44:13 volumio sudo[11788]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 23:44:13 volumio sudo[11788]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:44:13 volumio volumio[11694]: Starting albumart workers Feb 18 23:44:13 volumio volumio[11696]: Starting albumart workers Feb 18 23:44:13 volumio sudo[11788]: pam_unix(sudo:session): session closed for user root Feb 18 23:44:13 volumio volumio[11693]: Starting albumart workers Feb 18 23:44:14 volumio volumio[11560]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 23:44:14 volumio volumio[11560]: info: Discovery: Found device Volumio Feb 18 23:44:14 volumio volumio[11560]: info: CoreCommandRouter::volumioGetState Feb 18 23:44:14 volumio volumio[11560]: info: CorePlayQueue::getTrack 0 Feb 18 23:44:14 volumio volumio[11560]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 23:44:14 volumio volumio[11560]: info: Discovery: Found device Volumio Feb 18 23:44:14 volumio volumio[11560]: info: CoreCommandRouter::volumioGetState Feb 18 23:44:14 volumio volumio[11560]: info: CorePlayQueue::getTrack 0 Feb 18 23:44:14 volumio volumio[11560]: info: MPD Permissions set Feb 18 23:44:14 volumio volumio[11560]: info: MPD Permissions set Feb 18 23:44:14 volumio volumio[11560]: info: Upmpdcli Daemon Started Feb 18 23:44:14 volumio volumio[11560]: info: Spotify config file written Feb 18 23:44:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 18 23:44:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:44:14 volumio volumio[11560]: 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 18 23:44:14 volumio sudo[11794]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 23:44:14 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:44:14 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:44:14 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:44:14 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:44:14 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:44:14 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:44:14 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:44:14 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:44:14 volumio sudo[11794]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:44:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:44:14 volumio go-librespot[11795]: go-librespot daemon starting... Feb 18 23:44:14 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:44:14 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:44:14 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:44:14 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:44:14 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:44:14 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:44:15 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:44:15 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:44:15 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:44:15 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:44:15 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 18 23:44:15 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 18 23:44:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:44:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:44:15 volumio go-librespot[11809]: go-librespot daemon starting... Feb 18 23:44:15 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:44:15 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:44:15 volumio volumio[11560]: info: No need to fix Spotify hosts Feb 18 23:44:15 volumio sudo[11794]: pam_unix(sudo:session): session closed for user root Feb 18 23:44:15 volumio go-librespot[11813]: time="2026-02-18T23:44:15+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:44:15 volumio go-librespot[11813]: time="2026-02-18T23:44:15+07:00" level=debug msg="app state loaded" Feb 18 23:44:15 volumio go-librespot[11813]: time="2026-02-18T23:44:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:44:15 volumio go-librespot[11813]: time="2026-02-18T23:44: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-gew1.spotify.com:80]" Feb 18 23:44:15 volumio go-librespot[11813]: time="2026-02-18T23:44:15+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 18 23:44:15 volumio go-librespot[11813]: time="2026-02-18T23:44:15+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 18 23:44:15 volumio go-librespot[11813]: time="2026-02-18T23:44:15+07:00" level=info msg="zeroconf server listening on port 37789" Feb 18 23:44:15 volumio volumio[11560]: info: Volumio called home Feb 18 23:44:16 volumio go-librespot[11813]: time="2026-02-18T23:44:16+07:00" level=debug msg="obtained new client token: AABKThHoJ97UCsb3g/3tyTFKZtF30x/T2u7rNdob4qUhoKtd9jWpDiSrYPgKzLabgXiuJbeVU5eKilq9L1deDyeIiFL38R76LOjhpgZni0W8/WXXW5adCRiSVx5X+1tl0hj2pqA9IJFnHSeDC8YxOSgrJatcfB/A6yGg/hGkBwzufSW770vdXLelszHEyKfWkcEH8GM0osWHNLyF9QhlPgwfAPrFchKnrKariqCf6+4jc+t3O0g9Nik=" Feb 18 23:44:16 volumio go-librespot[11813]: time="2026-02-18T23:44:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:44:16 volumio go-librespot[11813]: time="2026-02-18T23:44:16+07:00" level=debug msg="completed keyexchange" Feb 18 23:44:16 volumio go-librespot[11813]: time="2026-02-18T23:44:16+07:00" level=debug msg="completed challenge" Feb 18 23:44:16 volumio volumio[11560]: info: Starting Shairport Sync Feb 18 23:44:16 volumio go-librespot[11813]: time="2026-02-18T23:44: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 18 23:44:16 volumio volumio[11560]: info: Starting Shairport Sync Feb 18 23:44:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:44:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:44:16 volumio volumio[11560]: info: Starting Shairport Sync Feb 18 23:44:16 volumio sudo[11840]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 23:44:16 volumio sudo[11840]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:44:16 volumio sudo[11842]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 23:44:16 volumio sudo[11842]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:44:16 volumio sudo[11844]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 23:44:16 volumio sudo[11844]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:44:16 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 23:44:16 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 23:44:16 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 23:44:16 volumio systemd[1]: shairport-sync.service: Consumed 2.338s CPU time. Feb 18 23:44:16 volumio volumio[11560]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 23:44:16 volumio volumio[11560]: SPOTIFY: BQAmXzWw3_8AAo7NkPhveGCiKfnmX0NrW_BxNIp0HlhSCq1uj2fHoiaRa0qrAJ-gudI2Vqb2EEMfe7MIsFo4w641Laue3L-oBDyj_EJWM8iJocRLfDDOTIlVtFBC9fGUxgDGYRnv4SWKZN9QtZXXzqMuIw7QWKdsak-CKNKxuk1mZjLrWjzXJHs81n-WUlQjDX1RhidIEgzXV6NbSezbSlA59OWzd8RZ1V2NdRCsifmoSLiRvwKXIKgFutycrxc2732DDQH3OftNO-K0OO5QEny3LOi5ZXUWlAairttekwznT7XMFlmY5_KS Feb 18 23:44:16 volumio volumio[11560]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 23:44:16 volumio volumio[11560]: info: New Spotify access token = BQAmXzWw3_8AAo7NkPhveGCiKfnmX0NrW_BxNIp0HlhSCq1uj2fHoiaRa0qrAJ-gudI2Vqb2EEMfe7MIsFo4w641Laue3L-oBDyj_EJWM8iJocRLfDDOTIlVtFBC9fGUxgDGYRnv4SWKZN9QtZXXzqMuIw7QWKdsak-CKNKxuk1mZjLrWjzXJHs81n-WUlQjDX1RhidIEgzXV6NbSezbSlA59OWzd8RZ1V2NdRCsifmoSLiRvwKXIKgFutycrxc2732DDQH3OftNO-K0OO5QEny3LOi5ZXUWlAairttekwznT7XMFlmY5_KS Feb 18 23:44:16 volumio volumio[11560]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 23:44:16 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 23:44:16 volumio sudo[11840]: pam_unix(sudo:session): session closed for user root Feb 18 23:44:16 volumio sudo[11842]: pam_unix(sudo:session): session closed for user root Feb 18 23:44:16 volumio sudo[11844]: pam_unix(sudo:session): session closed for user root Feb 18 23:44:16 volumio volumio[11560]: info: Shairport-Sync Started Feb 18 23:44:16 volumio volumio[11560]: Error adding Membership: Error: addMembership EINVAL Feb 18 23:44:16 volumio volumio[11560]: info: Shairport-Sync Started Feb 18 23:44:16 volumio volumio[11560]: info: Shairport-Sync Started Feb 18 23:44:17 volumio volumio[11560]: info: CoreCommandRouter::volumioGetState Feb 18 23:44:17 volumio volumio[11560]: info: CorePlayQueue::getTrack 0 Feb 18 23:44:17 volumio volumio[11560]: 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 18 23:44:17 volumio volumio[11560]: info: Spotify Successfully logged in Feb 18 23:44:17 volumio volumio[11560]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 23:44:17 volumio volumio[11560]: info: [1771433057554] CoreMusicLibrary::Adding element Spotify Feb 18 23:44:17 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 23:44:17 volumio volumio[11560]: Cannot find translation for source YouTube Music Feb 18 23:44:17 volumio volumio[11560]: Cannot find translation for source Spotify Feb 18 23:44:18 volumio volumio[11560]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 23:44:18 volumio volumio[11560]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 23:44:18 volumio volumio[11560]: info: VolumeController:: Volume=100 Mute =false Feb 18 23:44:18 volumio volumio[11560]: info: CoreCommandRouter::volumioGetState Feb 18 23:44:18 volumio volumio[11560]: info: CorePlayQueue::getTrack 0 Feb 18 23:44:18 volumio volumio[11560]: info: CoreStateMachine::pushState Feb 18 23:44:18 volumio volumio[11560]: info: CorePlayQueue::getTrack 0 Feb 18 23:44:18 volumio volumio[11560]: info: CoreCommandRouter::volumioPushState Feb 18 23:44:19 volumio volumio[11560]: info: go-librespot daemon successfully initialized Feb 18 23:44:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 18 23:44:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:44:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:44:19 volumio go-librespot[11881]: go-librespot daemon starting... Feb 18 23:44:19 volumio go-librespot[11882]: time="2026-02-18T23:44:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:44:19 volumio go-librespot[11882]: time="2026-02-18T23:44:19+07:00" level=debug msg="app state loaded" Feb 18 23:44:19 volumio go-librespot[11882]: time="2026-02-18T23:44:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:44:19 volumio mpd[11786]: 2026-02-18T23:44:19 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 23:44:19 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 23:44:19 volumio sudo[11757]: pam_unix(sudo:session): session closed for user root Feb 18 23:44:19 volumio sudo[11747]: pam_unix(sudo:session): session closed for user root Feb 18 23:44:19 volumio volumio[11560]: error: MPD error: The expression evaluated to a falsy value: Feb 18 23:44:19 volumio volumio[11560]: assert.ok(self.idling) Feb 18 23:44:19 volumio volumio[11560]: error: The expression evaluated to a falsy value: Feb 18 23:44:19 volumio volumio[11560]: assert.ok(self.idling) Feb 18 23:44:19 volumio volumio[11560]: error: updateQueue error: null Feb 18 23:44:20 volumio volumio[11560]: info: MPD running with PID11786 Feb 18 23:44:20 volumio volumio[11560]: ,establishing connection Feb 18 23:44:20 volumio volumio[11560]: info: Completed starting Core Plugins Feb 18 23:44:20 volumio volumio[11560]: info: ------------------------------------------- Feb 18 23:44:20 volumio volumio[11560]: info: ----- MyVolumio plugins startup ---- Feb 18 23:44:20 volumio volumio[11560]: info: ------------------------------------------- Feb 18 23:44:20 volumio volumio[11560]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 23:44:20 volumio volumio[11560]: error: updateQueue error: null Feb 18 23:44:20 volumio go-librespot[11882]: time="2026-02-18T23:44: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:44:20 volumio go-librespot[11882]: time="2026-02-18T23:44:20+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 18 23:44:20 volumio go-librespot[11882]: time="2026-02-18T23:44:20+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 18 23:44:20 volumio go-librespot[11882]: time="2026-02-18T23:44:20+07:00" level=info msg="zeroconf server listening on port 46811" Feb 18 23:44:20 volumio go-librespot[11882]: time="2026-02-18T23:44:20+07:00" level=debug msg="obtained new client token: AACYqSiS3jCkxUWHY54lbGhjMkSroi2PoZ5hBdirQ/7p+7zpYXhTXjLYzCOnU0yVphBv8hGX7dKT887RasAOBAi/up5r7dlegC6NTUc11O5slqKOvHlHUql+QBXWD7EGzHzmb68wm5IWy9CCss1L/dw0ezDBl++/y8EsUaYlrsi6X9EM7uYH6NeXP2eME8bFCk/mlYOBVTLSiF7YCnXje9WXOhDjvICoHvnOmEbP3Kdx8Y7acrJNUSmE/A==" Feb 18 23:44:20 volumio go-librespot[11882]: time="2026-02-18T23:44: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 18 23:44:20 volumio go-librespot[11882]: time="2026-02-18T23:44:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 18 23:44:20 volumio go-librespot[11882]: time="2026-02-18T23:44:20+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 23:44:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:44:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:44:22 volumio volumio[11560]: info: Initializing connection to go-librespot Websocket Feb 18 23:44:22 volumio volumio[11560]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 23:44:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 18 23:44:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:44:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:44:24 volumio go-librespot[11894]: go-librespot daemon starting... Feb 18 23:44:24 volumio go-librespot[11895]: time="2026-02-18T23:44:24+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:44:24 volumio go-librespot[11895]: time="2026-02-18T23:44:24+07:00" level=debug msg="app state loaded" Feb 18 23:44:24 volumio go-librespot[11895]: time="2026-02-18T23:44:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:44:24 volumio go-librespot[11895]: time="2026-02-18T23:44:24+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 23:44:24 volumio go-librespot[11895]: time="2026-02-18T23:44:24+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 18 23:44:24 volumio go-librespot[11895]: time="2026-02-18T23:44:24+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 18 23:44:24 volumio go-librespot[11895]: time="2026-02-18T23:44:24+07:00" level=info msg="zeroconf server listening on port 37897" Feb 18 23:44:24 volumio volumio[11560]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 23:44:24 volumio go-librespot[11895]: time="2026-02-18T23:44:24+07:00" level=debug msg="obtained new client token: AAAl3zwUBXfjSb8FFMfmBIkB3N2wa87qXy26Nraew+cd/IGtFeaLtp8QWxeh0mHrWtOSq1fDKtTJsIpi61I7p/thCDjO2Py7PclG6rn2KhbxiSVkXVjENkKhgK6RUdtWDbuLuGyc+JiPnXfEeeuKIj/64M58BIDtldPVEzZsn04lKzVpSVETKSUw8U6jtGH5etJG9K0DJl6VWXhCcuepzHHE6m5ABUQSmoR0v6JIAOEgsn39wM+QxTSJxA==" Feb 18 23:44:24 volumio go-librespot[11895]: time="2026-02-18T23:44:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:44:25 volumio go-librespot[11895]: time="2026-02-18T23:44:25+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 23:44:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:44:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:44:25 volumio volumio[11560]: info: Initializing connection to go-librespot Websocket Feb 18 23:44:25 volumio volumio[11560]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 23:44:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 18 23:44:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:44:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:44:28 volumio go-librespot[11902]: go-librespot daemon starting... Feb 18 23:44:28 volumio go-librespot[11903]: time="2026-02-18T23:44:28+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:44:28 volumio go-librespot[11903]: time="2026-02-18T23:44:28+07:00" level=debug msg="app state loaded" Feb 18 23:44:28 volumio go-librespot[11903]: time="2026-02-18T23:44:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:44:28 volumio volumio[11560]: info: Initializing connection to go-librespot Websocket Feb 18 23:44:28 volumio go-librespot[11903]: time="2026-02-18T23:44:28+07:00" level=debug msg="new websocket client" Feb 18 23:44:28 volumio volumio[11560]: info: Connection to go-librespot Websocket established Feb 18 23:44:28 volumio go-librespot[11903]: time="2026-02-18T23:44:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:44:28 volumio go-librespot[11903]: time="2026-02-18T23:44:28+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 18 23:44:28 volumio go-librespot[11903]: time="2026-02-18T23:44:28+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 18 23:44:28 volumio go-librespot[11903]: time="2026-02-18T23:44:28+07:00" level=info msg="zeroconf server listening on port 41551" Feb 18 23:44:28 volumio volumio[11560]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 23:44:28 volumio volumio[11560]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 23:44:28 volumio volumio[11560]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 23:44:28 volumio volumio[11560]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 23:44:28 volumio volumio[11560]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 23:44:28 volumio volumio[11560]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 23:44:28 volumio volumio[11560]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 23:44:28 volumio volumio[11560]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 23:44:28 volumio volumio[11560]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 23:44:28 volumio volumio[11560]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 23:44:28 volumio volumio[11560]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 23:44:28 volumio volumio[11560]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 23:44:28 volumio volumio[11560]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 23:44:28 volumio volumio[11560]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 23:44:28 volumio volumio[11560]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 23:44:28 volumio volumio[11560]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 23:44:28 volumio volumio[11560]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 23:44:28 volumio volumio[11560]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 23:44:28 volumio volumio[11560]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 23:44:28 volumio volumio[11560]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 23:44:28 volumio volumio[11560]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 23:44:28 volumio volumio[11560]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 23:44:28 volumio volumio[11560]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 23:44:28 volumio volumio[11560]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 23:44:28 volumio volumio[11560]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 23:44:28 volumio volumio[11560]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 23:44:28 volumio volumio[11560]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 23:44:28 volumio volumio[11560]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 23:44:28 volumio volumio[11560]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 23:44:28 volumio volumio[11560]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 23:44:28 volumio volumio[11560]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 23:44:28 volumio volumio[11560]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 23:44:28 volumio volumio[11560]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 23:44:28 volumio volumio[11560]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 23:44:28 volumio volumio[11560]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 23:44:28 volumio volumio[11560]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 23:44:29 volumio go-librespot[11903]: time="2026-02-18T23:44:29+07:00" level=debug msg="obtained new client token: AABQkBSZg8MZ0jdjq2VRKqN+CS3fjtSgbRrIrDpjAw+Q99AtZf5PxpediypgxgIpPynW0Hh2c0nRYn64sichImXCWKXPeRlUgLPBkUKh1D5Fjl1Wc8I8mIR525SuKy++oPAt4/d+kHjXGODiQqHdN8+EUpc47iw+1EIgvmKvlZq70QEnlLhGQYqP9wqgNiO/1XcrWUAZOtIPAb8mNx5ISHO9G71qxePVlXyGApOiTKWvKJv2dKu4jLU=" Feb 18 23:44:29 volumio go-librespot[11903]: time="2026-02-18T23:44:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:44:29 volumio go-librespot[11903]: time="2026-02-18T23:44:29+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 23:44:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:44:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:44:30 volumio volumio[11560]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 23:44:30 volumio volumio[11560]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 23:44:30 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:44:30 volumio volumio[11560]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:44:30 volumio volumio[11560]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 23:44:30 volumio volumio[11560]: info: MyVolumio login type: Token Feb 18 23:44:30 volumio volumio[11560]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 23:44:30 volumio volumio[11560]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 23:44:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 18 23:44:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:44:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:44:32 volumio go-librespot[11926]: go-librespot daemon starting... Feb 18 23:44:32 volumio volumio[11560]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 23:44:32 volumio volumio[11560]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 23:44:32 volumio volumio[11560]: info: Streaming services startup Feb 18 23:44:32 volumio volumio[11560]: info: Starting Streaming Daemon Feb 18 23:44:32 volumio go-librespot[11927]: time="2026-02-18T23:44:32+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:44:32 volumio go-librespot[11927]: time="2026-02-18T23:44:32+07:00" level=debug msg="app state loaded" Feb 18 23:44:32 volumio go-librespot[11927]: time="2026-02-18T23:44:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:44:32 volumio sudo[11934]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 23:44:32 volumio sudo[11934]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:44:32 volumio volumio[11560]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 23:44:32 volumio sudo[11934]: pam_unix(sudo:session): session closed for user root Feb 18 23:44:32 volumio volumio[11560]: info: Getting Spotify volume Feb 18 23:44:32 volumio volumio[11560]: info: Connection to go-librespot Websocket closed Feb 18 23:44:32 volumio volumio[11560]: error: Cannot start Volumio Streaming Daemon Feb 18 23:44:32 volumio volumio[11560]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 23:44:32 volumio volumio[11560]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 23:44:32 volumio volumio[11560]: 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 18 23:44:33 volumio volumio[11560]: info: CoreCommandRouter::volumioGetState Feb 18 23:44:33 volumio volumio[11560]: info: CorePlayQueue::getTrack 0 Feb 18 23:44:33 volumio volumio[11560]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 18 23:44:33 volumio volumio[11560]: SPOTIFY: SPOTIFY VOLUME undefined Feb 18 23:44:33 volumio volumio[11560]: SPOTIFY: VOLUMIO VOLUME 100 Feb 18 23:44:33 volumio volumio[11560]: info: Aligning Spotify Volume to Volumio Volume Feb 18 23:44:33 volumio volumio[11560]: info: CoreCommandRouter::volumioGetState Feb 18 23:44:33 volumio volumio[11560]: info: CorePlayQueue::getTrack 0 Feb 18 23:44:33 volumio volumio[11560]: info: Setting Spotify Volume from Volumio: 100 Feb 18 23:44:33 volumio go-librespot[11927]: time="2026-02-18T23:44:33+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 18 23:44:33 volumio go-librespot[11927]: time="2026-02-18T23:44:33+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 18 23:44:33 volumio go-librespot[11927]: time="2026-02-18T23:44:33+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 18 23:44:33 volumio go-librespot[11927]: time="2026-02-18T23:44:33+07:00" level=info msg="zeroconf server listening on port 36673" Feb 18 23:44:33 volumio go-librespot[11927]: time="2026-02-18T23:44:33+07:00" level=debug msg="obtained new client token: AACRB73y4GtnDfvPGoUcNhUT+kiO6V8qm35sNmKMTv/suMas4kVeiK5DvU3Ts5m7AWRjzb7VP4TzTumzhwJBlvzIR0sQM5NL2ChU+mREKhcXhkwfANRY9LOV27PX0QkyMOM/Qn0qQK4qQHmOMWDkSAiAIcI1cNhlnl++E2eP1NM4l4Rz0Ohsv8AUPoPc5V6SafHXsIse/SVPZGlfDNAGUYNQE/PgZvFPiEX8APTEkzBzqD7RihD2SoANlQ==" Feb 18 23:44:33 volumio go-librespot[11927]: time="2026-02-18T23:44:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:44:33 volumio go-librespot[11927]: time="2026-02-18T23:44:33+07:00" level=debug msg="completed keyexchange" Feb 18 23:44:33 volumio go-librespot[11927]: time="2026-02-18T23:44:33+07:00" level=debug msg="completed challenge" Feb 18 23:44:33 volumio go-librespot[11927]: time="2026-02-18T23:44:33+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 23:44:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:44:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:44:33 volumio volumio[11560]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 23:44:33 volumio volumio[11560]: Error: socket hang up Feb 18 23:44:33 volumio volumio[11560]: at connResetException (node:internal/errors:720:14) Feb 18 23:44:33 volumio volumio[11560]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 18 23:44:33 volumio volumio[11560]: at Socket.emit (node:events:526:35) Feb 18 23:44:33 volumio volumio[11560]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 18 23:44:33 volumio volumio[11560]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 18 23:44:33 volumio volumio[11560]: code: 'ECONNRESET', Feb 18 23:44:33 volumio volumio[11560]: response: undefined Feb 18 23:44:33 volumio volumio[11560]: } Feb 18 23:44:33 volumio volumio[11560]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 23:44:35 volumio sudo[11956]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 23:43' Feb 18 23:44:35 volumio sudo[11956]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"