Feb 18 17:28:00 volumio volumio[26732]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 17:28:00 volumio volumio[26732]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 17:28:00 volumio volumio[26732]: info: Streaming services startup Feb 18 17:28:00 volumio volumio[26732]: info: Starting Streaming Daemon Feb 18 17:28:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 18 17:28:00 volumio sudo[27114]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 17:28:00 volumio sudo[27114]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:28:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:28:00 volumio volumio[26732]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 17:28:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:28:00 volumio go-librespot[27120]: go-librespot daemon starting... Feb 18 17:28:00 volumio sudo[27114]: pam_unix(sudo:session): session closed for user root Feb 18 17:28:00 volumio go-librespot[27121]: time="2026-02-18T17:28:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 17:28:00 volumio go-librespot[27121]: time="2026-02-18T17:28:00+07:00" level=debug msg="app state loaded" Feb 18 17:28:00 volumio go-librespot[27121]: time="2026-02-18T17:28:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 17:28:00 volumio volumio[26732]: info: Getting Spotify volume Feb 18 17:28:00 volumio volumio[26732]: info: Connection to go-librespot Websocket closed Feb 18 17:28:00 volumio volumio[26732]: error: Cannot start Volumio Streaming Daemon Feb 18 17:28:00 volumio volumio[26732]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 17:28:00 volumio volumio[26732]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 17:28:00 volumio volumio[26732]: 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 17:28:01 volumio volumio[26732]: info: CoreCommandRouter::volumioGetState Feb 18 17:28:01 volumio volumio[26732]: info: CorePlayQueue::getTrack 0 Feb 18 17:28:01 volumio volumio[26732]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 18 17:28:01 volumio volumio[26732]: SPOTIFY: SPOTIFY VOLUME undefined Feb 18 17:28:01 volumio volumio[26732]: SPOTIFY: VOLUMIO VOLUME 100 Feb 18 17:28:01 volumio volumio[26732]: info: Aligning Spotify Volume to Volumio Volume Feb 18 17:28:01 volumio volumio[26732]: info: CoreCommandRouter::volumioGetState Feb 18 17:28:01 volumio volumio[26732]: info: CorePlayQueue::getTrack 0 Feb 18 17:28:01 volumio volumio[26732]: info: Setting Spotify Volume from Volumio: 100 Feb 18 17:28:01 volumio go-librespot[27121]: time="2026-02-18T17:28:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 17:28:01 volumio go-librespot[27121]: time="2026-02-18T17:28:01+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 17:28:01 volumio go-librespot[27121]: time="2026-02-18T17:28:01+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 17:28:01 volumio go-librespot[27121]: time="2026-02-18T17:28:01+07:00" level=info msg="zeroconf server listening on port 40417" Feb 18 17:28:01 volumio go-librespot[27121]: time="2026-02-18T17:28:01+07:00" level=debug msg="obtained new client token: AABfuy3ja6vV9Y+6ZyqQ1x1/67cevrA/F5YkSo9TqSUMScbKG+zkwKptXatO3OL3gFTXFAFgapAwZqlurs4zie8deUM8LLf0fCWb0JDo9iUf2OumJEhnq2LOvw5fJfx/9A+CGTBZuMIq2D/oTrjFTJ7sNGhjdUcaNwYuLeMJIDjejtUY7oQrHfyi3xYtEJTVhGpQ7ln06AoPMiaCYMzx6OrVlMwwmIUxvwP4ZXBSmcqyLTj3ZwREYeBc2A==" Feb 18 17:28:01 volumio go-librespot[27121]: time="2026-02-18T17:28:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 17:28:01 volumio go-librespot[27121]: time="2026-02-18T17:28:01+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 17:28:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 17:28:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 17:28:01 volumio volumio[26732]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 17:28:01 volumio volumio[26732]: Error: socket hang up Feb 18 17:28:01 volumio volumio[26732]: at connResetException (node:internal/errors:720:14) Feb 18 17:28:01 volumio volumio[26732]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 18 17:28:01 volumio volumio[26732]: at Socket.emit (node:events:526:35) Feb 18 17:28:01 volumio volumio[26732]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 18 17:28:01 volumio volumio[26732]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 18 17:28:01 volumio volumio[26732]: code: 'ECONNRESET', Feb 18 17:28:01 volumio volumio[26732]: response: undefined Feb 18 17:28:01 volumio volumio[26732]: } Feb 18 17:28:01 volumio volumio[26732]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 17:28:03 volumio sudo[27142]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 17:27' Feb 18 17:28:03 volumio sudo[27142]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:28:03 volumio sudo[27142]: pam_unix(sudo:session): session closed for user root Feb 18 17:28:03 volumio volumio-remote-updater[25144]: [2026-02-18 17:28:03] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 18 17:28:03 volumio volumio-remote-updater[25144]: [2026-02-18 17:28:03] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 18 17:28:03 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 18 17:28:03 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 18 17:28:03 volumio systemd[1]: volumio.service: Consumed 55.387s CPU time. Feb 18 17:28:03 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 17:28:03 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 17:28:03 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 22215. Feb 18 17:28:03 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 17:28:03 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 18 17:28:03 volumio systemd[1]: volumio.service: Consumed 55.387s CPU time. Feb 18 17:28:03 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 18 17:28:03 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 17:28:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 18 17:28:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:28:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:28:04 volumio go-librespot[27169]: go-librespot daemon starting... Feb 18 17:28:04 volumio go-librespot[27170]: time="2026-02-18T17:28:04+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 17:28:04 volumio go-librespot[27170]: time="2026-02-18T17:28:04+07:00" level=debug msg="app state loaded" Feb 18 17:28:04 volumio go-librespot[27170]: time="2026-02-18T17:28:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 17:28:05 volumio go-librespot[27170]: time="2026-02-18T17:28:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 17:28:05 volumio go-librespot[27170]: time="2026-02-18T17:28:05+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 17:28:05 volumio go-librespot[27170]: time="2026-02-18T17:28:05+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 17:28:05 volumio go-librespot[27170]: time="2026-02-18T17:28:05+07:00" level=info msg="zeroconf server listening on port 33231" Feb 18 17:28:05 volumio go-librespot[27170]: time="2026-02-18T17:28:05+07:00" level=debug msg="obtained new client token: AAB7gqbvMqXma5dZ/V3/18rWr7D14ylG0hHg7muJwxBtnvTvOEkVEQcgrULS8uE0Sb5wds00dQ2n6hoqSTzPoPwGRfmea4Vnzd3EYIv2KOtc89fmHjjbIETSdFIqxCi1nPKKYH4Gv3ZwThB1vcA4QpkJfPYa0bl0S7QVo4sPGsv5+uMMLUglGYgUIChFIdy7+Mz7Ln6LXNoccXZfNqnorSthtNkwC8EsPZbH7nuxTAQpvG+lPchENN099A==" Feb 18 17:28:05 volumio go-librespot[27170]: time="2026-02-18T17:28:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 17:28:05 volumio go-librespot[27170]: time="2026-02-18T17:28:05+07:00" level=debug msg="completed keyexchange" Feb 18 17:28:05 volumio go-librespot[27170]: time="2026-02-18T17:28:05+07:00" level=debug msg="completed challenge" Feb 18 17:28:06 volumio go-librespot[27170]: time="2026-02-18T17:28: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 17:28:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 17:28:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 17:28:07 volumio volumio[27154]: info: ------------------------------------------- Feb 18 17:28:07 volumio volumio[27154]: info: ----- Volumio3 ---- Feb 18 17:28:07 volumio volumio[27154]: info: ------------------------------------------- Feb 18 17:28:07 volumio volumio[27154]: info: ----- System startup ---- Feb 18 17:28:07 volumio volumio[27154]: info: ------------------------------------------- Feb 18 17:28:08 volumio volumio-remote-updater[25144]: [2026-02-18 17:28:08] [connect] Successful connection Feb 18 17:28:08 volumio volumio[27154]: info: MYVOLUMIO Environment detected Feb 18 17:28:08 volumio volumio[27154]: info: Plugin folders cleanup Feb 18 17:28:08 volumio volumio[27154]: info: Scanning into folder /volumio/app/plugins/ Feb 18 17:28:08 volumio volumio[27154]: info: Scanning category audio_interface Feb 18 17:28:08 volumio volumio[27154]: info: Scanning category miscellanea Feb 18 17:28:08 volumio volumio[27154]: info: Scanning category music_service Feb 18 17:28:08 volumio volumio[27154]: info: Scanning category plugins.json Feb 18 17:28:08 volumio volumio[27154]: info: Scanning category system_controller Feb 18 17:28:08 volumio volumio[27154]: info: Scanning category user_interface Feb 18 17:28:09 volumio volumio[27154]: info: Scanning into folder /data/plugins/ Feb 18 17:28:09 volumio volumio[27154]: info: Scanning category music_service Feb 18 17:28:09 volumio volumio[27154]: info: Plugin folders cleanup completed Feb 18 17:28:09 volumio volumio[27154]: info: ------------------------------------------- Feb 18 17:28:09 volumio volumio[27154]: info: ----- Core plugins startup ---- Feb 18 17:28:09 volumio volumio[27154]: info: ------------------------------------------- Feb 18 17:28:09 volumio volumio[27154]: info: Loading plugins from folder /volumio/app/plugins/ Feb 18 17:28:09 volumio volumio[27154]: info: Adding plugin upnp to MyMusic Plugins Feb 18 17:28:09 volumio volumio[27154]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 18 17:28:09 volumio volumio[27154]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 18 17:28:09 volumio volumio[27154]: info: Loading plugins from folder /data/plugins/ Feb 18 17:28:09 volumio volumio[27154]: info: Loading plugin "system"... Feb 18 17:28:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 18 17:28:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:28:09 volumio volumio[27154]: info: Loading plugin "appearance"... Feb 18 17:28:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:28:09 volumio go-librespot[27187]: go-librespot daemon starting... Feb 18 17:28:09 volumio go-librespot[27191]: time="2026-02-18T17:28:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 17:28:09 volumio go-librespot[27191]: time="2026-02-18T17:28:09+07:00" level=debug msg="app state loaded" Feb 18 17:28:09 volumio go-librespot[27191]: time="2026-02-18T17:28:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 17:28:09 volumio go-librespot[27191]: time="2026-02-18T17:28: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 17:28:09 volumio go-librespot[27191]: time="2026-02-18T17:28: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 17:28:09 volumio go-librespot[27191]: time="2026-02-18T17:28: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 17:28:09 volumio go-librespot[27191]: time="2026-02-18T17:28:09+07:00" level=info msg="zeroconf server listening on port 37461" Feb 18 17:28:09 volumio go-librespot[27191]: time="2026-02-18T17:28:09+07:00" level=debug msg="obtained new client token: AADkSiWjk8QXa8CN3dNRew2IXkxltw4mcbUuMY04e4fgR2JzJZtjE3lf4G8XUYZqUdcrCWYv77dRw85qTS89cMK6+hL4N/B9+rD33KqNsSpG8MItZrMqRciOGFPa8s56cRLCBRUbvhplsjwFO8grFkgBwR/xqLFYlKU6Q3z98EB/AVTLxRly76ASM1nqjN0ZFWxOIv3G31hQKVrd7AO5Jbn5YCP3LrLD2wQm+aSrevbANmzh6B3CLRua+g==" Feb 18 17:28:10 volumio go-librespot[27191]: time="2026-02-18T17:28:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 17:28:10 volumio go-librespot[27191]: time="2026-02-18T17:28: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 17:28:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 17:28:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 17:28:11 volumio volumio[27154]: info: Loading plugin "network"... Feb 18 17:28:11 volumio volumio[27154]: info: Refreshing Cached IP Addresses Feb 18 17:28:11 volumio sudo[27199]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 17:28:11 volumio sudo[27199]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:28:11 volumio sudo[27201]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 17:28:11 volumio sudo[27199]: pam_unix(sudo:session): session closed for user root Feb 18 17:28:11 volumio sudo[27201]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:28:11 volumio volumio[27154]: info: Loading plugin "services"... Feb 18 17:28:11 volumio volumio[27154]: info: Loading plugin "alsa_controller"... Feb 18 17:28:11 volumio sudo[27201]: pam_unix(sudo:session): session closed for user root Feb 18 17:28:11 volumio sudo[27209]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 18 17:28:11 volumio sudo[27209]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:28:11 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 17:28:11 volumio volumio[27154]: info: Loading plugin "wizard"... Feb 18 17:28:11 volumio volumio[27154]: info: Loading plugin "networkfs"... Feb 18 17:28:11 volumio volumio[27154]: info: Starting Udev Watcher for removable devices Feb 18 17:28:11 volumio volumio[27154]: info: Ignoring mount for partition: boot Feb 18 17:28:11 volumio volumio[27154]: info: Ignoring mount for partition: volumio Feb 18 17:28:11 volumio volumio[27154]: info: Ignoring mount for partition: volumio_data Feb 18 17:28:11 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 17:28:11 volumio volumio[27154]: info: Loading plugin "volumio_command_line_client"... Feb 18 17:28:11 volumio volumio[27154]: info: Loading plugin "upnp"... Feb 18 17:28:11 volumio volumio[27154]: info: [1771410491445] Starting Upmpd Daemon Feb 18 17:28:11 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 17:28:11 volumio volumio[27154]: info: Loading plugin "my_music"... Feb 18 17:28:11 volumio volumio[27154]: info: Loading plugin "mpd"... Feb 18 17:28:12 volumio volumio[27154]: info: Loading plugin "upnp_browser"... Feb 18 17:28:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 18 17:28:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:28:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:28:13 volumio go-librespot[27232]: go-librespot daemon starting... Feb 18 17:28:13 volumio go-librespot[27233]: time="2026-02-18T17:28:13+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 17:28:13 volumio go-librespot[27233]: time="2026-02-18T17:28:13+07:00" level=debug msg="app state loaded" Feb 18 17:28:13 volumio go-librespot[27233]: time="2026-02-18T17:28:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 17:28:13 volumio go-librespot[27233]: time="2026-02-18T17:28:13+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 17:28:13 volumio go-librespot[27233]: time="2026-02-18T17:28:13+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 17:28:13 volumio go-librespot[27233]: time="2026-02-18T17:28:13+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 17:28:13 volumio go-librespot[27233]: time="2026-02-18T17:28:13+07:00" level=info msg="zeroconf server listening on port 38093" Feb 18 17:28:14 volumio sudo[27209]: pam_unix(sudo:session): session closed for user root Feb 18 17:28:14 volumio go-librespot[27233]: time="2026-02-18T17:28:14+07:00" level=debug msg="obtained new client token: AACxYC/7VctKFLlXuLi/VptYDSjx11XiWpX3iEcgrwPAMOh8vdDGptvy1/bZu+kLnLFSvSylhbFN8bm8b53IV3/CUN4HG7wRlRw89L2Iw46BtAuMnaPx9hbCpPilWE7ehrqSCSEf1xD1pBp/308bD+6+pm+IKMXN3xvuMc2EgCmIgdlOV3ETvrpE+SrkGtCbBGgDK+QuPMngjMFFxfpCm9NEltGIt25QdBRKCvXImDfXyHeAw+ogP34=" Feb 18 17:28:14 volumio go-librespot[27233]: time="2026-02-18T17:28:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 17:28:14 volumio go-librespot[27233]: time="2026-02-18T17:28:14+07:00" level=debug msg="completed keyexchange" Feb 18 17:28:14 volumio go-librespot[27233]: time="2026-02-18T17:28:14+07:00" level=debug msg="completed challenge" Feb 18 17:28:14 volumio go-librespot[27233]: time="2026-02-18T17:28:14+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 17:28:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 17:28:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 17:28:15 volumio volumio[27154]: info: Starting UPNP Browser Feb 18 17:28:15 volumio volumio[27154]: info: Loading plugin "alarm-clock"... Feb 18 17:28:15 volumio volumio[27154]: info: Loading plugin "airplay_emulation"... Feb 18 17:28:15 volumio volumio[27154]: info: Starting Shairport Sync Feb 18 17:28:15 volumio volumio[27154]: info: Loading plugin "last_100"... Feb 18 17:28:15 volumio volumio[27154]: info: Loading plugin "webradio"... Feb 18 17:28:15 volumio volumio[27154]: info: Loading plugin "i2s_dacs"... Feb 18 17:28:15 volumio volumio[27154]: info: Loading plugin "volumiodiscovery"... Feb 18 17:28:15 volumio volumio[27154]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 17:28:15 volumio volumio[27154]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 17:28:15 volumio node[27154]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 17:28:15 volumio volumio[27154]: *** WARNING *** For more information see Feb 18 17:28:15 volumio volumio[27154]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 17:28:15 volumio volumio[27154]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 17:28:15 volumio volumio[27154]: *** WARNING *** For more information see Feb 18 17:28:15 volumio node[27154]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 17:28:15 volumio node[27154]: *** WARNING *** For more information see Feb 18 17:28:15 volumio node[27154]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 17:28:15 volumio node[27154]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 17:28:15 volumio node[27154]: *** WARNING *** For more information see Feb 18 17:28:15 volumio volumio[27154]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 18 17:28:15 volumio volumio[27154]: info: Discovery: Started advertising with name: Volumio Feb 18 17:28:15 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 17:28:15 volumio volumio[27154]: info: Loading plugin "spop"... Feb 18 17:28:17 volumio volumio[27154]: info: Loading plugin "ytcr"... Feb 18 17:28:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 18 17:28:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:28:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:28:17 volumio go-librespot[27242]: go-librespot daemon starting... Feb 18 17:28:17 volumio go-librespot[27243]: time="2026-02-18T17:28:17+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 17:28:17 volumio go-librespot[27243]: time="2026-02-18T17:28:17+07:00" level=debug msg="app state loaded" Feb 18 17:28:17 volumio go-librespot[27243]: time="2026-02-18T17:28:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 17:28:18 volumio go-librespot[27243]: time="2026-02-18T17:28: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 17:28:18 volumio go-librespot[27243]: time="2026-02-18T17:28: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 17:28:18 volumio go-librespot[27243]: time="2026-02-18T17:28: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 17:28:18 volumio go-librespot[27243]: time="2026-02-18T17:28:18+07:00" level=info msg="zeroconf server listening on port 39663" Feb 18 17:28:18 volumio go-librespot[27243]: time="2026-02-18T17:28:18+07:00" level=debug msg="obtained new client token: AADLGyO+YeQmNu+ggeiePMY02j3/j38K6uCvDA1F4/7fQe/lVd79dTpArnodn+MSTLfW9BKcAO9u5H22PUc/vvmzozuyiWmyt4bx9GBDv9swZsCZRVhQCY5WZMoDVj+F5kzq5MAHR5H97HXEZel3j/nYLZWS38f0WGOVKh2NCJDbIIJ0qrrHRrq+AQhu4qrGJqFtEuDMASMCr5WBRmMh3IGjOY+KLBnH5WmLyBZgFw+DMbvMQZw1nJzaBQ==" Feb 18 17:28:18 volumio go-librespot[27243]: time="2026-02-18T17:28:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 17:28:18 volumio go-librespot[27243]: time="2026-02-18T17:28:18+07:00" level=debug msg="completed keyexchange" Feb 18 17:28:18 volumio go-librespot[27243]: time="2026-02-18T17:28:18+07:00" level=debug msg="completed challenge" Feb 18 17:28:18 volumio go-librespot[27243]: time="2026-02-18T17:28: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 17:28:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 17:28:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 17:28:20 volumio volumio[27154]: info: Loading plugin "ytmusic"... Feb 18 17:28:20 volumio volumio-remote-updater[25144]: [2026-02-18 17:28:20] [connect] Successful connection Feb 18 17:28:21 volumio volumio[27154]: info: Loading plugin "outputs"... Feb 18 17:28:21 volumio volumio[27154]: info: Loading plugin "albumart"... Feb 18 17:28:21 volumio volumio[27154]: info: Plugin example_plugin is not enabled Feb 18 17:28:21 volumio volumio[27154]: info: Loading plugin "inputs"... Feb 18 17:28:21 volumio volumio[27154]: info: Loading plugin "updater_comm"... Feb 18 17:28:21 volumio volumio[27154]: info: Plugin mpdemulation is not enabled Feb 18 17:28:21 volumio volumio[27154]: info: Loading plugin "rest_api"... Feb 18 17:28:21 volumio volumio[27154]: info: Loading plugin "websocket"... Feb 18 17:28:21 volumio volumio[27154]: info: Starting Socket.io Server version 1.7.4 Feb 18 17:28:21 volumio volumio[27154]: info: Loading plugin "RoonBridge"... Feb 18 17:28:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 18 17:28:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:28:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:28:21 volumio go-librespot[27275]: go-librespot daemon starting... Feb 18 17:28:21 volumio go-librespot[27276]: time="2026-02-18T17:28:21+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 17:28:21 volumio go-librespot[27276]: time="2026-02-18T17:28:21+07:00" level=debug msg="app state loaded" Feb 18 17:28:21 volumio go-librespot[27276]: time="2026-02-18T17:28:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 17:28:22 volumio volumio[27154]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 17:28:22 volumio volumio[27154]: info: Loading i18n strings for locale en Feb 18 17:28:22 volumio volumio[27154]: Updating browse sources language Feb 18 17:28:22 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 17:28:22 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 17:28:22 volumio volumio[27154]: info: CoreCommandRouter::initPlayerControls Feb 18 17:28:22 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:28:22 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:28:22 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:28:22 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:28:22 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:28:22 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:28:22 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:28:22 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:28:22 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 17:28:22 volumio volumio[27154]: Express server listening on port 3000 Feb 18 17:28:22 volumio volumio[27154]: [Metrics] WebUI: 15s 908.56ms Feb 18 17:28:22 volumio volumio[27265]: Forking 3 albumart workers Feb 18 17:28:22 volumio volumio[27154]: info: CoreStateMachine::resetVolumioState Feb 18 17:28:22 volumio volumio[27154]: info: CoreStateMachine::getcurrentVolume Feb 18 17:28:22 volumio volumio[27154]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 17:28:22 volumio go-librespot[27276]: time="2026-02-18T17:28: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 17:28:22 volumio go-librespot[27276]: time="2026-02-18T17:28: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 17:28:22 volumio go-librespot[27276]: time="2026-02-18T17:28: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 17:28:22 volumio go-librespot[27276]: time="2026-02-18T17:28:22+07:00" level=info msg="zeroconf server listening on port 37967" Feb 18 17:28:22 volumio sudo[27292]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 17:28:22 volumio sudo[27292]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:28:22 volumio sudo[27292]: pam_unix(sudo:session): session closed for user root Feb 18 17:28:22 volumio sudo[27294]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 17:28:22 volumio sudo[27294]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:28:22 volumio sudo[27294]: pam_unix(sudo:session): session closed for user root Feb 18 17:28:22 volumio volumio[27154]: info: Volumio Network Manager: Network status updated: 1 Feb 18 17:28:22 volumio go-librespot[27276]: time="2026-02-18T17:28:22+07:00" level=debug msg="obtained new client token: AABZwBj7ETIReK3BgRDp6hNPdGPKKlmDu2jIUlZw9LkPVPj0zm0QHuGwBlvyOqp8i3RJWomVDBcWQzx7PXH6A9t+GO1iGfjC9uq6s46tkL1vr6SXNinw/2S3CPBiqKLoxkBBqvw8qNXtTp+/OTtUga7vorxcFKAmHWdtj9DnSiQ25aCMJVM2BNSdQQXHZ09YTIYIv40K7ZuuQ/c3I/0hR/XQURt5wvs+aq8TikY7A058qccV4jxl9uBmxg==" Feb 18 17:28:22 volumio go-librespot[27276]: time="2026-02-18T17:28:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 17:28:23 volumio go-librespot[27276]: time="2026-02-18T17:28: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 17:28:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 17:28:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 17:28:23 volumio volumio[27154]: info: VolumeController:: Volume=100 Mute =false Feb 18 17:28:23 volumio volumio[27154]: info: CoreStateMachine::pushState Feb 18 17:28:23 volumio volumio[27154]: info: CorePlayQueue::getTrack 0 Feb 18 17:28:23 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 17:28:23 volumio volumio[27154]: info: CoreCommandRouter::volumioPushState Feb 18 17:28:23 volumio volumio[27154]: info: CoreStateMachine::updateTrackBlock Feb 18 17:28:23 volumio volumio[27154]: info: CorePlayQueue::getTrackBlock Feb 18 17:28:23 volumio volumio[27154]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 17:28:23 volumio volumio-remote-updater[25144]: [2026-02-18 17:28:23] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771410500 101 Feb 18 17:28:23 volumio volumio[27154]: 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 17:28:23 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 17:28:23 volumio volumio[27154]: info: Reloading queue from file Feb 18 17:28:23 volumio volumio[27154]: info: CoreStateMachine::setRepeat null single undefined Feb 18 17:28:23 volumio volumio[27154]: info: CoreStateMachine::pushState Feb 18 17:28:23 volumio volumio[27154]: info: CorePlayQueue::getTrack 0 Feb 18 17:28:23 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 17:28:23 volumio volumio[27154]: info: CoreCommandRouter::volumioPushState Feb 18 17:28:23 volumio volumio[27154]: info: CoreStateMachine::setRandom null Feb 18 17:28:23 volumio volumio[27154]: info: CoreStateMachine::pushState Feb 18 17:28:23 volumio volumio[27154]: info: CorePlayQueue::getTrack 0 Feb 18 17:28:23 volumio volumio[27154]: info: CoreCommandRouter::volumioPushState Feb 18 17:28:23 volumio volumio[27154]: info: Setting Device type: Raspberry PI Feb 18 17:28:23 volumio volumio[27154]: info: Completed loading Core Plugins Feb 18 17:28:23 volumio volumio[27154]: info: Preparing to generate the ALSA configuration file Feb 18 17:28:23 volumio volumio[27154]: info: VolumeController:: Volume=100 Mute =false Feb 18 17:28:23 volumio volumio[27154]: info: CoreStateMachine::pushState Feb 18 17:28:23 volumio volumio[27154]: info: CorePlayQueue::getTrack 0 Feb 18 17:28:23 volumio volumio[27154]: info: CoreCommandRouter::volumioPushState Feb 18 17:28:23 volumio volumio[27154]: info: Asound.conf file unchanged, so no further update is needed Feb 18 17:28:23 volumio volumio[27154]: info: Output device has changed, restarting MPD Feb 18 17:28:23 volumio sudo[27334]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 17:28:23 volumio volumio[27154]: info: Output device has changed, restarting Shairport Sync Feb 18 17:28:23 volumio sudo[27334]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:28:23 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:28:23 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 17:28:23 volumio sudo[27336]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 17:28:23 volumio sudo[27336]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:28:23 volumio volumio[27154]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 17:28:23 volumio volumio[27154]: info: ___________ START PLUGINS ___________ Feb 18 17:28:23 volumio sudo[27338]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 17:28:23 volumio sudo[27338]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:28:23 volumio sudo[27334]: pam_unix(sudo:session): session closed for user root Feb 18 17:28:23 volumio volumio[27154]: info: ControllerMpd::onStart: Initializing MPD Feb 18 17:28:23 volumio volumio[27154]: info: Creating MPD Configuration file Feb 18 17:28:23 volumio sudo[27336]: pam_unix(sudo:session): session closed for user root Feb 18 17:28:23 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 17:28:23 volumio volumio[27154]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 17:28:23 volumio volumio[27154]: info: [1771410503843] CoreMusicLibrary::Adding element Media Servers Feb 18 17:28:23 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 17:28:23 volumio volumio[27154]: info: UPNP Browser: Client initialized successfully Feb 18 17:28:23 volumio sudo[27347]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 17:28:23 volumio sudo[27347]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:28:23 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 17:28:23 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:28:23 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 17:28:23 volumio sudo[27347]: pam_unix(sudo:session): session closed for user root Feb 18 17:28:23 volumio sudo[27349]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 17:28:23 volumio sudo[27349]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:28:24 volumio volumio[27154]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 17:28:24 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 17:28:24 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:28:24 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 17:28:24 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 17:28:24 volumio systemd[1]: mpd.service: Consumed 7.168s CPU time. Feb 18 17:28:24 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 17:28:24 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 17:28:24 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 17:28:24 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 17:28:24 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 17:28:24 volumio volumio[27154]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 17:28:24 volumio volumio[27154]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 17:28:24 volumio volumio[27154]: info: [1771410504182] CoreMusicLibrary::Adding element Last_100 Feb 18 17:28:24 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 17:28:24 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 17:28:24 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 17:28:24 volumio volumio[27154]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 17:28:24 volumio volumio[27154]: info: [1771410504236] CoreMusicLibrary::Adding element Webradio Feb 18 17:28:24 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 17:28:24 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 17:28:24 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 17:28:24 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 17:28:24 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 17:28:24 volumio volumio[27154]: info: Initializing BBC Radios Feb 18 17:28:24 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 17:28:24 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 17:28:24 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 17:28:24 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 17:28:24 volumio volumio[27154]: info: Creating Spotify config file Feb 18 17:28:24 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:28:24 volumio sudo[27371]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 17:28:24 volumio sudo[27371]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 17:28:24 volumio sudo[27371]: pam_unix(sudo:session): session closed for user root Feb 18 17:28:25 volumio volumio[27154]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 17:28:25 volumio volumio[27154]: info: [1771410505557] CoreMusicLibrary::Adding element YouTube Music Feb 18 17:28:25 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 17:28:25 volumio volumio[27154]: Cannot find translation for source YouTube Music Feb 18 17:28:25 volumio volumio[27154]: info: Volumio Calling Home Feb 18 17:28:25 volumio sudo[27380]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 17:28:25 volumio sudo[27380]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:28:25 volumio sudo[27380]: pam_unix(sudo:session): session closed for user root Feb 18 17:28:25 volumio volumio[27287]: Starting albumart workers Feb 18 17:28:26 volumio volumio[27290]: Starting albumart workers Feb 18 17:28:26 volumio volumio[27289]: Starting albumart workers Feb 18 17:28:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 18 17:28:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:28:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:28:26 volumio go-librespot[27385]: go-librespot daemon starting... Feb 18 17:28:26 volumio go-librespot[27386]: time="2026-02-18T17:28:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 17:28:26 volumio volumio[27154]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 17:28:26 volumio volumio[27154]: info: Discovery: Found device Volumio Feb 18 17:28:26 volumio volumio[27154]: info: CoreCommandRouter::volumioGetState Feb 18 17:28:26 volumio volumio[27154]: info: CorePlayQueue::getTrack 0 Feb 18 17:28:26 volumio go-librespot[27386]: time="2026-02-18T17:28:26+07:00" level=info msg="zeroconf server listening on port 35901" Feb 18 17:28:26 volumio volumio[27154]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 17:28:26 volumio volumio[27154]: info: Discovery: Found device Volumio Feb 18 17:28:26 volumio volumio[27154]: info: CoreCommandRouter::volumioGetState Feb 18 17:28:26 volumio volumio[27154]: info: CorePlayQueue::getTrack 0 Feb 18 17:28:26 volumio volumio[27154]: info: MPD Permissions set Feb 18 17:28:26 volumio volumio[27154]: info: MPD Permissions set Feb 18 17:28:26 volumio volumio[27154]: info: Upmpdcli Daemon Started Feb 18 17:28:27 volumio volumio[27154]: info: Volumio called home Feb 18 17:28:27 volumio volumio[27154]: info: Spotify config file written Feb 18 17:28:27 volumio sudo[27394]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 17:28:27 volumio sudo[27394]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:28:27 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 18 17:28:27 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 18 17:28:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:28:27 volumio go-librespot[27396]: go-librespot daemon starting... Feb 18 17:28:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:28:27 volumio sudo[27394]: pam_unix(sudo:session): session closed for user root Feb 18 17:28:27 volumio go-librespot[27397]: time="2026-02-18T17:28:27+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 17:28:27 volumio go-librespot[27397]: time="2026-02-18T17:28:27+07:00" level=debug msg="app state loaded" Feb 18 17:28:27 volumio go-librespot[27397]: time="2026-02-18T17:28:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 17:28:28 volumio volumio[27154]: 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 17:28:28 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:28:28 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:28:28 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:28:28 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:28:28 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:28:28 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:28:28 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:28:28 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:28:28 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 17:28:28 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:28:28 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:28:28 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:28:28 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:28:28 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:28:28 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:28:28 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:28:28 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:28:28 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:28:28 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 17:28:28 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:28:28 volumio volumio[27154]: info: No need to fix Spotify hosts Feb 18 17:28:28 volumio go-librespot[27397]: time="2026-02-18T17:28: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 17:28:28 volumio go-librespot[27397]: time="2026-02-18T17:28:28+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 17:28:28 volumio go-librespot[27397]: time="2026-02-18T17:28:28+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 17:28:28 volumio go-librespot[27397]: time="2026-02-18T17:28:28+07:00" level=info msg="zeroconf server listening on port 35255" Feb 18 17:28:28 volumio go-librespot[27397]: time="2026-02-18T17:28:28+07:00" level=debug msg="obtained new client token: AACDMNRcDN31QkDLetjmmiZz5uYS989iM+85mJmv6fWhyGB3Lf+DBGXLdFUiyNOr2mB6mueuIpTlRbeGi7+2KKpigJ7ssQK5MPZibZb2GxC7SZcuUEU1ItC7pCBdQASA5Mk/H11MIQQkB50Z5+PFcvb3bKC9gFmuMDEjL8YZYWch5BBKrM4OGJrK6RgW+facLC5VUGIJEh0L3yNvlgCLs9SRfDqlzisEgs7S07kp90Z5/rYglOmM5lHFNg==" Feb 18 17:28:28 volumio go-librespot[27397]: time="2026-02-18T17:28:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 17:28:28 volumio go-librespot[27397]: time="2026-02-18T17:28: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 17:28:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 17:28:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 17:28:28 volumio volumio[27154]: info: Starting Shairport Sync Feb 18 17:28:28 volumio volumio[27154]: info: Starting Shairport Sync Feb 18 17:28:28 volumio volumio[27154]: info: Starting Shairport Sync Feb 18 17:28:29 volumio sudo[27434]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 17:28:29 volumio sudo[27434]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:28:29 volumio sudo[27438]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 17:28:29 volumio sudo[27436]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 17:28:29 volumio sudo[27436]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:28:29 volumio sudo[27438]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:28:29 volumio volumio[27154]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 17:28:29 volumio volumio[27154]: SPOTIFY: BQBEMyUX9reFuvbL5TUqeux9x5vTPUbewl84eci-I2glstciSD6Uc-8cmza6zR3Cuh8wWKK5Hz4-764C9el8ZdvYISIYj-vPloM0vEOYutwsveoR6UXAg4N4QBUD0HAkxsVxDsCz66FkePCyJmnEGo2Ss3ieppdE6PTC9GnI7GeRhoU2foL-6Y2x_M5Ni2_lZWXY_Wo2z7IRib3F-mptYXoYAwRukFLQX_egvM3dKK6qXN8zYhg-ir4vQWQWEBjeWIbaBU482XaljY2wY7XuldARY4KGyYJXne4vaaJQQDlt4b6jmK3zj8b_ Feb 18 17:28:29 volumio volumio[27154]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 17:28:29 volumio volumio[27154]: info: New Spotify access token = BQBEMyUX9reFuvbL5TUqeux9x5vTPUbewl84eci-I2glstciSD6Uc-8cmza6zR3Cuh8wWKK5Hz4-764C9el8ZdvYISIYj-vPloM0vEOYutwsveoR6UXAg4N4QBUD0HAkxsVxDsCz66FkePCyJmnEGo2Ss3ieppdE6PTC9GnI7GeRhoU2foL-6Y2x_M5Ni2_lZWXY_Wo2z7IRib3F-mptYXoYAwRukFLQX_egvM3dKK6qXN8zYhg-ir4vQWQWEBjeWIbaBU482XaljY2wY7XuldARY4KGyYJXne4vaaJQQDlt4b6jmK3zj8b_ Feb 18 17:28:29 volumio volumio[27154]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 17:28:29 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 17:28:29 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 17:28:29 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 17:28:29 volumio systemd[1]: shairport-sync.service: Consumed 2.279s CPU time. Feb 18 17:28:29 volumio volumio[27154]: info: CoreCommandRouter::volumioGetState Feb 18 17:28:29 volumio volumio[27154]: info: CorePlayQueue::getTrack 0 Feb 18 17:28:29 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 17:28:29 volumio sudo[27434]: pam_unix(sudo:session): session closed for user root Feb 18 17:28:29 volumio sudo[27436]: pam_unix(sudo:session): session closed for user root Feb 18 17:28:29 volumio sudo[27438]: pam_unix(sudo:session): session closed for user root Feb 18 17:28:29 volumio volumio[27154]: info: Shairport-Sync Started Feb 18 17:28:29 volumio volumio[27154]: Error adding Membership: Error: addMembership EINVAL Feb 18 17:28:29 volumio volumio[27154]: info: Shairport-Sync Started Feb 18 17:28:29 volumio volumio[27154]: info: Shairport-Sync Started Feb 18 17:28:29 volumio volumio[27154]: 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 17:28:29 volumio volumio[27154]: info: Spotify Successfully logged in Feb 18 17:28:29 volumio volumio[27154]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 17:28:29 volumio volumio[27154]: info: [1771410509720] CoreMusicLibrary::Adding element Spotify Feb 18 17:28:29 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 17:28:29 volumio volumio[27154]: Cannot find translation for source YouTube Music Feb 18 17:28:29 volumio volumio[27154]: Cannot find translation for source Spotify Feb 18 17:28:30 volumio volumio[27154]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 17:28:30 volumio volumio[27154]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 17:28:30 volumio volumio[27154]: info: VolumeController:: Volume=100 Mute =false Feb 18 17:28:30 volumio volumio[27154]: info: CoreCommandRouter::volumioGetState Feb 18 17:28:30 volumio volumio[27154]: info: CorePlayQueue::getTrack 0 Feb 18 17:28:30 volumio volumio[27154]: info: CoreStateMachine::pushState Feb 18 17:28:30 volumio volumio[27154]: info: CorePlayQueue::getTrack 0 Feb 18 17:28:30 volumio volumio[27154]: info: CoreCommandRouter::volumioPushState Feb 18 17:28:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 18 17:28:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:28:31 volumio mpd[27378]: 2026-02-18T17:28:31 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 17:28:31 volumio volumio[27154]: info: go-librespot daemon successfully initialized Feb 18 17:28:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:28:31 volumio go-librespot[27476]: go-librespot daemon starting... Feb 18 17:28:31 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 17:28:31 volumio sudo[27338]: pam_unix(sudo:session): session closed for user root Feb 18 17:28:31 volumio sudo[27349]: pam_unix(sudo:session): session closed for user root Feb 18 17:28:31 volumio go-librespot[27479]: time="2026-02-18T17:28:31+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 17:28:31 volumio go-librespot[27479]: time="2026-02-18T17:28:31+07:00" level=debug msg="app state loaded" Feb 18 17:28:31 volumio go-librespot[27479]: time="2026-02-18T17:28:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 17:28:32 volumio volumio[27154]: error: MPD error: The expression evaluated to a falsy value: Feb 18 17:28:32 volumio volumio[27154]: assert.ok(self.idling) Feb 18 17:28:32 volumio volumio[27154]: error: The expression evaluated to a falsy value: Feb 18 17:28:32 volumio volumio[27154]: assert.ok(self.idling) Feb 18 17:28:32 volumio volumio[27154]: info: Completed starting Core Plugins Feb 18 17:28:32 volumio volumio[27154]: info: ------------------------------------------- Feb 18 17:28:32 volumio volumio[27154]: info: ----- MyVolumio plugins startup ---- Feb 18 17:28:32 volumio volumio[27154]: info: ------------------------------------------- Feb 18 17:28:32 volumio volumio[27154]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 17:28:32 volumio volumio[27154]: error: updateQueue error: null Feb 18 17:28:32 volumio volumio[27154]: info: MPD running with PID27378 Feb 18 17:28:32 volumio volumio[27154]: ,establishing connection Feb 18 17:28:32 volumio volumio[27154]: error: updateQueue error: null Feb 18 17:28:32 volumio go-librespot[27479]: time="2026-02-18T17:28: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 17:28:32 volumio go-librespot[27479]: time="2026-02-18T17:28: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 17:28:32 volumio go-librespot[27479]: time="2026-02-18T17:28: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 17:28:32 volumio go-librespot[27479]: time="2026-02-18T17:28:32+07:00" level=info msg="zeroconf server listening on port 43171" Feb 18 17:28:32 volumio go-librespot[27479]: time="2026-02-18T17:28:32+07:00" level=debug msg="obtained new client token: AAAP62DNsi9RtSQN6eYH76oFTyDbS16qbiOF5HnwkAHd3SuJXt9cFrJHMtYyOzGF/7zvRvOQqPOsQK2H1ipI9bw88NK//xF7CgRxiVD8TwewOahK7itqDnXuYadepiwHMvZnxsH5+bd3dYSc1dSaPdPSwOaqlzM5Vd5ZBA1wu58V8AwmMf7hoW9YCPNnTIMQlZt8/JR/nDVMFsJmXt0YZjdcH8JBFGG+d5DuTjniV6sCmYdCuTU4xb25gw==" Feb 18 17:28:32 volumio go-librespot[27479]: time="2026-02-18T17:28:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 17:28:32 volumio go-librespot[27479]: time="2026-02-18T17:28:32+07:00" level=debug msg="completed keyexchange" Feb 18 17:28:32 volumio go-librespot[27479]: time="2026-02-18T17:28:32+07:00" level=debug msg="completed challenge" Feb 18 17:28:32 volumio go-librespot[27479]: time="2026-02-18T17:28:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 17:28:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 17:28:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 17:28:34 volumio volumio[27154]: info: Initializing connection to go-librespot Websocket Feb 18 17:28:34 volumio volumio[27154]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 17:28:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 18 17:28:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:28:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:28:36 volumio go-librespot[27488]: go-librespot daemon starting... Feb 18 17:28:36 volumio go-librespot[27489]: time="2026-02-18T17:28:36+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 17:28:36 volumio go-librespot[27489]: time="2026-02-18T17:28:36+07:00" level=debug msg="app state loaded" Feb 18 17:28:36 volumio go-librespot[27489]: time="2026-02-18T17:28:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 17:28:36 volumio go-librespot[27489]: time="2026-02-18T17:28: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 17:28:36 volumio go-librespot[27489]: time="2026-02-18T17:28:36+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 17:28:36 volumio go-librespot[27489]: time="2026-02-18T17:28:36+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 17:28:36 volumio go-librespot[27489]: time="2026-02-18T17:28:36+07:00" level=info msg="zeroconf server listening on port 44393" Feb 18 17:28:36 volumio go-librespot[27489]: time="2026-02-18T17:28:36+07:00" level=debug msg="obtained new client token: AAAP7S5Lmg9T4b3wdAeuSAeGtPumXpVUnLyIlXg4DU3pROy33Xm7OTAPOJN2ByhNo66Zns6IXH75PH44o4deDjwbRGfMdWfmCsX0EdefQ33aJy3wvPsMIksnuzbmIWi+zbUTfc/oXMc1HqAM9aYqmwUvXEn21zYAmeW39BMai4iubytdNCicf7TNgQWg4gsaaePrDvoMwULa2+N54qMDKZ+Bw78LmveSZMhlUm7HjH/WCE4ikptuUDqc7Q==" Feb 18 17:28:36 volumio volumio[27154]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 17:28:37 volumio go-librespot[27489]: time="2026-02-18T17:28:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 17:28:37 volumio go-librespot[27489]: time="2026-02-18T17:28:37+07:00" level=debug msg="completed keyexchange" Feb 18 17:28:37 volumio go-librespot[27489]: time="2026-02-18T17:28:37+07:00" level=debug msg="completed challenge" Feb 18 17:28:37 volumio go-librespot[27489]: time="2026-02-18T17:28: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 17:28:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 17:28:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 17:28:37 volumio volumio[27154]: info: Initializing connection to go-librespot Websocket Feb 18 17:28:37 volumio volumio[27154]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 17:28:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 18 17:28:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:28:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:28:40 volumio go-librespot[27496]: go-librespot daemon starting... Feb 18 17:28:40 volumio go-librespot[27498]: time="2026-02-18T17:28:40+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 17:28:40 volumio go-librespot[27498]: time="2026-02-18T17:28:40+07:00" level=debug msg="app state loaded" Feb 18 17:28:40 volumio go-librespot[27498]: time="2026-02-18T17:28:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 17:28:40 volumio volumio[27154]: info: Initializing connection to go-librespot Websocket Feb 18 17:28:40 volumio go-librespot[27498]: time="2026-02-18T17:28:40+07:00" level=debug msg="new websocket client" Feb 18 17:28:40 volumio go-librespot[27498]: time="2026-02-18T17:28: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 17:28:40 volumio go-librespot[27498]: time="2026-02-18T17:28:40+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 17:28:40 volumio go-librespot[27498]: time="2026-02-18T17:28:40+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 17:28:40 volumio volumio[27154]: info: Connection to go-librespot Websocket established Feb 18 17:28:40 volumio go-librespot[27498]: time="2026-02-18T17:28:40+07:00" level=info msg="zeroconf server listening on port 46565" Feb 18 17:28:40 volumio volumio[27154]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 17:28:40 volumio volumio[27154]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 17:28:40 volumio volumio[27154]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 17:28:40 volumio volumio[27154]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 17:28:40 volumio volumio[27154]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 17:28:40 volumio volumio[27154]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 17:28:40 volumio volumio[27154]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 17:28:40 volumio volumio[27154]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 17:28:40 volumio volumio[27154]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 17:28:40 volumio volumio[27154]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 17:28:40 volumio volumio[27154]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 17:28:40 volumio volumio[27154]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 17:28:40 volumio volumio[27154]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 17:28:40 volumio volumio[27154]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 17:28:40 volumio volumio[27154]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 17:28:40 volumio volumio[27154]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 17:28:40 volumio volumio[27154]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 17:28:40 volumio volumio[27154]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 17:28:40 volumio volumio[27154]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 17:28:40 volumio volumio[27154]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 17:28:40 volumio volumio[27154]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 17:28:40 volumio volumio[27154]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 17:28:40 volumio volumio[27154]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 17:28:40 volumio volumio[27154]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 17:28:40 volumio volumio[27154]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 17:28:40 volumio volumio[27154]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 17:28:40 volumio volumio[27154]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 17:28:40 volumio volumio[27154]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 17:28:40 volumio volumio[27154]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 17:28:40 volumio volumio[27154]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 17:28:40 volumio volumio[27154]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 17:28:40 volumio volumio[27154]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 17:28:40 volumio volumio[27154]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 17:28:40 volumio volumio[27154]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 17:28:40 volumio volumio[27154]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 17:28:40 volumio volumio[27154]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 17:28:41 volumio go-librespot[27498]: time="2026-02-18T17:28:41+07:00" level=debug msg="obtained new client token: AADPNVbqtr2J9WnJwk4n6N2jAlqm1CzGpM70wpfH+ypM8xVLGatqYFJ9Sib6cakZpDqtPnqcxnAf2TipHjAh/qF7gowfotwiJ1/V/q0D3itNPKR42ADWsXoTz7/59HoL5mSnsWDckSn7o+ZZNiNCIPe8w9rm4zuXHMUo9qQkyp3ASscbzKqnDfswnYdRKOc/KV8WXTTxDUJr2WE2fVg56PlFYt5WprtN36+u6xunuSYWK/S6pmmFX6o=" Feb 18 17:28:41 volumio go-librespot[27498]: time="2026-02-18T17:28:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 17:28:41 volumio go-librespot[27498]: time="2026-02-18T17:28:41+07:00" level=debug msg="completed keyexchange" Feb 18 17:28:41 volumio go-librespot[27498]: time="2026-02-18T17:28:41+07:00" level=debug msg="completed challenge" Feb 18 17:28:41 volumio go-librespot[27498]: time="2026-02-18T17:28: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 17:28:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 17:28:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 17:28:42 volumio volumio[27154]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 17:28:42 volumio volumio[27154]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 17:28:42 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 17:28:42 volumio volumio[27154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 17:28:42 volumio volumio[27154]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 17:28:42 volumio volumio[27154]: info: MyVolumio login type: Token Feb 18 17:28:42 volumio volumio[27154]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 17:28:42 volumio volumio[27154]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 17:28:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 18 17:28:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:28:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:28:44 volumio go-librespot[27519]: go-librespot daemon starting... Feb 18 17:28:44 volumio go-librespot[27520]: time="2026-02-18T17:28:44+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 17:28:44 volumio go-librespot[27520]: time="2026-02-18T17:28:44+07:00" level=debug msg="app state loaded" Feb 18 17:28:44 volumio go-librespot[27520]: time="2026-02-18T17:28:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 17:28:44 volumio volumio[27154]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 17:28:44 volumio volumio[27154]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 17:28:44 volumio volumio[27154]: info: Streaming services startup Feb 18 17:28:44 volumio volumio[27154]: info: Starting Streaming Daemon Feb 18 17:28:44 volumio sudo[27527]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 17:28:44 volumio volumio[27154]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 17:28:44 volumio sudo[27527]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:28:44 volumio sudo[27527]: pam_unix(sudo:session): session closed for user root Feb 18 17:28:44 volumio volumio[27154]: info: Getting Spotify volume Feb 18 17:28:44 volumio volumio[27154]: info: Connection to go-librespot Websocket closed Feb 18 17:28:44 volumio volumio[27154]: error: Cannot start Volumio Streaming Daemon Feb 18 17:28:44 volumio volumio[27154]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 17:28:44 volumio volumio[27154]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 17:28:45 volumio volumio[27154]: 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 17:28:45 volumio volumio[27154]: info: CoreCommandRouter::volumioGetState Feb 18 17:28:45 volumio volumio[27154]: info: CorePlayQueue::getTrack 0 Feb 18 17:28:45 volumio go-librespot[27520]: time="2026-02-18T17:28: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 17:28:45 volumio go-librespot[27520]: time="2026-02-18T17:28:45+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 17:28:45 volumio go-librespot[27520]: time="2026-02-18T17:28:45+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 17:28:45 volumio volumio[27154]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 18 17:28:45 volumio volumio[27154]: SPOTIFY: SPOTIFY VOLUME undefined Feb 18 17:28:45 volumio volumio[27154]: SPOTIFY: VOLUMIO VOLUME 100 Feb 18 17:28:45 volumio volumio[27154]: info: Aligning Spotify Volume to Volumio Volume Feb 18 17:28:45 volumio volumio[27154]: info: CoreCommandRouter::volumioGetState Feb 18 17:28:45 volumio volumio[27154]: info: CorePlayQueue::getTrack 0 Feb 18 17:28:45 volumio volumio[27154]: info: Setting Spotify Volume from Volumio: 100 Feb 18 17:28:45 volumio go-librespot[27520]: time="2026-02-18T17:28:45+07:00" level=info msg="zeroconf server listening on port 42147" Feb 18 17:28:45 volumio go-librespot[27520]: time="2026-02-18T17:28:45+07:00" level=debug msg="obtained new client token: AABaXTH1tCyQK9eQsl3Y86Ve4KIak8VvbGis6zb4rM/4qeZdgr2XAZ+VwnuCar8iBqaBJH1K3zcrqU0ji5HTS22DcFxlFH9N+tFftHhEJLz8IzYpDtNE3yAnXTitnf3ZPOOuGfgZ4ml1iYMwV77yd56rkvDQNo9eIzZy/OAH5GUqs419eLdWBvfNFvZ4E2xT7Dnc2038yJE9/bewlzXYSYYqdr7gc1meC+JArWaForVjhYe/HjESwotIVQ==" Feb 18 17:28:45 volumio go-librespot[27520]: time="2026-02-18T17:28:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 17:28:45 volumio go-librespot[27520]: time="2026-02-18T17:28: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 17:28:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 17:28:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 17:28:45 volumio volumio[27154]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 17:28:45 volumio volumio[27154]: Error: socket hang up Feb 18 17:28:45 volumio volumio[27154]: at connResetException (node:internal/errors:720:14) Feb 18 17:28:45 volumio volumio[27154]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 18 17:28:45 volumio volumio[27154]: at Socket.emit (node:events:526:35) Feb 18 17:28:45 volumio volumio[27154]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 18 17:28:45 volumio volumio[27154]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 18 17:28:45 volumio volumio[27154]: code: 'ECONNRESET', Feb 18 17:28:45 volumio volumio[27154]: response: undefined Feb 18 17:28:45 volumio volumio[27154]: } Feb 18 17:28:45 volumio volumio[27154]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 17:28:47 volumio sudo[27548]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 17:27' Feb 18 17:28:47 volumio sudo[27548]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:28:47 volumio sudo[27548]: pam_unix(sudo:session): session closed for user root Feb 18 17:28:47 volumio volumio-remote-updater[25144]: [2026-02-18 17:28:47] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 18 17:28:47 volumio volumio-remote-updater[25144]: [2026-02-18 17:28:47] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 18 17:28:47 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 18 17:28:47 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 18 17:28:47 volumio systemd[1]: volumio.service: Consumed 55.642s CPU time. Feb 18 17:28:47 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 17:28:47 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 17:28:48 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 22216. Feb 18 17:28:48 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 17:28:48 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 18 17:28:48 volumio systemd[1]: volumio.service: Consumed 55.642s CPU time. Feb 18 17:28:48 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 18 17:28:48 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 17:28:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 18 17:28:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:28:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:28:48 volumio go-librespot[27578]: go-librespot daemon starting... Feb 18 17:28:48 volumio go-librespot[27579]: time="2026-02-18T17:28:48+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 17:28:48 volumio go-librespot[27579]: time="2026-02-18T17:28:48+07:00" level=debug msg="app state loaded" Feb 18 17:28:48 volumio go-librespot[27579]: time="2026-02-18T17:28:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 17:28:49 volumio go-librespot[27579]: time="2026-02-18T17:28:49+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 17:28:49 volumio go-librespot[27579]: time="2026-02-18T17:28:49+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 17:28:49 volumio go-librespot[27579]: time="2026-02-18T17:28:49+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 17:28:49 volumio go-librespot[27579]: time="2026-02-18T17:28:49+07:00" level=info msg="zeroconf server listening on port 41075" Feb 18 17:28:49 volumio go-librespot[27579]: time="2026-02-18T17:28:49+07:00" level=debug msg="obtained new client token: AADYk5nU0Hj+AjVih6Ftvz36YaDaZx1Ya7Vv/d/PIkiVw1YK/KoSLUITZf3oNSkfHsjvyFxNqI4SUGQSUsgNARKqENg5IckWhf6SgTVUDie6CTP7+HaXCmAvEXbXSCDFmEv2AfyyyT7RxiVu9FIP3qd51TpgLelKctoimp633vxogIyHDTJnEz2/g1ZN+ak1Kiwkx69lkA0qm1X84fsVE5FZn1uEKkyRyheBvfCzHxvLZeqcXCirtRTY4w==" Feb 18 17:28:49 volumio go-librespot[27579]: time="2026-02-18T17:28:49+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 17:28:49 volumio go-librespot[27579]: time="2026-02-18T17:28:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 18 17:28:49 volumio go-librespot[27579]: time="2026-02-18T17:28:49+07:00" level=debug msg="completed keyexchange" Feb 18 17:28:49 volumio go-librespot[27579]: time="2026-02-18T17:28:49+07:00" level=debug msg="completed challenge" Feb 18 17:28:50 volumio go-librespot[27579]: time="2026-02-18T17:28: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 17:28:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 17:28:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 17:28:51 volumio volumio[27563]: info: ------------------------------------------- Feb 18 17:28:51 volumio volumio[27563]: info: ----- Volumio3 ---- Feb 18 17:28:51 volumio volumio[27563]: info: ------------------------------------------- Feb 18 17:28:51 volumio volumio[27563]: info: ----- System startup ---- Feb 18 17:28:51 volumio volumio[27563]: info: ------------------------------------------- Feb 18 17:28:52 volumio volumio-remote-updater[25144]: [2026-02-18 17:28:52] [connect] Successful connection Feb 18 17:28:53 volumio volumio[27563]: info: MYVOLUMIO Environment detected Feb 18 17:28:53 volumio volumio[27563]: info: Plugin folders cleanup Feb 18 17:28:53 volumio volumio[27563]: info: Scanning into folder /volumio/app/plugins/ Feb 18 17:28:53 volumio volumio[27563]: info: Scanning category audio_interface Feb 18 17:28:53 volumio volumio[27563]: info: Scanning category miscellanea Feb 18 17:28:53 volumio volumio[27563]: info: Scanning category music_service Feb 18 17:28:53 volumio volumio[27563]: info: Scanning category plugins.json Feb 18 17:28:53 volumio volumio[27563]: info: Scanning category system_controller Feb 18 17:28:53 volumio volumio[27563]: info: Scanning category user_interface Feb 18 17:28:53 volumio volumio[27563]: info: Scanning into folder /data/plugins/ Feb 18 17:28:53 volumio volumio[27563]: info: Scanning category music_service Feb 18 17:28:53 volumio volumio[27563]: info: Plugin folders cleanup completed Feb 18 17:28:53 volumio volumio[27563]: info: ------------------------------------------- Feb 18 17:28:53 volumio volumio[27563]: info: ----- Core plugins startup ---- Feb 18 17:28:53 volumio volumio[27563]: info: ------------------------------------------- Feb 18 17:28:53 volumio volumio[27563]: info: Loading plugins from folder /volumio/app/plugins/ Feb 18 17:28:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 18 17:28:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:28:53 volumio volumio[27563]: info: Adding plugin upnp to MyMusic Plugins Feb 18 17:28:53 volumio volumio[27563]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 18 17:28:53 volumio volumio[27563]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 18 17:28:53 volumio volumio[27563]: info: Loading plugins from folder /data/plugins/ Feb 18 17:28:53 volumio volumio[27563]: info: Loading plugin "system"... Feb 18 17:28:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:28:53 volumio volumio[27563]: info: Loading plugin "appearance"... Feb 18 17:28:53 volumio go-librespot[27597]: go-librespot daemon starting... Feb 18 17:28:53 volumio go-librespot[27601]: time="2026-02-18T17:28:53+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 17:28:53 volumio go-librespot[27601]: time="2026-02-18T17:28:53+07:00" level=debug msg="app state loaded" Feb 18 17:28:53 volumio go-librespot[27601]: time="2026-02-18T17:28:53+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 17:28:54 volumio go-librespot[27601]: time="2026-02-18T17:28:54+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 17:28:54 volumio go-librespot[27601]: time="2026-02-18T17:28:54+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 17:28:54 volumio go-librespot[27601]: time="2026-02-18T17:28:54+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 17:28:54 volumio go-librespot[27601]: time="2026-02-18T17:28:54+07:00" level=info msg="zeroconf server listening on port 38599" Feb 18 17:28:54 volumio go-librespot[27601]: time="2026-02-18T17:28:54+07:00" level=debug msg="obtained new client token: AABFKoQlSH6jfiXmggNXv2Dc5li7YE0W+Oond9+Xc7QR3Hrf7fiU8GeE1pQMzEWc3NPevjntnklPOOQHUcqhPP0zIfZJCwz4it8pZJAtunkq1X/6LXpJ9eAn/9EhZL0We5CxdLtB/YfQq4nq/6ycy57OAKhkJmSwCLYGisVg+MYDAoi7xwyE1cELSDjse0XyG6PLJ+GhSi8epWWWra7Iq1BORkMkpGBKZ8B5q7Tx6C4+xU8SGYXTOTg=" Feb 18 17:28:54 volumio go-librespot[27601]: time="2026-02-18T17:28:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 17:28:54 volumio go-librespot[27601]: time="2026-02-18T17:28:54+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 17:28:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 17:28:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 17:28:55 volumio volumio[27563]: info: Loading plugin "network"... Feb 18 17:28:55 volumio volumio[27563]: info: Refreshing Cached IP Addresses Feb 18 17:28:55 volumio sudo[27610]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 17:28:55 volumio sudo[27610]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:28:55 volumio sudo[27610]: pam_unix(sudo:session): session closed for user root Feb 18 17:28:55 volumio sudo[27612]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 17:28:55 volumio sudo[27612]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:28:55 volumio volumio[27563]: info: Loading plugin "services"... Feb 18 17:28:55 volumio volumio[27563]: info: Loading plugin "alsa_controller"... Feb 18 17:28:55 volumio sudo[27612]: pam_unix(sudo:session): session closed for user root Feb 18 17:28:55 volumio sudo[27620]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 18 17:28:55 volumio sudo[27620]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:28:55 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 17:28:55 volumio volumio[27563]: info: Loading plugin "wizard"... Feb 18 17:28:55 volumio volumio[27563]: info: Loading plugin "networkfs"... Feb 18 17:28:55 volumio volumio[27563]: info: Starting Udev Watcher for removable devices Feb 18 17:28:55 volumio volumio[27563]: info: Ignoring mount for partition: boot Feb 18 17:28:55 volumio volumio[27563]: info: Ignoring mount for partition: volumio Feb 18 17:28:55 volumio volumio[27563]: info: Ignoring mount for partition: volumio_data Feb 18 17:28:55 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 17:28:55 volumio volumio[27563]: info: Loading plugin "volumio_command_line_client"... Feb 18 17:28:55 volumio volumio[27563]: info: Loading plugin "upnp"... Feb 18 17:28:55 volumio volumio[27563]: info: [1771410535776] Starting Upmpd Daemon Feb 18 17:28:55 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 17:28:55 volumio volumio[27563]: info: Loading plugin "my_music"... Feb 18 17:28:55 volumio volumio[27563]: info: Loading plugin "mpd"... Feb 18 17:28:56 volumio volumio[27563]: info: Loading plugin "upnp_browser"... Feb 18 17:28:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 18 17:28:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:28:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:28:57 volumio go-librespot[27643]: go-librespot daemon starting... Feb 18 17:28:57 volumio go-librespot[27644]: time="2026-02-18T17:28:57+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 17:28:57 volumio go-librespot[27644]: time="2026-02-18T17:28:57+07:00" level=debug msg="app state loaded" Feb 18 17:28:57 volumio go-librespot[27644]: time="2026-02-18T17:28:57+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 17:28:58 volumio go-librespot[27644]: time="2026-02-18T17:28:58+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 17:28:58 volumio go-librespot[27644]: time="2026-02-18T17:28:58+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 17:28:58 volumio go-librespot[27644]: time="2026-02-18T17:28:58+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 17:28:58 volumio go-librespot[27644]: time="2026-02-18T17:28:58+07:00" level=info msg="zeroconf server listening on port 43665" Feb 18 17:28:58 volumio sudo[27620]: pam_unix(sudo:session): session closed for user root Feb 18 17:28:58 volumio go-librespot[27644]: time="2026-02-18T17:28:58+07:00" level=debug msg="obtained new client token: AACern7PQ0y2q9ZTqEDVwy/eXD7T2limuTju7Q/zkqYE+6gfTITKImIYzXO0qBWekrax+NKuk6/CYBZvssUA0VFJXGiaFzJyzsz+USEyQED8HLpEQNhXVqluA5pvKoqZZm5ayj9pGfh8Hxl0AKti4PIEbsnTpiBlSEn+uS0I3dD4N6oRweh70kiczbwDTmziw0lVFDbikEIYI3X8wHr/6xut2uwhX2aU0dlV9gH1IeKQ61ZMbZewy4FDbw==" Feb 18 17:28:58 volumio go-librespot[27644]: time="2026-02-18T17:28:58+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 17:28:58 volumio go-librespot[27644]: time="2026-02-18T17:28:58+07:00" level=debug msg="completed keyexchange" Feb 18 17:28:58 volumio go-librespot[27644]: time="2026-02-18T17:28:58+07:00" level=debug msg="completed challenge" Feb 18 17:28:58 volumio go-librespot[27644]: time="2026-02-18T17:28:58+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 17:28:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 17:28:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 17:28:59 volumio volumio[27563]: info: Starting UPNP Browser Feb 18 17:28:59 volumio volumio[27563]: info: Loading plugin "alarm-clock"... Feb 18 17:28:59 volumio volumio[27563]: info: Loading plugin "airplay_emulation"... Feb 18 17:28:59 volumio volumio[27563]: info: Starting Shairport Sync Feb 18 17:28:59 volumio volumio[27563]: info: Loading plugin "last_100"... Feb 18 17:28:59 volumio volumio[27563]: info: Loading plugin "webradio"... Feb 18 17:28:59 volumio volumio[27563]: info: Loading plugin "i2s_dacs"... Feb 18 17:28:59 volumio volumio[27563]: info: Loading plugin "volumiodiscovery"... Feb 18 17:28:59 volumio volumio[27563]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 17:28:59 volumio node[27563]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 17:28:59 volumio volumio[27563]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 17:28:59 volumio node[27563]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 17:28:59 volumio volumio[27563]: *** WARNING *** For more information see Feb 18 17:28:59 volumio node[27563]: *** WARNING *** For more information see Feb 18 17:28:59 volumio volumio[27563]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 17:28:59 volumio node[27563]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 17:28:59 volumio volumio[27563]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 17:28:59 volumio volumio[27563]: *** WARNING *** For more information see Feb 18 17:28:59 volumio node[27563]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 17:28:59 volumio node[27563]: *** WARNING *** For more information see Feb 18 17:28:59 volumio volumio[27563]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 18 17:29:00 volumio volumio[27563]: info: Discovery: Started advertising with name: Volumio Feb 18 17:29:00 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 17:29:00 volumio volumio[27563]: info: Loading plugin "spop"... Feb 18 17:29:01 volumio volumio[27563]: info: Loading plugin "ytcr"... Feb 18 17:29:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 18 17:29:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:29:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:29:02 volumio go-librespot[27654]: go-librespot daemon starting... Feb 18 17:29:02 volumio go-librespot[27655]: time="2026-02-18T17:29:02+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 17:29:02 volumio go-librespot[27655]: time="2026-02-18T17:29:02+07:00" level=debug msg="app state loaded" Feb 18 17:29:02 volumio go-librespot[27655]: time="2026-02-18T17:29:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 17:29:02 volumio go-librespot[27655]: time="2026-02-18T17:29:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 17:29:02 volumio go-librespot[27655]: time="2026-02-18T17:29:02+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 17:29:02 volumio go-librespot[27655]: time="2026-02-18T17:29:02+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 17:29:02 volumio go-librespot[27655]: time="2026-02-18T17:29:02+07:00" level=info msg="zeroconf server listening on port 38681" Feb 18 17:29:02 volumio go-librespot[27655]: time="2026-02-18T17:29:02+07:00" level=debug msg="obtained new client token: AACyG/8tFnKCt/TOpKLFdTGFQL0YneB7W8EYzwPl4zA5cCJyvVpvKwiH7TX3zQBnpjgP7v8z24hiOwIlcz1CTbp6pmnmfc1EAwt7StjSKab2QuGpnsnGWmGL3NSEzWiN789rinGhTFBnj0YbZO2PgGAbISU7ISq0c1a0Y/AaQ23NnKw1ATbbj3chI8hkBHneHQVBQPIEMdCR6KHd0+FO63SVYLQJjFreNE+wMTbtmAHHFgPEH+0AzsjAZg==" Feb 18 17:29:03 volumio go-librespot[27655]: time="2026-02-18T17:29:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 17:29:03 volumio go-librespot[27655]: time="2026-02-18T17:29:03+07:00" level=debug msg="completed keyexchange" Feb 18 17:29:03 volumio go-librespot[27655]: time="2026-02-18T17:29:03+07:00" level=debug msg="completed challenge" Feb 18 17:29:03 volumio go-librespot[27655]: time="2026-02-18T17:29:03+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 17:29:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 17:29:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 17:29:04 volumio volumio[27563]: info: Loading plugin "ytmusic"... Feb 18 17:29:05 volumio volumio-remote-updater[25144]: [2026-02-18 17:29:05] [connect] Successful connection Feb 18 17:29:05 volumio volumio[27563]: info: Loading plugin "outputs"... Feb 18 17:29:05 volumio volumio[27563]: info: Loading plugin "albumart"... Feb 18 17:29:05 volumio volumio[27563]: info: Plugin example_plugin is not enabled Feb 18 17:29:05 volumio volumio[27563]: info: Loading plugin "inputs"... Feb 18 17:29:05 volumio volumio[27563]: info: Loading plugin "updater_comm"... Feb 18 17:29:05 volumio volumio[27563]: info: Plugin mpdemulation is not enabled Feb 18 17:29:05 volumio volumio[27563]: info: Loading plugin "rest_api"... Feb 18 17:29:05 volumio volumio[27563]: info: Loading plugin "websocket"... Feb 18 17:29:05 volumio volumio[27563]: info: Starting Socket.io Server version 1.7.4 Feb 18 17:29:05 volumio volumio[27563]: info: Loading plugin "RoonBridge"... Feb 18 17:29:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 18 17:29:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:29:06 volumio volumio[27563]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 17:29:06 volumio volumio[27563]: info: Loading i18n strings for locale en Feb 18 17:29:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:29:06 volumio go-librespot[27686]: go-librespot daemon starting... Feb 18 17:29:06 volumio volumio[27563]: Updating browse sources language Feb 18 17:29:06 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 17:29:06 volumio go-librespot[27687]: time="2026-02-18T17:29:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 17:29:06 volumio go-librespot[27687]: time="2026-02-18T17:29:06+07:00" level=debug msg="app state loaded" Feb 18 17:29:06 volumio go-librespot[27687]: time="2026-02-18T17:29:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 17:29:06 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 17:29:06 volumio volumio[27563]: info: CoreCommandRouter::initPlayerControls Feb 18 17:29:06 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:29:06 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:29:06 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:29:06 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:29:06 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:29:06 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:29:06 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:29:06 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:29:06 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 17:29:06 volumio volumio[27563]: Express server listening on port 3000 Feb 18 17:29:06 volumio volumio[27563]: [Metrics] WebUI: 15s 898.83ms Feb 18 17:29:06 volumio volumio[27563]: info: CoreStateMachine::resetVolumioState Feb 18 17:29:06 volumio volumio[27563]: info: CoreStateMachine::getcurrentVolume Feb 18 17:29:06 volumio volumio[27563]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 17:29:06 volumio volumio[27675]: Forking 3 albumart workers Feb 18 17:29:06 volumio sudo[27701]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 17:29:06 volumio sudo[27705]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 17:29:06 volumio sudo[27705]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:29:06 volumio sudo[27701]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:29:06 volumio sudo[27705]: pam_unix(sudo:session): session closed for user root Feb 18 17:29:06 volumio sudo[27701]: pam_unix(sudo:session): session closed for user root Feb 18 17:29:07 volumio go-librespot[27687]: time="2026-02-18T17:29:07+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 17:29:07 volumio go-librespot[27687]: time="2026-02-18T17:29:07+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 17:29:07 volumio go-librespot[27687]: time="2026-02-18T17:29:07+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 17:29:07 volumio volumio[27563]: info: Volumio Network Manager: Network status updated: 1 Feb 18 17:29:07 volumio go-librespot[27687]: time="2026-02-18T17:29:07+07:00" level=info msg="zeroconf server listening on port 44951" Feb 18 17:29:07 volumio go-librespot[27687]: time="2026-02-18T17:29:07+07:00" level=debug msg="obtained new client token: AAAs20Kf7sVMi1P1uxMxCK7jAZAQarQqO4Vx3r64WOVpD0XQJcgCpZgzXBqk9Lg9EvLXpN8+biUEOSJeP9OQl/GY6IYEXeqtWzuf+FMSxzRAEQ658GeMfwlSrz1VieUEVPWkbaicTRUVO/+WmFAFZp57E4DnQqwgIxJrdxG+ykkNC0n42aOh6ZFPQ20ouFRsfYoeJhM7/4uQgYeZjlYk5H6Vng4Jvs54fihV9m1UIVDWL8E9W3eKR0vM2w==" Feb 18 17:29:07 volumio volumio[27563]: info: VolumeController:: Volume=100 Mute =false Feb 18 17:29:07 volumio volumio[27563]: info: CoreStateMachine::pushState Feb 18 17:29:07 volumio volumio[27563]: info: CorePlayQueue::getTrack 0 Feb 18 17:29:07 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 17:29:07 volumio volumio[27563]: info: CoreCommandRouter::volumioPushState Feb 18 17:29:07 volumio volumio[27563]: info: CoreStateMachine::updateTrackBlock Feb 18 17:29:07 volumio volumio[27563]: info: CorePlayQueue::getTrackBlock Feb 18 17:29:07 volumio volumio[27563]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 17:29:07 volumio go-librespot[27687]: time="2026-02-18T17:29:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 17:29:07 volumio volumio-remote-updater[25144]: [2026-02-18 17:29:07] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771410545 101 Feb 18 17:29:07 volumio volumio[27563]: 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 17:29:07 volumio go-librespot[27687]: time="2026-02-18T17:29:07+07:00" level=debug msg="completed keyexchange" Feb 18 17:29:07 volumio go-librespot[27687]: time="2026-02-18T17:29:07+07:00" level=debug msg="completed challenge" Feb 18 17:29:07 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 17:29:07 volumio volumio[27563]: info: Reloading queue from file Feb 18 17:29:07 volumio go-librespot[27687]: time="2026-02-18T17:29:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 17:29:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 17:29:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 17:29:07 volumio volumio[27563]: info: CoreStateMachine::setRepeat null single undefined Feb 18 17:29:07 volumio volumio[27563]: info: CoreStateMachine::pushState Feb 18 17:29:07 volumio volumio[27563]: info: CorePlayQueue::getTrack 0 Feb 18 17:29:07 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 17:29:07 volumio volumio[27563]: info: CoreCommandRouter::volumioPushState Feb 18 17:29:07 volumio volumio[27563]: info: CoreStateMachine::setRandom null Feb 18 17:29:07 volumio volumio[27563]: info: CoreStateMachine::pushState Feb 18 17:29:07 volumio volumio[27563]: info: CorePlayQueue::getTrack 0 Feb 18 17:29:07 volumio volumio[27563]: info: CoreCommandRouter::volumioPushState Feb 18 17:29:07 volumio volumio[27563]: info: Setting Device type: Raspberry PI Feb 18 17:29:07 volumio volumio[27563]: info: Completed loading Core Plugins Feb 18 17:29:07 volumio volumio[27563]: info: Preparing to generate the ALSA configuration file Feb 18 17:29:07 volumio volumio[27563]: info: VolumeController:: Volume=100 Mute =false Feb 18 17:29:07 volumio volumio[27563]: info: CoreStateMachine::pushState Feb 18 17:29:07 volumio volumio[27563]: info: CorePlayQueue::getTrack 0 Feb 18 17:29:07 volumio volumio[27563]: info: CoreCommandRouter::volumioPushState Feb 18 17:29:08 volumio volumio[27563]: info: Asound.conf file unchanged, so no further update is needed Feb 18 17:29:08 volumio volumio[27563]: info: Output device has changed, restarting MPD Feb 18 17:29:08 volumio volumio[27563]: info: Output device has changed, restarting Shairport Sync Feb 18 17:29:08 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:29:08 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 17:29:08 volumio sudo[27745]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 17:29:08 volumio sudo[27745]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:29:08 volumio sudo[27747]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 17:29:08 volumio sudo[27747]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:29:08 volumio sudo[27749]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 17:29:08 volumio sudo[27749]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:29:08 volumio sudo[27747]: pam_unix(sudo:session): session closed for user root Feb 18 17:29:08 volumio volumio[27563]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 17:29:08 volumio volumio[27563]: info: ___________ START PLUGINS ___________ Feb 18 17:29:08 volumio volumio[27563]: info: ControllerMpd::onStart: Initializing MPD Feb 18 17:29:08 volumio volumio[27563]: info: Creating MPD Configuration file Feb 18 17:29:08 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 17:29:08 volumio volumio[27563]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 17:29:08 volumio volumio[27563]: info: [1771410548281] CoreMusicLibrary::Adding element Media Servers Feb 18 17:29:08 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 17:29:08 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 17:29:08 volumio volumio[27563]: info: UPNP Browser: Client initialized successfully Feb 18 17:29:08 volumio sudo[27745]: pam_unix(sudo:session): session closed for user root Feb 18 17:29:08 volumio sudo[27758]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 17:29:08 volumio sudo[27758]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:29:08 volumio sudo[27758]: pam_unix(sudo:session): session closed for user root Feb 18 17:29:08 volumio sudo[27760]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 17:29:08 volumio sudo[27760]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:29:08 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:29:08 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 17:29:08 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 17:29:08 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 17:29:08 volumio systemd[1]: mpd.service: Consumed 7.181s CPU time. Feb 18 17:29:08 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 17:29:08 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 17:29:08 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 17:29:08 volumio volumio[27563]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 17:29:08 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:29:08 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 17:29:08 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 17:29:08 volumio volumio[27563]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 17:29:08 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 17:29:08 volumio volumio[27563]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 17:29:08 volumio volumio[27563]: info: [1771410548678] CoreMusicLibrary::Adding element Last_100 Feb 18 17:29:08 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 17:29:08 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 17:29:08 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 17:29:08 volumio volumio[27563]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 17:29:08 volumio volumio[27563]: info: [1771410548705] CoreMusicLibrary::Adding element Webradio Feb 18 17:29:08 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 17:29:08 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 17:29:08 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 17:29:08 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 17:29:08 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 17:29:08 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 17:29:08 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 17:29:08 volumio volumio[27563]: info: Initializing BBC Radios Feb 18 17:29:08 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 17:29:08 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 17:29:09 volumio volumio[27563]: info: Creating Spotify config file Feb 18 17:29:09 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:29:09 volumio sudo[27774]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 17:29:09 volumio sudo[27774]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 17:29:09 volumio sudo[27774]: pam_unix(sudo:session): session closed for user root Feb 18 17:29:10 volumio volumio[27563]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 17:29:10 volumio volumio[27563]: info: [1771410550130] CoreMusicLibrary::Adding element YouTube Music Feb 18 17:29:10 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 17:29:10 volumio volumio[27563]: Cannot find translation for source YouTube Music Feb 18 17:29:10 volumio volumio[27699]: Starting albumart workers Feb 18 17:29:10 volumio volumio[27704]: Starting albumart workers Feb 18 17:29:10 volumio volumio[27702]: Starting albumart workers Feb 18 17:29:10 volumio volumio[27563]: info: Volumio Calling Home Feb 18 17:29:10 volumio sudo[27791]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 17:29:10 volumio sudo[27791]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:29:10 volumio sudo[27791]: pam_unix(sudo:session): session closed for user root Feb 18 17:29:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 18 17:29:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:29:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:29:10 volumio go-librespot[27796]: go-librespot daemon starting... Feb 18 17:29:10 volumio volumio[27563]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 17:29:10 volumio volumio[27563]: info: Discovery: Found device Volumio Feb 18 17:29:11 volumio go-librespot[27797]: time="2026-02-18T17:29:11+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 17:29:11 volumio go-librespot[27797]: time="2026-02-18T17:29:11+07:00" level=debug msg="app state loaded" Feb 18 17:29:11 volumio volumio[27563]: info: CoreCommandRouter::volumioGetState Feb 18 17:29:11 volumio go-librespot[27797]: time="2026-02-18T17:29:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 17:29:11 volumio volumio[27563]: info: CorePlayQueue::getTrack 0 Feb 18 17:29:11 volumio volumio[27563]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 17:29:11 volumio volumio[27563]: info: Discovery: Found device Volumio Feb 18 17:29:11 volumio volumio[27563]: info: CoreCommandRouter::volumioGetState Feb 18 17:29:11 volumio volumio[27563]: info: CorePlayQueue::getTrack 0 Feb 18 17:29:11 volumio volumio[27563]: info: MPD Permissions set Feb 18 17:29:11 volumio volumio[27563]: info: MPD Permissions set Feb 18 17:29:11 volumio volumio[27563]: info: Upmpdcli Daemon Started Feb 18 17:29:11 volumio volumio[27563]: info: Volumio called home Feb 18 17:29:11 volumio volumio[27563]: info: Spotify config file written Feb 18 17:29:11 volumio sudo[27805]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 17:29:11 volumio sudo[27805]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:29:11 volumio go-librespot[27797]: time="2026-02-18T17:29:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 17:29:11 volumio go-librespot[27797]: time="2026-02-18T17:29:11+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 17:29:11 volumio go-librespot[27797]: time="2026-02-18T17:29:11+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 17:29:11 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 18 17:29:11 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 18 17:29:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:29:11 volumio go-librespot[27807]: go-librespot daemon starting... Feb 18 17:29:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:29:11 volumio sudo[27805]: pam_unix(sudo:session): session closed for user root Feb 18 17:29:12 volumio go-librespot[27808]: time="2026-02-18T17:29:12+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 17:29:12 volumio go-librespot[27808]: time="2026-02-18T17:29:12+07:00" level=debug msg="app state loaded" Feb 18 17:29:12 volumio go-librespot[27808]: time="2026-02-18T17:29:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 17:29:12 volumio volumio[27563]: 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 17:29:12 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:29:12 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:29:12 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:29:12 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:29:12 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:29:12 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:29:12 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:29:12 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:29:12 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 17:29:12 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:29:12 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:29:12 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:29:12 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:29:12 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:29:12 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:29:12 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:29:12 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:29:12 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:29:12 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 17:29:12 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 17:29:12 volumio volumio[27563]: info: No need to fix Spotify hosts Feb 18 17:29:12 volumio go-librespot[27808]: time="2026-02-18T17:29:12+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 17:29:12 volumio go-librespot[27808]: time="2026-02-18T17:29:12+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 17:29:12 volumio go-librespot[27808]: time="2026-02-18T17:29:12+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 17:29:12 volumio go-librespot[27808]: time="2026-02-18T17:29:12+07:00" level=info msg="zeroconf server listening on port 42577" Feb 18 17:29:13 volumio volumio[27563]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 17:29:13 volumio volumio[27563]: SPOTIFY: BQAPTXtLqlOD9UpcilZ_aGzlGNpTvjQEJBF98rAO5ixeALpz81clxxb5KG5_aH5z8iybwr-MbuMLiK0Hn6NW8sP8PfXjzCE18N7cPI9AJD-3bgMdRajtk0BxdHl-SkXrA13o7B6pwwnGNkJdZ5jp2BHstwnwtg_1QKq1h4p4VWzSf4zIweBn8-92LoNe05P2q0VcLKUqGNJOlXh2FhSQqUz9e1n6GV39btg3LGnLXi-k0_A6uwPd8Gm_mq-3-k-D4ZvLxByGgqCcXoX8AoKr6sGajIJaRPT-zQII-55w_dlyXjCnYoc1V2Rd Feb 18 17:29:13 volumio volumio[27563]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 17:29:13 volumio volumio[27563]: info: New Spotify access token = BQAPTXtLqlOD9UpcilZ_aGzlGNpTvjQEJBF98rAO5ixeALpz81clxxb5KG5_aH5z8iybwr-MbuMLiK0Hn6NW8sP8PfXjzCE18N7cPI9AJD-3bgMdRajtk0BxdHl-SkXrA13o7B6pwwnGNkJdZ5jp2BHstwnwtg_1QKq1h4p4VWzSf4zIweBn8-92LoNe05P2q0VcLKUqGNJOlXh2FhSQqUz9e1n6GV39btg3LGnLXi-k0_A6uwPd8Gm_mq-3-k-D4ZvLxByGgqCcXoX8AoKr6sGajIJaRPT-zQII-55w_dlyXjCnYoc1V2Rd Feb 18 17:29:13 volumio volumio[27563]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 17:29:13 volumio volumio[27563]: info: Starting Shairport Sync Feb 18 17:29:13 volumio volumio[27563]: info: Starting Shairport Sync Feb 18 17:29:13 volumio volumio[27563]: info: Starting Shairport Sync Feb 18 17:29:13 volumio sudo[27845]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 17:29:13 volumio sudo[27845]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:29:13 volumio sudo[27847]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 17:29:13 volumio sudo[27847]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:29:13 volumio go-librespot[27808]: time="2026-02-18T17:29:13+07:00" level=debug msg="obtained new client token: AAD5WX9n3/moycVpO5X9ZASgHjMXtRiy6NczsEPa5VFP6lGKrTkLvop/AeSLKHaZkMiOB0PVYooJBRUCaS2TfZnF+cAo1GUbfLIpXkx+r+IZTGDHLggoP9jkJSohMwNjJmEJOmzy2aNttuY4RwPbVlhJT8RNc5sUi6rK7ZFP27iAn1ic/a7nO1UQHt2rnmDUYflaqTXxtbMCQ1B+F0fVwoQlgM/ZlPGc845S/EvAXvvG+q+60ohZaxw=" Feb 18 17:29:13 volumio sudo[27849]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 17:29:13 volumio sudo[27849]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:29:13 volumio go-librespot[27808]: time="2026-02-18T17:29:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 17:29:13 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 17:29:13 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 17:29:13 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 17:29:13 volumio systemd[1]: shairport-sync.service: Consumed 2.280s CPU time. Feb 18 17:29:13 volumio go-librespot[27808]: time="2026-02-18T17:29:13+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 17:29:13 volumio volumio[27563]: info: CoreCommandRouter::volumioGetState Feb 18 17:29:13 volumio volumio[27563]: info: CorePlayQueue::getTrack 0 Feb 18 17:29:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 17:29:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 17:29:13 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 17:29:13 volumio sudo[27847]: pam_unix(sudo:session): session closed for user root Feb 18 17:29:13 volumio sudo[27845]: pam_unix(sudo:session): session closed for user root Feb 18 17:29:13 volumio volumio[27563]: info: Shairport-Sync Started Feb 18 17:29:13 volumio volumio[27563]: Error adding Membership: Error: addMembership EINVAL Feb 18 17:29:13 volumio volumio[27563]: info: Shairport-Sync Started Feb 18 17:29:13 volumio volumio[27563]: 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 17:29:13 volumio volumio[27563]: info: Spotify Successfully logged in Feb 18 17:29:13 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 17:29:13 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 17:29:13 volumio volumio[27563]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 17:29:13 volumio volumio[27563]: info: [1771410553782] CoreMusicLibrary::Adding element Spotify Feb 18 17:29:13 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 17:29:13 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 17:29:13 volumio volumio[27563]: Cannot find translation for source YouTube Music Feb 18 17:29:13 volumio volumio[27563]: Cannot find translation for source Spotify Feb 18 17:29:13 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 17:29:13 volumio sudo[27849]: pam_unix(sudo:session): session closed for user root Feb 18 17:29:13 volumio volumio[27563]: info: Shairport-Sync Started Feb 18 17:29:14 volumio volumio[27563]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 17:29:14 volumio volumio[27563]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 17:29:14 volumio volumio[27563]: info: VolumeController:: Volume=100 Mute =false Feb 18 17:29:14 volumio volumio[27563]: info: CoreCommandRouter::volumioGetState Feb 18 17:29:14 volumio volumio[27563]: info: CorePlayQueue::getTrack 0 Feb 18 17:29:14 volumio volumio[27563]: info: CoreStateMachine::pushState Feb 18 17:29:14 volumio volumio[27563]: info: CorePlayQueue::getTrack 0 Feb 18 17:29:14 volumio volumio[27563]: info: CoreCommandRouter::volumioPushState Feb 18 17:29:16 volumio volumio[27563]: info: go-librespot daemon successfully initialized Feb 18 17:29:16 volumio mpd[27789]: 2026-02-18T17:29:16 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 17:29:16 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 17:29:16 volumio sudo[27749]: pam_unix(sudo:session): session closed for user root Feb 18 17:29:16 volumio sudo[27760]: pam_unix(sudo:session): session closed for user root Feb 18 17:29:16 volumio volumio[27563]: error: MPD error: The expression evaluated to a falsy value: Feb 18 17:29:16 volumio volumio[27563]: assert.ok(self.idling) Feb 18 17:29:16 volumio volumio[27563]: error: The expression evaluated to a falsy value: Feb 18 17:29:16 volumio volumio[27563]: assert.ok(self.idling) Feb 18 17:29:16 volumio volumio[27563]: error: updateQueue error: null Feb 18 17:29:16 volumio volumio[27563]: info: MPD running with PID27789 Feb 18 17:29:16 volumio volumio[27563]: ,establishing connection Feb 18 17:29:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 18 17:29:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:29:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:29:16 volumio go-librespot[27891]: go-librespot daemon starting... Feb 18 17:29:16 volumio volumio[27563]: info: Completed starting Core Plugins Feb 18 17:29:16 volumio volumio[27563]: info: ------------------------------------------- Feb 18 17:29:16 volumio volumio[27563]: info: ----- MyVolumio plugins startup ---- Feb 18 17:29:16 volumio volumio[27563]: info: ------------------------------------------- Feb 18 17:29:16 volumio volumio[27563]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 17:29:16 volumio volumio[27563]: error: updateQueue error: null Feb 18 17:29:16 volumio go-librespot[27892]: time="2026-02-18T17:29:16+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 17:29:16 volumio go-librespot[27892]: time="2026-02-18T17:29:16+07:00" level=debug msg="app state loaded" Feb 18 17:29:16 volumio go-librespot[27892]: time="2026-02-18T17:29:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 17:29:17 volumio go-librespot[27892]: time="2026-02-18T17:29:17+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 17:29:17 volumio go-librespot[27892]: time="2026-02-18T17:29:17+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 17:29:17 volumio go-librespot[27892]: time="2026-02-18T17:29:17+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 17:29:17 volumio go-librespot[27892]: time="2026-02-18T17:29:17+07:00" level=info msg="zeroconf server listening on port 35007" Feb 18 17:29:17 volumio go-librespot[27892]: time="2026-02-18T17:29:17+07:00" level=debug msg="obtained new client token: AAC0Tvf3AA+jDIYKRLYoV/2VKtuBZ42jidBhgfnXoMoWqzFI+5HCvZeJwgVeFA8PI9XTcAAB41RksAZnzUM+LgdQ3WGvoGpu+wRDj2bRjwBNtcMRdqgEKNY39Fg08JhoJsoFe/fV9CgqH3lFPfaKYO7yxSPprhWkYWyqYmrVnFS4PM+058kM3yihko2RJ4F2bGL7E8eQTXr6bCKj9+J0kqyok4s+gHbtd9kfvntrTTQPYgSlpo1vZ7gH2w==" Feb 18 17:29:17 volumio go-librespot[27892]: time="2026-02-18T17:29:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 17:29:17 volumio go-librespot[27892]: time="2026-02-18T17:29:17+07:00" level=debug msg="completed keyexchange" Feb 18 17:29:17 volumio go-librespot[27892]: time="2026-02-18T17:29:17+07:00" level=debug msg="completed challenge" Feb 18 17:29:17 volumio go-librespot[27892]: time="2026-02-18T17:29:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 17:29:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 17:29:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 17:29:19 volumio volumio[27563]: info: Initializing connection to go-librespot Websocket Feb 18 17:29:19 volumio volumio[27563]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 17:29:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 18 17:29:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:29:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:29:20 volumio go-librespot[27899]: go-librespot daemon starting... Feb 18 17:29:20 volumio go-librespot[27900]: time="2026-02-18T17:29:20+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 17:29:20 volumio go-librespot[27900]: time="2026-02-18T17:29:20+07:00" level=debug msg="app state loaded" Feb 18 17:29:20 volumio go-librespot[27900]: time="2026-02-18T17:29:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 17:29:21 volumio volumio[27563]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 17:29:21 volumio go-librespot[27900]: time="2026-02-18T17:29:21+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 17:29:21 volumio go-librespot[27900]: time="2026-02-18T17:29:21+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 17:29:21 volumio go-librespot[27900]: time="2026-02-18T17:29:21+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 17:29:21 volumio go-librespot[27900]: time="2026-02-18T17:29:21+07:00" level=info msg="zeroconf server listening on port 40623" Feb 18 17:29:21 volumio go-librespot[27900]: time="2026-02-18T17:29:21+07:00" level=debug msg="obtained new client token: AADWDbYfS7Iia0BAkx3/Ui4qVDALWglUagtBuTiwF7yrrDzGv2A5Yuuwkf7X1EnRCK+3ZayFRzzrvkXz0bjvsBrkE8PF7eV4KQ4L5q4L2d+u5nkIVNu7adiYa5c7vdo/MVnU3l2g2WiTpQWdWOhRAcdNFz4q7tUAyZFwgl20Db9QGLiHC+Mk6MdY4klS0SlWowxIn05foD8oDntsCLMDIPOqA0bndUmXQVhSHJcnrWMqcawW8T5idEo4ow==" Feb 18 17:29:21 volumio go-librespot[27900]: time="2026-02-18T17:29:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 17:29:21 volumio go-librespot[27900]: time="2026-02-18T17:29:21+07:00" level=debug msg="completed keyexchange" Feb 18 17:29:21 volumio go-librespot[27900]: time="2026-02-18T17:29:21+07:00" level=debug msg="completed challenge" Feb 18 17:29:22 volumio go-librespot[27900]: time="2026-02-18T17:29:22+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 17:29:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 17:29:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 17:29:22 volumio volumio[27563]: info: Initializing connection to go-librespot Websocket Feb 18 17:29:22 volumio volumio[27563]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 17:29:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 18 17:29:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:29:25 volumio volumio[27563]: info: Initializing connection to go-librespot Websocket Feb 18 17:29:25 volumio volumio[27563]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 17:29:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:29:25 volumio go-librespot[27908]: go-librespot daemon starting... Feb 18 17:29:25 volumio go-librespot[27909]: time="2026-02-18T17:29:25+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 17:29:25 volumio go-librespot[27909]: time="2026-02-18T17:29:25+07:00" level=debug msg="app state loaded" Feb 18 17:29:25 volumio go-librespot[27909]: time="2026-02-18T17:29:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 17:29:25 volumio go-librespot[27909]: time="2026-02-18T17:29:25+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 17:29:25 volumio go-librespot[27909]: time="2026-02-18T17:29:25+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 17:29:25 volumio go-librespot[27909]: time="2026-02-18T17:29:25+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 17:29:25 volumio go-librespot[27909]: time="2026-02-18T17:29:25+07:00" level=info msg="zeroconf server listening on port 35659" Feb 18 17:29:25 volumio volumio[27563]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 17:29:25 volumio volumio[27563]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 17:29:25 volumio volumio[27563]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 17:29:25 volumio volumio[27563]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 17:29:25 volumio volumio[27563]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 17:29:25 volumio volumio[27563]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 17:29:25 volumio volumio[27563]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 17:29:25 volumio volumio[27563]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 17:29:25 volumio volumio[27563]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 17:29:25 volumio volumio[27563]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 17:29:25 volumio volumio[27563]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 17:29:25 volumio volumio[27563]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 17:29:25 volumio volumio[27563]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 17:29:25 volumio volumio[27563]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 17:29:25 volumio volumio[27563]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 17:29:25 volumio volumio[27563]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 17:29:25 volumio volumio[27563]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 17:29:25 volumio volumio[27563]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 17:29:25 volumio volumio[27563]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 17:29:25 volumio volumio[27563]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 17:29:25 volumio volumio[27563]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 17:29:25 volumio volumio[27563]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 17:29:25 volumio volumio[27563]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 17:29:25 volumio volumio[27563]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 17:29:25 volumio volumio[27563]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 17:29:25 volumio volumio[27563]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 17:29:25 volumio volumio[27563]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 17:29:25 volumio volumio[27563]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 17:29:25 volumio volumio[27563]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 17:29:25 volumio volumio[27563]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 17:29:25 volumio volumio[27563]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 17:29:25 volumio volumio[27563]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 17:29:25 volumio volumio[27563]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 17:29:25 volumio volumio[27563]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 17:29:25 volumio volumio[27563]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 17:29:25 volumio volumio[27563]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 17:29:25 volumio go-librespot[27909]: time="2026-02-18T17:29:25+07:00" level=debug msg="obtained new client token: AAAaWKt6RylvrSrRTll73mjwdpWXisg4YtCFHIWQj4Ekph3XSFClpxhYxRmSV45AtZgVB5feZjhzf7XDaeY4U+t3d5Dnbn49GI1lT5bN/wnY1n9KWkH9u+44m8fLrgDkJYKEv1774a/mwFVHiglhCIGmdM5B+57GiUL+n8VmnvS7mgRlZg68t/n4S+TGGlcao5glmqfuakKDJurIp49fIpvSyqDIB9Jd8aJnE5IEDP5yOxiyrx3A7vjGDA==" Feb 18 17:29:26 volumio go-librespot[27909]: time="2026-02-18T17:29:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 17:29:26 volumio go-librespot[27909]: time="2026-02-18T17:29:26+07:00" level=debug msg="completed keyexchange" Feb 18 17:29:26 volumio go-librespot[27909]: time="2026-02-18T17:29:26+07:00" level=debug msg="completed challenge" Feb 18 17:29:26 volumio go-librespot[27909]: time="2026-02-18T17:29:26+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 17:29:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 17:29:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 17:29:27 volumio volumio[27563]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 17:29:27 volumio volumio[27563]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 17:29:27 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 17:29:27 volumio volumio[27563]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 17:29:27 volumio volumio[27563]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 17:29:27 volumio volumio[27563]: info: MyVolumio login type: Token Feb 18 17:29:27 volumio volumio[27563]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 17:29:27 volumio volumio[27563]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 17:29:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 18 17:29:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:29:29 volumio volumio[27563]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 17:29:29 volumio volumio[27563]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 17:29:29 volumio volumio[27563]: info: Streaming services startup Feb 18 17:29:29 volumio volumio[27563]: info: Starting Streaming Daemon Feb 18 17:29:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:29:29 volumio go-librespot[27930]: go-librespot daemon starting... Feb 18 17:29:29 volumio sudo[27933]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 17:29:29 volumio sudo[27933]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:29:29 volumio go-librespot[27932]: time="2026-02-18T17:29:29+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 17:29:29 volumio go-librespot[27932]: time="2026-02-18T17:29:29+07:00" level=debug msg="app state loaded" Feb 18 17:29:29 volumio go-librespot[27932]: time="2026-02-18T17:29:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 17:29:29 volumio volumio[27563]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 17:29:29 volumio sudo[27933]: pam_unix(sudo:session): session closed for user root Feb 18 17:29:29 volumio volumio[27563]: info: Initializing connection to go-librespot Websocket Feb 18 17:29:29 volumio volumio[27563]: error: Cannot start Volumio Streaming Daemon Feb 18 17:29:29 volumio volumio[27563]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 17:29:29 volumio volumio[27563]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 17:29:29 volumio go-librespot[27932]: time="2026-02-18T17:29:29+07:00" level=debug msg="new websocket client" Feb 18 17:29:29 volumio volumio[27563]: info: Connection to go-librespot Websocket established Feb 18 17:29:29 volumio go-librespot[27932]: time="2026-02-18T17:29:29+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 17:29:29 volumio go-librespot[27932]: time="2026-02-18T17:29:29+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 17:29:29 volumio go-librespot[27932]: time="2026-02-18T17:29:29+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 17:29:29 volumio go-librespot[27932]: time="2026-02-18T17:29:29+07:00" level=info msg="zeroconf server listening on port 36789" Feb 18 17:29:30 volumio go-librespot[27932]: time="2026-02-18T17:29:30+07:00" level=debug msg="obtained new client token: AAAu3f5E8l0snX3im3NOJE4dMPJJZBxzXdHQoV2eaScpuVcU8YsRuCNmnIeeEc7XNYIm56WS3abgkHfiCDUAe+oqAfRxCKCigMHrXUG7+pFbSeTmYGo3FxE52tKE6A4IMPWIslGIpehA5KjNC7fKmrS4wJQWr8GUuCwZT5jcdtmAd7do9P/yu34AFu3LsfHrGbVMXD91Sxol1aS0PXFXrBEWDsipnkdAvYt8y2u5RLN4+35ORasRJ5o=" Feb 18 17:29:30 volumio go-librespot[27932]: time="2026-02-18T17:29:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 17:29:30 volumio go-librespot[27932]: time="2026-02-18T17:29:30+07:00" level=debug msg="completed keyexchange" Feb 18 17:29:30 volumio go-librespot[27932]: time="2026-02-18T17:29:30+07:00" level=debug msg="completed challenge" Feb 18 17:29:30 volumio go-librespot[27932]: time="2026-02-18T17:29:30+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 17:29:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 17:29:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 17:29:30 volumio volumio[27563]: info: Connection to go-librespot Websocket closed Feb 18 17:29:30 volumio volumio[27563]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 18 17:29:31 volumio volumio[27563]: info: MyVolumio token set successfully Feb 18 17:29:31 volumio volumio[27563]: info: MYVOLUMIO: Adding device Feb 18 17:29:31 volumio volumio[27563]: info: MYVOLUMIO: Evaluating Server Feb 18 17:29:31 volumio volumio[27563]: info: MyVolumio status changed Feb 18 17:29:31 volumio volumio[27563]: info: Streaming services startup Feb 18 17:29:31 volumio volumio[27563]: info: Starting Streaming Daemon Feb 18 17:29:31 volumio volumio[27563]: info: Removing browser output: myVolumio user plan is not superstar Feb 18 17:29:31 volumio volumio[27563]: info: Removing audio output: Feb 18 17:29:31 volumio volumio[27563]: info: Stoppping Tunnel 1 Feb 18 17:29:31 volumio sudo[27967]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 17:29:31 volumio sudo[27967]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:29:32 volumio sudo[27967]: pam_unix(sudo:session): session closed for user root Feb 18 17:29:32 volumio sudo[27970]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 18 17:29:32 volumio volumio[27563]: error: Cannot start Volumio Streaming Daemon Feb 18 17:29:32 volumio volumio[27563]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 17:29:32 volumio volumio[27563]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 17:29:32 volumio sudo[27970]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:29:32 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 17:29:32 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 17:29:32 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 17:29:32 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 17:29:32 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 17:29:32 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 17:29:32 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 17:29:32 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 17:29:32 volumio sudo[27970]: pam_unix(sudo:session): session closed for user root Feb 18 17:29:32 volumio volumio[27563]: info: Remote SSH Stopped Feb 18 17:29:32 volumio volumio[27563]: info: Getting Spotify volume Feb 18 17:29:32 volumio volumio[27563]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 17:29:32 volumio volumio[27563]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 17:29:32 volumio volumio[27563]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 18 17:29:32 volumio volumio[27563]: errno: -111, Feb 18 17:29:32 volumio volumio[27563]: code: 'ECONNREFUSED', Feb 18 17:29:32 volumio volumio[27563]: syscall: 'connect', Feb 18 17:29:32 volumio volumio[27563]: address: '127.0.0.1', Feb 18 17:29:32 volumio volumio[27563]: port: 9879, Feb 18 17:29:32 volumio volumio[27563]: response: undefined Feb 18 17:29:32 volumio volumio[27563]: } Feb 18 17:29:32 volumio volumio[27563]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 17:29:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 18 17:29:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:29:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 17:29:33 volumio go-librespot[27984]: go-librespot daemon starting... Feb 18 17:29:33 volumio go-librespot[27985]: time="2026-02-18T17:29:33+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 17:29:33 volumio go-librespot[27985]: time="2026-02-18T17:29:33+07:00" level=debug msg="app state loaded" Feb 18 17:29:33 volumio go-librespot[27985]: time="2026-02-18T17:29:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 17:29:34 volumio go-librespot[27985]: time="2026-02-18T17:29:34+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 17:29:34 volumio go-librespot[27985]: time="2026-02-18T17:29:34+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 17:29:34 volumio go-librespot[27985]: time="2026-02-18T17:29:34+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 17:29:34 volumio sudo[27994]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 17:28' Feb 18 17:29:34 volumio sudo[27994]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 17:29:34 volumio go-librespot[27985]: time="2026-02-18T17:29:34+07:00" level=info msg="zeroconf server listening on port 34189" Feb 18 17:29:34 volumio go-librespot[27985]: time="2026-02-18T17:29:34+07:00" level=debug msg="obtained new client token: AAC6r3i7OloTjGbbbEyYWDIbFkU5AiM75omDkw+j+o5q7wdn0b5rSrr7fE1nGRsSRzBPIXLFZzsH2ufC0Gj6YhkwUV92MckN5lR31OmQxIG5eyxXJr9zLwxll+ZqEVuEviNaLkRa2LOJTW0uh5N3+4zh9HHfdonXC2kboWLTd93hZGuHdbgWQXJeDtIDNK38UVux8zOboV4BdvlQjT7hrAG+Z+pipzHHdHlqLrVsjHAItgPnxC3xg5dOmA==" Feb 18 17:29:34 volumio go-librespot[27985]: time="2026-02-18T17:29:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" 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"