Feb 17 05:36:00 volumio go-librespot[24026]: time="2026-02-17T05:36:00+07:00" level=debug msg="obtained new client token: AABbLcvJHBFiENaZuCKjtVtWVd2ALagXNmM+lZUA4slWShZTOVeaQQKqZwqTF4CaNwDQXN0YsNZ2W5F4wewxjQTarKiXUDxpgWEJVhsis56s8zPXmb4JRWn9lo4TmlFr9JxHTOqqmkN/ZpEKCUyzUez0je3fv5HkAy5G8ElR71yUxs8Ka1OJvpj8siHWkQd4DG92MEFAmulpaU/U/quYEEmsSXwGBQXZd9TGnCjuqg4EvHWUz4eb3pE=" Feb 17 05:36:00 volumio go-librespot[24026]: time="2026-02-17T05:36:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 05:36:00 volumio go-librespot[24026]: time="2026-02-17T05:36:00+07:00" level=debug msg="completed keyexchange" Feb 17 05:36:00 volumio go-librespot[24026]: time="2026-02-17T05:36:00+07:00" level=debug msg="completed challenge" Feb 17 05:36:00 volumio go-librespot[24026]: time="2026-02-17T05:36:00+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 05:36:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 05:36:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 05:36:00 volumio sudo[24052]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 05:35' Feb 17 05:36:00 volumio sudo[24052]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:36:00 volumio sudo[24052]: pam_unix(sudo:session): session closed for user root Feb 17 05:36:00 volumio volumio-remote-updater[25144]: [2026-02-17 05:36:00] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 17 05:36:00 volumio volumio-remote-updater[25144]: [2026-02-17 05:36:00] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 17 05:36:00 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 17 05:36:00 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 17 05:36:00 volumio systemd[1]: volumio.service: Consumed 49.576s CPU time. Feb 17 05:36:00 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 05:36:00 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 05:36:00 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 19927. Feb 17 05:36:00 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 05:36:00 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 17 05:36:00 volumio systemd[1]: volumio.service: Consumed 49.576s CPU time. Feb 17 05:36:01 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 17 05:36:01 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 05:36:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 17 05:36:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:36:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:36:03 volumio go-librespot[24079]: go-librespot daemon starting... Feb 17 05:36:03 volumio go-librespot[24080]: time="2026-02-17T05:36:03+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 05:36:03 volumio go-librespot[24080]: time="2026-02-17T05:36:03+07:00" level=debug msg="app state loaded" Feb 17 05:36:03 volumio go-librespot[24080]: time="2026-02-17T05:36:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 05:36:04 volumio go-librespot[24080]: time="2026-02-17T05:36:04+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 05:36:04 volumio go-librespot[24080]: time="2026-02-17T05:36:04+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 05:36:04 volumio go-librespot[24080]: time="2026-02-17T05:36:04+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 05:36:04 volumio go-librespot[24080]: time="2026-02-17T05:36:04+07:00" level=info msg="zeroconf server listening on port 33359" Feb 17 05:36:04 volumio go-librespot[24080]: time="2026-02-17T05:36:04+07:00" level=debug msg="obtained new client token: AAC1V8iNNG7uzgvOD7jG+f4bpBPkdSRBxtOVwZhs2Qnh7O2WbUpigCpfgyNGFz5slBc2WCy7Z4G+SAhzqfJ1RLVRiGEvO5IfOpDc9oADU07DRERCjO35wSpxiUicWypBLrn1kUtS9fEC7eFbII4eI4ydJ/ohAi6HqigZ6BG3GQFc02qMimjzZ4s76rQlwCoPQ7LmyB4sO0XLMe+++hFQPDCabsIiqjdr0uTQKhaGNq+PKoWSTQpPcDQ0hA==" Feb 17 05:36:04 volumio go-librespot[24080]: time="2026-02-17T05:36:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 05:36:04 volumio volumio[24064]: info: ------------------------------------------- Feb 17 05:36:04 volumio volumio[24064]: info: ----- Volumio3 ---- Feb 17 05:36:04 volumio volumio[24064]: info: ------------------------------------------- Feb 17 05:36:04 volumio volumio[24064]: info: ----- System startup ---- Feb 17 05:36:04 volumio volumio[24064]: info: ------------------------------------------- Feb 17 05:36:04 volumio go-librespot[24080]: time="2026-02-17T05:36:04+07:00" level=debug msg="completed keyexchange" Feb 17 05:36:04 volumio go-librespot[24080]: time="2026-02-17T05:36:04+07:00" level=debug msg="completed challenge" Feb 17 05:36:04 volumio go-librespot[24080]: time="2026-02-17T05:36:04+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 05:36:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 05:36:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 05:36:05 volumio volumio-remote-updater[25144]: [2026-02-17 05:36:05] [connect] Successful connection Feb 17 05:36:06 volumio volumio[24064]: info: MYVOLUMIO Environment detected Feb 17 05:36:06 volumio volumio[24064]: info: Plugin folders cleanup Feb 17 05:36:06 volumio volumio[24064]: info: Scanning into folder /volumio/app/plugins/ Feb 17 05:36:06 volumio volumio[24064]: info: Scanning category audio_interface Feb 17 05:36:06 volumio volumio[24064]: info: Scanning category miscellanea Feb 17 05:36:06 volumio volumio[24064]: info: Scanning category music_service Feb 17 05:36:06 volumio volumio[24064]: info: Scanning category plugins.json Feb 17 05:36:06 volumio volumio[24064]: info: Scanning category system_controller Feb 17 05:36:06 volumio volumio[24064]: info: Scanning category user_interface Feb 17 05:36:06 volumio volumio[24064]: info: Scanning into folder /data/plugins/ Feb 17 05:36:06 volumio volumio[24064]: info: Scanning category music_service Feb 17 05:36:06 volumio volumio[24064]: info: Plugin folders cleanup completed Feb 17 05:36:06 volumio volumio[24064]: info: ------------------------------------------- Feb 17 05:36:06 volumio volumio[24064]: info: ----- Core plugins startup ---- Feb 17 05:36:06 volumio volumio[24064]: info: ------------------------------------------- Feb 17 05:36:06 volumio volumio[24064]: info: Loading plugins from folder /volumio/app/plugins/ Feb 17 05:36:06 volumio volumio[24064]: info: Adding plugin upnp to MyMusic Plugins Feb 17 05:36:06 volumio volumio[24064]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 17 05:36:06 volumio volumio[24064]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 17 05:36:06 volumio volumio[24064]: info: Loading plugins from folder /data/plugins/ Feb 17 05:36:06 volumio volumio[24064]: info: Loading plugin "system"... Feb 17 05:36:06 volumio volumio[24064]: info: Loading plugin "appearance"... Feb 17 05:36:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 17 05:36:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:36:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:36:07 volumio go-librespot[24099]: go-librespot daemon starting... Feb 17 05:36:07 volumio go-librespot[24100]: time="2026-02-17T05:36:07+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 05:36:07 volumio go-librespot[24100]: time="2026-02-17T05:36:07+07:00" level=debug msg="app state loaded" Feb 17 05:36:07 volumio go-librespot[24100]: time="2026-02-17T05:36:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 05:36:08 volumio volumio[24064]: info: Loading plugin "network"... Feb 17 05:36:08 volumio volumio[24064]: info: Refreshing Cached IP Addresses Feb 17 05:36:08 volumio sudo[24107]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 05:36:08 volumio sudo[24107]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:36:08 volumio sudo[24107]: pam_unix(sudo:session): session closed for user root Feb 17 05:36:08 volumio sudo[24109]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 05:36:08 volumio sudo[24109]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:36:08 volumio volumio[24064]: info: Loading plugin "services"... Feb 17 05:36:08 volumio volumio[24064]: info: Loading plugin "alsa_controller"... Feb 17 05:36:08 volumio sudo[24109]: pam_unix(sudo:session): session closed for user root Feb 17 05:36:08 volumio sudo[24117]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 17 05:36:08 volumio sudo[24117]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:36:08 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 05:36:08 volumio volumio[24064]: info: Loading plugin "wizard"... Feb 17 05:36:08 volumio volumio[24064]: info: Loading plugin "networkfs"... Feb 17 05:36:08 volumio volumio[24064]: info: Starting Udev Watcher for removable devices Feb 17 05:36:08 volumio go-librespot[24100]: time="2026-02-17T05:36:08+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 05:36:08 volumio go-librespot[24100]: time="2026-02-17T05:36:08+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 05:36:08 volumio go-librespot[24100]: time="2026-02-17T05:36:08+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 05:36:08 volumio volumio[24064]: info: Ignoring mount for partition: boot Feb 17 05:36:08 volumio volumio[24064]: info: Ignoring mount for partition: volumio Feb 17 05:36:08 volumio volumio[24064]: info: Ignoring mount for partition: volumio_data Feb 17 05:36:08 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 05:36:08 volumio volumio[24064]: info: Loading plugin "volumio_command_line_client"... Feb 17 05:36:08 volumio go-librespot[24100]: time="2026-02-17T05:36:08+07:00" level=info msg="zeroconf server listening on port 37811" Feb 17 05:36:08 volumio volumio[24064]: info: Loading plugin "upnp"... Feb 17 05:36:08 volumio volumio[24064]: info: [1771281368566] Starting Upmpd Daemon Feb 17 05:36:08 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 05:36:08 volumio volumio[24064]: info: Loading plugin "my_music"... Feb 17 05:36:08 volumio volumio[24064]: info: Loading plugin "mpd"... Feb 17 05:36:08 volumio go-librespot[24100]: time="2026-02-17T05:36:08+07:00" level=debug msg="obtained new client token: AADmrdSHzm/BkU1VZqIEJRt7ANEEqhE6NlyqTt+M70avLUWQpg4vt3Yi3ROFW9Koi7GuIfQwX2Q8P0GGhQkOj4wVrpGnxoSpx01xSNquBbGTYGZoDsdLHl2snfNbs2iePS4E9dqE5/iWeiQAwiswVSkVrgBRcPmrbHPQlhYrgFjzVgCA2eos5fRBJuL0ozoNau9uxC+ijFtCCRfb4Tlm0imcYFocpGiUueD4TxIWDjgQtXrFr2vYGCnn7A==" Feb 17 05:36:08 volumio go-librespot[24100]: time="2026-02-17T05:36:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 05:36:08 volumio go-librespot[24100]: time="2026-02-17T05:36:08+07:00" level=debug msg="completed keyexchange" Feb 17 05:36:08 volumio go-librespot[24100]: time="2026-02-17T05:36:08+07:00" level=debug msg="completed challenge" Feb 17 05:36:09 volumio go-librespot[24100]: time="2026-02-17T05:36:09+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 05:36:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 05:36:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 05:36:09 volumio volumio[24064]: info: Loading plugin "upnp_browser"... Feb 17 05:36:11 volumio sudo[24117]: pam_unix(sudo:session): session closed for user root Feb 17 05:36:12 volumio volumio[24064]: info: Starting UPNP Browser Feb 17 05:36:12 volumio volumio[24064]: info: Loading plugin "alarm-clock"... Feb 17 05:36:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 17 05:36:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:36:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:36:12 volumio go-librespot[24142]: go-librespot daemon starting... Feb 17 05:36:12 volumio go-librespot[24144]: time="2026-02-17T05:36:12+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 05:36:12 volumio go-librespot[24144]: time="2026-02-17T05:36:12+07:00" level=debug msg="app state loaded" Feb 17 05:36:12 volumio go-librespot[24144]: time="2026-02-17T05:36:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 05:36:12 volumio volumio[24064]: info: Loading plugin "airplay_emulation"... Feb 17 05:36:12 volumio volumio[24064]: info: Starting Shairport Sync Feb 17 05:36:12 volumio volumio[24064]: info: Loading plugin "last_100"... Feb 17 05:36:12 volumio volumio[24064]: info: Loading plugin "webradio"... Feb 17 05:36:12 volumio volumio[24064]: info: Loading plugin "i2s_dacs"... Feb 17 05:36:12 volumio volumio[24064]: info: Loading plugin "volumiodiscovery"... Feb 17 05:36:12 volumio volumio[24064]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 05:36:12 volumio volumio[24064]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 05:36:12 volumio volumio[24064]: *** WARNING *** For more information see Feb 17 05:36:12 volumio volumio[24064]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 05:36:12 volumio volumio[24064]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 05:36:12 volumio volumio[24064]: *** WARNING *** For more information see Feb 17 05:36:12 volumio node[24064]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 05:36:12 volumio node[24064]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 05:36:12 volumio node[24064]: *** WARNING *** For more information see Feb 17 05:36:12 volumio node[24064]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 05:36:12 volumio node[24064]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 05:36:12 volumio node[24064]: *** WARNING *** For more information see Feb 17 05:36:12 volumio volumio[24064]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 17 05:36:12 volumio volumio[24064]: info: Discovery: Started advertising with name: Volumio Feb 17 05:36:12 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 05:36:12 volumio volumio[24064]: info: Loading plugin "spop"... Feb 17 05:36:13 volumio go-librespot[24144]: time="2026-02-17T05:36:13+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 05:36:13 volumio go-librespot[24144]: time="2026-02-17T05:36:13+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 05:36:13 volumio go-librespot[24144]: time="2026-02-17T05:36:13+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 05:36:13 volumio go-librespot[24144]: time="2026-02-17T05:36:13+07:00" level=info msg="zeroconf server listening on port 33283" Feb 17 05:36:13 volumio go-librespot[24144]: time="2026-02-17T05:36:13+07:00" level=debug msg="obtained new client token: AAAF5spHszYbrNcZ6n99rOiqZfSsZ8+0bN0dyFomJBx0ERqXzZ6+HDjqPanGgOyjQ+NfqxyWkHi44XoxaXkaS5rQRIrZnMoAjdxA0KZvhSUquY9JJI3aKDfAJE1AHW28nx9bg86UCOD7ASbWPfS9oU4aa19UXlTFE0RLK4uuCJvO8s9GU/IToRkzbf45fr0u2HbrVnEDJfjPniRXKqC4MpQcG1jecuwJ1LRx3aw++RuFAjiI01ZpNYmf7A==" Feb 17 05:36:13 volumio go-librespot[24144]: time="2026-02-17T05:36:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 05:36:13 volumio go-librespot[24144]: time="2026-02-17T05:36:13+07:00" level=debug msg="completed keyexchange" Feb 17 05:36:13 volumio go-librespot[24144]: time="2026-02-17T05:36:13+07:00" level=debug msg="completed challenge" Feb 17 05:36:13 volumio go-librespot[24144]: time="2026-02-17T05:36:13+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 05:36:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 05:36:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 05:36:14 volumio volumio[24064]: info: Loading plugin "ytcr"... Feb 17 05:36:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 17 05:36:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:36:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:36:16 volumio go-librespot[24153]: go-librespot daemon starting... Feb 17 05:36:16 volumio go-librespot[24154]: time="2026-02-17T05:36:16+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 05:36:16 volumio go-librespot[24154]: time="2026-02-17T05:36:16+07:00" level=debug msg="app state loaded" Feb 17 05:36:16 volumio go-librespot[24154]: time="2026-02-17T05:36:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 05:36:17 volumio volumio[24064]: info: Loading plugin "ytmusic"... Feb 17 05:36:17 volumio go-librespot[24154]: time="2026-02-17T05:36:17+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 05:36:17 volumio go-librespot[24154]: time="2026-02-17T05:36:17+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 17 05:36:17 volumio go-librespot[24154]: time="2026-02-17T05:36:17+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 17 05:36:17 volumio go-librespot[24154]: time="2026-02-17T05:36:17+07:00" level=info msg="zeroconf server listening on port 37253" Feb 17 05:36:17 volumio go-librespot[24154]: time="2026-02-17T05:36:17+07:00" level=debug msg="obtained new client token: AADEiQBf/72m68McS4y/2cH8wjQmZ+7G/Cv3KJRTH8jledR8hqzG9/hhFjYOs6e82/LmeyeGW52l7/KlzzWLiZ2hpM7AcMF3rY1LTKUtP2RL/1MNsbE/R7kFvOSVPfL2FzSSVmUV+GFmAyiTwMYAB8s/RGLLLr30erzBb8sDzGLi/YLcnBdQjJq0XyhAxZA+r0hodNmSPxHXXM8U56NKiy/qZYV9PbJ3lzT7/m6tprN1k5BxdUiPaVGlJw==" Feb 17 05:36:17 volumio go-librespot[24154]: time="2026-02-17T05:36:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 05:36:17 volumio go-librespot[24154]: time="2026-02-17T05:36:17+07:00" level=debug msg="completed keyexchange" Feb 17 05:36:17 volumio go-librespot[24154]: time="2026-02-17T05:36:17+07:00" level=debug msg="completed challenge" Feb 17 05:36:18 volumio go-librespot[24154]: time="2026-02-17T05:36: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 17 05:36:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 05:36:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 05:36:18 volumio volumio-remote-updater[25144]: [2026-02-17 05:36:18] [connect] Successful connection Feb 17 05:36:18 volumio volumio[24064]: info: Loading plugin "outputs"... Feb 17 05:36:18 volumio volumio[24064]: info: Loading plugin "albumart"... Feb 17 05:36:18 volumio volumio[24064]: info: Plugin example_plugin is not enabled Feb 17 05:36:18 volumio volumio[24064]: info: Loading plugin "inputs"... Feb 17 05:36:18 volumio volumio[24064]: info: Loading plugin "updater_comm"... Feb 17 05:36:18 volumio volumio[24064]: info: Plugin mpdemulation is not enabled Feb 17 05:36:18 volumio volumio[24064]: info: Loading plugin "rest_api"... Feb 17 05:36:18 volumio volumio[24064]: info: Loading plugin "websocket"... Feb 17 05:36:18 volumio volumio[24064]: info: Starting Socket.io Server version 1.7.4 Feb 17 05:36:18 volumio volumio[24064]: info: Loading plugin "RoonBridge"... Feb 17 05:36:19 volumio volumio[24064]: info: Applying required configuration parameters for plugin RoonBridge Feb 17 05:36:19 volumio volumio[24064]: info: Loading i18n strings for locale en Feb 17 05:36:19 volumio volumio[24064]: Updating browse sources language Feb 17 05:36:19 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 05:36:19 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 05:36:19 volumio volumio[24064]: info: CoreCommandRouter::initPlayerControls Feb 17 05:36:19 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:19 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:19 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:19 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:19 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:19 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:19 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:19 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:19 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 05:36:19 volumio volumio[24064]: Express server listening on port 3000 Feb 17 05:36:19 volumio volumio[24064]: [Metrics] WebUI: 15s 959.47ms Feb 17 05:36:19 volumio volumio[24064]: info: CoreStateMachine::resetVolumioState Feb 17 05:36:19 volumio volumio[24064]: info: CoreStateMachine::getcurrentVolume Feb 17 05:36:19 volumio volumio[24064]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 05:36:19 volumio volumio[24175]: Forking 3 albumart workers Feb 17 05:36:19 volumio sudo[24190]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 05:36:19 volumio sudo[24190]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:36:19 volumio sudo[24194]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 05:36:19 volumio sudo[24194]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:36:19 volumio sudo[24194]: pam_unix(sudo:session): session closed for user root Feb 17 05:36:19 volumio sudo[24190]: pam_unix(sudo:session): session closed for user root Feb 17 05:36:19 volumio volumio[24064]: info: Volumio Network Manager: Network status updated: 1 Feb 17 05:36:20 volumio volumio[24064]: info: VolumeController:: Volume=100 Mute =false Feb 17 05:36:20 volumio volumio[24064]: info: CoreStateMachine::pushState Feb 17 05:36:20 volumio volumio[24064]: info: CorePlayQueue::getTrack 0 Feb 17 05:36:20 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 05:36:20 volumio volumio[24064]: info: CoreCommandRouter::volumioPushState Feb 17 05:36:20 volumio volumio[24064]: info: CoreStateMachine::updateTrackBlock Feb 17 05:36:20 volumio volumio[24064]: info: CorePlayQueue::getTrackBlock Feb 17 05:36:20 volumio volumio[24064]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 05:36:20 volumio volumio-remote-updater[25144]: [2026-02-17 05:36:20] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771281378 101 Feb 17 05:36:20 volumio volumio[24064]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 17 05:36:20 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 05:36:20 volumio volumio[24064]: info: Reloading queue from file Feb 17 05:36:20 volumio volumio[24064]: info: CoreStateMachine::setRepeat null single undefined Feb 17 05:36:20 volumio volumio[24064]: info: CoreStateMachine::pushState Feb 17 05:36:20 volumio volumio[24064]: info: CorePlayQueue::getTrack 0 Feb 17 05:36:20 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 05:36:20 volumio volumio[24064]: info: CoreCommandRouter::volumioPushState Feb 17 05:36:20 volumio volumio[24064]: info: CoreStateMachine::setRandom null Feb 17 05:36:20 volumio volumio[24064]: info: CoreStateMachine::pushState Feb 17 05:36:20 volumio volumio[24064]: info: CorePlayQueue::getTrack 0 Feb 17 05:36:20 volumio volumio[24064]: info: CoreCommandRouter::volumioPushState Feb 17 05:36:20 volumio volumio[24064]: info: Setting Device type: Raspberry PI Feb 17 05:36:20 volumio volumio[24064]: info: Completed loading Core Plugins Feb 17 05:36:20 volumio volumio[24064]: info: Preparing to generate the ALSA configuration file Feb 17 05:36:20 volumio volumio[24064]: info: VolumeController:: Volume=100 Mute =false Feb 17 05:36:20 volumio volumio[24064]: info: CoreStateMachine::pushState Feb 17 05:36:20 volumio volumio[24064]: info: CorePlayQueue::getTrack 0 Feb 17 05:36:20 volumio volumio[24064]: info: CoreCommandRouter::volumioPushState Feb 17 05:36:20 volumio volumio[24064]: info: Asound.conf file unchanged, so no further update is needed Feb 17 05:36:20 volumio volumio[24064]: info: Output device has changed, restarting MPD Feb 17 05:36:20 volumio volumio[24064]: info: Output device has changed, restarting Shairport Sync Feb 17 05:36:20 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:20 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 05:36:20 volumio sudo[24235]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 17 05:36:20 volumio sudo[24235]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:36:20 volumio sudo[24237]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 05:36:20 volumio sudo[24237]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:36:20 volumio sudo[24239]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 05:36:20 volumio sudo[24239]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:36:20 volumio sudo[24237]: pam_unix(sudo:session): session closed for user root Feb 17 05:36:20 volumio volumio[24064]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 05:36:20 volumio volumio[24064]: info: ___________ START PLUGINS ___________ Feb 17 05:36:20 volumio volumio[24064]: info: ControllerMpd::onStart: Initializing MPD Feb 17 05:36:20 volumio volumio[24064]: info: Creating MPD Configuration file Feb 17 05:36:20 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 05:36:20 volumio volumio[24064]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 05:36:20 volumio volumio[24064]: info: [1771281380869] CoreMusicLibrary::Adding element Media Servers Feb 17 05:36:20 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 05:36:20 volumio volumio[24064]: info: UPNP Browser: Client initialized successfully Feb 17 05:36:20 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 17 05:36:20 volumio sudo[24248]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 05:36:20 volumio sudo[24248]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:36:20 volumio sudo[24235]: pam_unix(sudo:session): session closed for user root Feb 17 05:36:20 volumio sudo[24248]: pam_unix(sudo:session): session closed for user root Feb 17 05:36:21 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:21 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 05:36:21 volumio sudo[24250]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 05:36:21 volumio sudo[24250]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:36:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Feb 17 05:36:21 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 05:36:21 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 05:36:21 volumio systemd[1]: mpd.service: Consumed 7.178s CPU time. Feb 17 05:36:21 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 05:36:21 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 05:36:21 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 05:36:21 volumio volumio[24064]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 05:36:21 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:21 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 05:36:21 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 05:36:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:36:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:36:21 volumio go-librespot[24262]: go-librespot daemon starting... Feb 17 05:36:21 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 05:36:21 volumio volumio[24064]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 05:36:21 volumio volumio[24064]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 05:36:21 volumio volumio[24064]: info: [1771281381238] CoreMusicLibrary::Adding element Last_100 Feb 17 05:36:21 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 05:36:21 volumio volumio[24064]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 05:36:21 volumio volumio[24064]: info: [1771281381263] CoreMusicLibrary::Adding element Webradio Feb 17 05:36:21 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 05:36:21 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 05:36:21 volumio go-librespot[24264]: time="2026-02-17T05:36:21+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 05:36:21 volumio go-librespot[24264]: time="2026-02-17T05:36:21+07:00" level=debug msg="app state loaded" Feb 17 05:36:21 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 05:36:21 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 05:36:21 volumio go-librespot[24264]: time="2026-02-17T05:36:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 05:36:21 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 05:36:21 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 05:36:21 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 05:36:21 volumio volumio[24064]: info: Initializing BBC Radios Feb 17 05:36:21 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 05:36:21 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 05:36:21 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 05:36:21 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 05:36:21 volumio volumio[24064]: info: Creating Spotify config file Feb 17 05:36:21 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:21 volumio sudo[24275]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 17 05:36:21 volumio sudo[24275]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 17 05:36:21 volumio sudo[24275]: pam_unix(sudo:session): session closed for user root Feb 17 05:36:22 volumio go-librespot[24264]: time="2026-02-17T05:36: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 17 05:36:22 volumio go-librespot[24264]: time="2026-02-17T05:36: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 17 05:36:22 volumio go-librespot[24264]: time="2026-02-17T05:36: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 17 05:36:22 volumio go-librespot[24264]: time="2026-02-17T05:36:22+07:00" level=info msg="zeroconf server listening on port 34897" Feb 17 05:36:22 volumio go-librespot[24264]: time="2026-02-17T05:36:22+07:00" level=debug msg="obtained new client token: AABTprH9hPYwsFddvjwfCsYftjdP/nEpPVakdMGECJe31Agycwg1lWcIbQfZH815JI8t9HFtvgZQLk1UWo++HD/fqZF/Y4SM6JH/uDhYfAwKCAITN+RjT8HTMGgzqRnpVksiXEoLAOmTSa/Gk3xEhkO3VF/hSBNWChZMTWqPOCRufCLLrBRDQDqgZFBh9z3XbQzLNiVZanf0ounHnO2wzEtdp7KDoYdaSqHif3vi+Dh2n+P3bDUEcuk=" Feb 17 05:36:22 volumio go-librespot[24264]: time="2026-02-17T05:36:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 05:36:22 volumio go-librespot[24264]: time="2026-02-17T05:36:22+07:00" level=debug msg="completed keyexchange" Feb 17 05:36:22 volumio go-librespot[24264]: time="2026-02-17T05:36:22+07:00" level=debug msg="completed challenge" Feb 17 05:36:22 volumio go-librespot[24264]: time="2026-02-17T05:36:22+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 05:36:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 05:36:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 05:36:23 volumio volumio[24064]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 05:36:23 volumio volumio[24064]: info: [1771281383009] CoreMusicLibrary::Adding element YouTube Music Feb 17 05:36:23 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 05:36:23 volumio volumio[24064]: Cannot find translation for source YouTube Music Feb 17 05:36:23 volumio volumio[24064]: info: Volumio Calling Home Feb 17 05:36:23 volumio sudo[24290]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 17 05:36:23 volumio sudo[24290]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:36:23 volumio volumio[24191]: Starting albumart workers Feb 17 05:36:23 volumio sudo[24290]: pam_unix(sudo:session): session closed for user root Feb 17 05:36:23 volumio volumio[24193]: Starting albumart workers Feb 17 05:36:23 volumio volumio[24195]: Starting albumart workers Feb 17 05:36:23 volumio volumio[24064]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 05:36:23 volumio volumio[24064]: info: Discovery: Found device Volumio Feb 17 05:36:23 volumio volumio[24064]: info: CoreCommandRouter::volumioGetState Feb 17 05:36:23 volumio volumio[24064]: info: CorePlayQueue::getTrack 0 Feb 17 05:36:23 volumio volumio[24064]: info: MPD Permissions set Feb 17 05:36:23 volumio volumio[24064]: info: MPD Permissions set Feb 17 05:36:23 volumio volumio[24064]: info: Upmpdcli Daemon Started Feb 17 05:36:23 volumio volumio[24064]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 05:36:23 volumio volumio[24064]: info: Discovery: Found device Volumio Feb 17 05:36:23 volumio volumio[24064]: info: CoreCommandRouter::volumioGetState Feb 17 05:36:23 volumio volumio[24064]: info: CorePlayQueue::getTrack 0 Feb 17 05:36:23 volumio volumio[24064]: info: Volumio called home Feb 17 05:36:23 volumio volumio[24064]: info: Spotify config file written Feb 17 05:36:24 volumio volumio[24064]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 17 05:36:24 volumio sudo[24296]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 17 05:36:24 volumio sudo[24296]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:36:24 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:24 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:24 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:24 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:24 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:24 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:24 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:24 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:36:24 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 05:36:24 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:24 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:24 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:24 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:24 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:24 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:24 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:24 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:24 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:36:24 volumio go-librespot[24303]: go-librespot daemon starting... Feb 17 05:36:24 volumio sudo[24296]: pam_unix(sudo:session): session closed for user root Feb 17 05:36:24 volumio go-librespot[24306]: time="2026-02-17T05:36:24+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 05:36:24 volumio go-librespot[24306]: time="2026-02-17T05:36:24+07:00" level=debug msg="app state loaded" Feb 17 05:36:24 volumio go-librespot[24306]: time="2026-02-17T05:36:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 05:36:24 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 05:36:24 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:24 volumio volumio[24064]: info: No need to fix Spotify hosts Feb 17 05:36:25 volumio go-librespot[24306]: time="2026-02-17T05:36: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 05:36:25 volumio go-librespot[24306]: time="2026-02-17T05:36:25+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 17 05:36:25 volumio go-librespot[24306]: time="2026-02-17T05:36:25+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 17 05:36:25 volumio go-librespot[24306]: time="2026-02-17T05:36:25+07:00" level=info msg="zeroconf server listening on port 45537" Feb 17 05:36:25 volumio go-librespot[24306]: time="2026-02-17T05:36:25+07:00" level=debug msg="obtained new client token: AAB7uo/uJqGQOiFh2AjMNeCn/nERY+W25Q56BPrGen8Od0rX8jRQL9uxTlJPEd/8cRJR9bBCHW9wdJppsufvnAwWfIaqi/vs0jf2F8+MV2zom3XsoXLflBhyZYbi9jx3oqYsoBcelVkkpqMqj+8t732bVszUqZQgbeSzU03iwcudDOIqRjEQ4D4Zx9Cig7T4OEEnjqsrIxmIH9MuEaxi8sFbZq8R2K89eNPM+k6+coUV0U+xPS2KbzMKzQ==" Feb 17 05:36:25 volumio go-librespot[24306]: time="2026-02-17T05:36:25+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 17 05:36:25 volumio go-librespot[24306]: time="2026-02-17T05:36:25+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Feb 17 05:36:25 volumio go-librespot[24306]: time="2026-02-17T05:36:25+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:80, retrying with a different AP" error="dial tcp 104.199.241.202:80: connect: connection refused" Feb 17 05:36:25 volumio volumio[24064]: info: Starting Shairport Sync Feb 17 05:36:25 volumio volumio[24064]: info: Starting Shairport Sync Feb 17 05:36:25 volumio volumio[24064]: info: Starting Shairport Sync Feb 17 05:36:25 volumio sudo[24336]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 05:36:25 volumio sudo[24336]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:36:26 volumio go-librespot[24306]: time="2026-02-17T05:36:26+07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 17 05:36:26 volumio sudo[24338]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 05:36:26 volumio sudo[24338]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:36:26 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 05:36:26 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 05:36:26 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 05:36:26 volumio systemd[1]: shairport-sync.service: Consumed 2.214s CPU time. Feb 17 05:36:26 volumio sudo[24341]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 05:36:26 volumio sudo[24341]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:36:26 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 05:36:26 volumio sudo[24336]: pam_unix(sudo:session): session closed for user root Feb 17 05:36:26 volumio volumio[24064]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 05:36:26 volumio volumio[24064]: SPOTIFY: BQAXX4PqSmGXwvWBD6RuMZhoKjY3cOwWFH77oKm6GZyc88MzekumSQtwJvnz3271tdjNeL1S2TYAiANyxbULBvKUltc8Gd2i_QQbUmytOCDQtreWH9Uv5WhIQ3EHaRwyhW127Lvc-uEnDYJ-zskOQyOxI1lP3_uGEb9eYHeBhpC1D7TKliB5uZ941sSJnN8w8KpmEVb7TB6KwMBHUY5T-MLqpgthmwodtX_Fj7cJUuuC010Luwq5PTvbcQAw6Yplj1jz9_4TL5IRI-iDVv9SLmAbW1LuLW3aglSSDMHlv0Vw8kb7vdgq0XEx Feb 17 05:36:26 volumio volumio[24064]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 05:36:26 volumio volumio[24064]: info: New Spotify access token = BQAXX4PqSmGXwvWBD6RuMZhoKjY3cOwWFH77oKm6GZyc88MzekumSQtwJvnz3271tdjNeL1S2TYAiANyxbULBvKUltc8Gd2i_QQbUmytOCDQtreWH9Uv5WhIQ3EHaRwyhW127Lvc-uEnDYJ-zskOQyOxI1lP3_uGEb9eYHeBhpC1D7TKliB5uZ941sSJnN8w8KpmEVb7TB6KwMBHUY5T-MLqpgthmwodtX_Fj7cJUuuC010Luwq5PTvbcQAw6Yplj1jz9_4TL5IRI-iDVv9SLmAbW1LuLW3aglSSDMHlv0Vw8kb7vdgq0XEx Feb 17 05:36:26 volumio volumio[24064]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 17 05:36:26 volumio go-librespot[24306]: time="2026-02-17T05:36:26+07:00" level=debug msg="completed keyexchange" Feb 17 05:36:26 volumio go-librespot[24306]: time="2026-02-17T05:36:26+07:00" level=debug msg="completed challenge" Feb 17 05:36:26 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 05:36:26 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 05:36:26 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 05:36:26 volumio volumio[24064]: info: Shairport-Sync Started Feb 17 05:36:26 volumio volumio[24064]: Error adding Membership: Error: addMembership EINVAL Feb 17 05:36:26 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 05:36:26 volumio sudo[24341]: pam_unix(sudo:session): session closed for user root Feb 17 05:36:26 volumio volumio[24064]: info: CoreCommandRouter::volumioGetState Feb 17 05:36:26 volumio volumio[24064]: info: CorePlayQueue::getTrack 0 Feb 17 05:36:26 volumio sudo[24338]: pam_unix(sudo:session): session closed for user root Feb 17 05:36:26 volumio volumio[24064]: info: Shairport-Sync Started Feb 17 05:36:26 volumio volumio[24064]: info: Shairport-Sync Started Feb 17 05:36:26 volumio go-librespot[24306]: time="2026-02-17T05:36:26+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 05:36:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 05:36:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 05:36:26 volumio volumio[24064]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 17 05:36:26 volumio volumio[24064]: info: Spotify Successfully logged in Feb 17 05:36:26 volumio volumio[24064]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 05:36:26 volumio volumio[24064]: info: [1771281386866] CoreMusicLibrary::Adding element Spotify Feb 17 05:36:26 volumio volumio[24064]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 05:36:26 volumio volumio[24064]: Cannot find translation for source YouTube Music Feb 17 05:36:26 volumio volumio[24064]: Cannot find translation for source Spotify Feb 17 05:36:27 volumio volumio[24064]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 17 05:36:27 volumio volumio[24064]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 05:36:27 volumio volumio[24064]: info: VolumeController:: Volume=100 Mute =false Feb 17 05:36:27 volumio volumio[24064]: info: CoreCommandRouter::volumioGetState Feb 17 05:36:27 volumio volumio[24064]: info: CorePlayQueue::getTrack 0 Feb 17 05:36:27 volumio volumio[24064]: info: CoreStateMachine::pushState Feb 17 05:36:27 volumio volumio[24064]: info: CorePlayQueue::getTrack 0 Feb 17 05:36:27 volumio volumio[24064]: info: CoreCommandRouter::volumioPushState Feb 17 05:36:28 volumio volumio[24064]: info: go-librespot daemon successfully initialized Feb 17 05:36:29 volumio mpd[24288]: 2026-02-17T05:36:29 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 17 05:36:29 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 17 05:36:29 volumio sudo[24239]: pam_unix(sudo:session): session closed for user root Feb 17 05:36:29 volumio sudo[24250]: pam_unix(sudo:session): session closed for user root Feb 17 05:36:29 volumio volumio[24064]: error: MPD error: The expression evaluated to a falsy value: Feb 17 05:36:29 volumio volumio[24064]: assert.ok(self.idling) Feb 17 05:36:29 volumio volumio[24064]: error: The expression evaluated to a falsy value: Feb 17 05:36:29 volumio volumio[24064]: assert.ok(self.idling) Feb 17 05:36:29 volumio volumio[24064]: error: updateQueue error: null Feb 17 05:36:29 volumio volumio[24064]: info: MPD running with PID24288 Feb 17 05:36:29 volumio volumio[24064]: ,establishing connection Feb 17 05:36:29 volumio volumio[24064]: info: Completed starting Core Plugins Feb 17 05:36:29 volumio volumio[24064]: info: ------------------------------------------- Feb 17 05:36:29 volumio volumio[24064]: info: ----- MyVolumio plugins startup ---- Feb 17 05:36:29 volumio volumio[24064]: info: ------------------------------------------- Feb 17 05:36:29 volumio volumio[24064]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 17 05:36:29 volumio volumio[24064]: error: updateQueue error: null Feb 17 05:36:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Feb 17 05:36:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:36:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:36:29 volumio go-librespot[24393]: go-librespot daemon starting... Feb 17 05:36:29 volumio go-librespot[24394]: time="2026-02-17T05:36:29+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 05:36:29 volumio go-librespot[24394]: time="2026-02-17T05:36:29+07:00" level=debug msg="app state loaded" Feb 17 05:36:29 volumio go-librespot[24394]: time="2026-02-17T05:36:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 05:36:30 volumio go-librespot[24394]: time="2026-02-17T05:36:30+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 05:36:30 volumio go-librespot[24394]: time="2026-02-17T05:36:30+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 05:36:30 volumio go-librespot[24394]: time="2026-02-17T05:36:30+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 05:36:30 volumio go-librespot[24394]: time="2026-02-17T05:36:30+07:00" level=info msg="zeroconf server listening on port 35279" Feb 17 05:36:30 volumio go-librespot[24394]: time="2026-02-17T05:36:30+07:00" level=debug msg="obtained new client token: AABOSgE4qIct8F/V0z3TqiYVdyvaHGbizMYkvRMX4AnWpMLMLICWmxaGIhmKliluFMN1/uJhJEUnHfa7VkeShXzuAWdAcM7kyUu73AbWavccGrZgOQbRd+MjU4YEzlL7PnL+pfj2AzxfNw1WcGfiaKBWIM0N3aWMCu4pwKbPGjhLzSJmzaehM5NII7HMIaq7lDUkwdvXc/QM//cSN3A5p6r1iUJsZXhRyZDu9bF2NK5n0d5I2fB+v32UPw==" Feb 17 05:36:30 volumio go-librespot[24394]: time="2026-02-17T05:36:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 05:36:30 volumio go-librespot[24394]: time="2026-02-17T05:36:30+07:00" level=debug msg="completed keyexchange" Feb 17 05:36:30 volumio go-librespot[24394]: time="2026-02-17T05:36:30+07:00" level=debug msg="completed challenge" Feb 17 05:36:30 volumio go-librespot[24394]: time="2026-02-17T05:36:30+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 05:36:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 05:36:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 05:36:31 volumio volumio[24064]: info: Initializing connection to go-librespot Websocket Feb 17 05:36:31 volumio volumio[24064]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 05:36:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Feb 17 05:36:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:36:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:36:34 volumio go-librespot[24404]: go-librespot daemon starting... Feb 17 05:36:34 volumio volumio[24064]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 17 05:36:34 volumio go-librespot[24405]: time="2026-02-17T05:36:34+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 05:36:34 volumio go-librespot[24405]: time="2026-02-17T05:36:34+07:00" level=debug msg="app state loaded" Feb 17 05:36:34 volumio go-librespot[24405]: time="2026-02-17T05:36:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 05:36:34 volumio go-librespot[24405]: time="2026-02-17T05:36: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 05:36:34 volumio go-librespot[24405]: time="2026-02-17T05:36:34+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 05:36:34 volumio go-librespot[24405]: time="2026-02-17T05:36:34+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 05:36:34 volumio go-librespot[24405]: time="2026-02-17T05:36:34+07:00" level=info msg="zeroconf server listening on port 44581" Feb 17 05:36:34 volumio go-librespot[24405]: time="2026-02-17T05:36:34+07:00" level=debug msg="obtained new client token: AADQ3x2TH8aIjSE8tt++2DOqIh/NkrnzFDiB39lvXnIQBKOve0FDBCeWGw9qMiJNaN9x9h2ZYw6z2MXoVc92KZ++7UH7kDkYEOUEC8Jisxuxb1dav4orPZkkfKnugCC2Fnwp0AAZNjDEWFgR8jEJVZw7jrbU1xDxZ8yJGHPC9BIZH7q5FIVeolMQga5Qp4Sx3dyvxoYyxJRy60bUa/i4setfOrguaCAWQlsH3XUiI1bu9fKUPU2091WmBA==" Feb 17 05:36:34 volumio volumio[24064]: info: Initializing connection to go-librespot Websocket Feb 17 05:36:34 volumio go-librespot[24405]: time="2026-02-17T05:36:34+07:00" level=debug msg="new websocket client" Feb 17 05:36:34 volumio volumio[24064]: info: Connection to go-librespot Websocket established Feb 17 05:36:34 volumio go-librespot[24405]: time="2026-02-17T05:36:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 05:36:35 volumio go-librespot[24405]: time="2026-02-17T05:36:35+07:00" level=debug msg="completed keyexchange" Feb 17 05:36:35 volumio go-librespot[24405]: time="2026-02-17T05:36:35+07:00" level=debug msg="completed challenge" Feb 17 05:36:35 volumio go-librespot[24405]: time="2026-02-17T05:36:35+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 05:36:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 05:36:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 05:36:35 volumio volumio[24064]: info: Connection to go-librespot Websocket closed Feb 17 05:36:37 volumio volumio[24064]: info: Getting Spotify volume Feb 17 05:36:37 volumio volumio[24064]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 05:36:37 volumio volumio[24064]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 05:36:37 volumio volumio[24064]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 17 05:36:37 volumio volumio[24064]: errno: -111, Feb 17 05:36:37 volumio volumio[24064]: code: 'ECONNREFUSED', Feb 17 05:36:37 volumio volumio[24064]: syscall: 'connect', Feb 17 05:36:37 volumio volumio[24064]: address: '127.0.0.1', Feb 17 05:36:37 volumio volumio[24064]: port: 9879, Feb 17 05:36:37 volumio volumio[24064]: response: undefined Feb 17 05:36:37 volumio volumio[24064]: } Feb 17 05:36:37 volumio volumio[24064]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 05:36:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Feb 17 05:36:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:36:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:36:38 volumio go-librespot[24424]: go-librespot daemon starting... Feb 17 05:36:38 volumio go-librespot[24425]: time="2026-02-17T05:36:38+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 05:36:38 volumio go-librespot[24425]: time="2026-02-17T05:36:38+07:00" level=debug msg="app state loaded" Feb 17 05:36:38 volumio go-librespot[24425]: time="2026-02-17T05:36:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 05:36:38 volumio go-librespot[24425]: time="2026-02-17T05:36:38+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 05:36:38 volumio go-librespot[24425]: time="2026-02-17T05:36:38+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 05:36:38 volumio go-librespot[24425]: time="2026-02-17T05:36:38+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 05:36:38 volumio go-librespot[24425]: time="2026-02-17T05:36:38+07:00" level=info msg="zeroconf server listening on port 44643" Feb 17 05:36:39 volumio go-librespot[24425]: time="2026-02-17T05:36:39+07:00" level=debug msg="obtained new client token: AAA5Nt8DVDUmPQrVox/BFLpgIzkr37FoimJJ4/L1cth5pF2um3ZXYDmXg995/g0/rjfVyPzSHw8e//Jz+0z9+Vt8suG6mPTuQhwIlcsi0luQrzhH6C3La5Aq1x/bbcQAPF2sESk0vNQ+rvWMENiJ1v4lbcRdkImENRNF0z6HCDxxw9yovYPf1FTKi3T3d5dF66s9O0oDcTlg7a4K+Mt/r1UXNhshnbN5rgh9yvmxgiC7g1y+1nBC3/I=" Feb 17 05:36:39 volumio go-librespot[24425]: time="2026-02-17T05:36:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 05:36:39 volumio go-librespot[24425]: time="2026-02-17T05:36:39+07:00" level=debug msg="completed keyexchange" Feb 17 05:36:39 volumio go-librespot[24425]: time="2026-02-17T05:36:39+07:00" level=debug msg="completed challenge" Feb 17 05:36:39 volumio go-librespot[24425]: time="2026-02-17T05:36:39+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 05:36:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 05:36:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 05:36:39 volumio sudo[24448]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 05:35' Feb 17 05:36:39 volumio sudo[24448]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:36:39 volumio sudo[24448]: pam_unix(sudo:session): session closed for user root Feb 17 05:36:39 volumio volumio-remote-updater[25144]: [2026-02-17 05:36:39] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 17 05:36:39 volumio volumio-remote-updater[25144]: [2026-02-17 05:36:39] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 17 05:36:39 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 17 05:36:39 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 17 05:36:39 volumio systemd[1]: volumio.service: Consumed 49.248s CPU time. Feb 17 05:36:40 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 05:36:40 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 05:36:40 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 19928. Feb 17 05:36:40 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 05:36:40 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 17 05:36:40 volumio systemd[1]: volumio.service: Consumed 49.248s CPU time. Feb 17 05:36:40 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 17 05:36:40 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 05:36:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Feb 17 05:36:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:36:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:36:42 volumio go-librespot[24475]: go-librespot daemon starting... Feb 17 05:36:42 volumio go-librespot[24476]: time="2026-02-17T05:36:42+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 05:36:42 volumio go-librespot[24476]: time="2026-02-17T05:36:42+07:00" level=debug msg="app state loaded" Feb 17 05:36:42 volumio go-librespot[24476]: time="2026-02-17T05:36:42+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 05:36:43 volumio go-librespot[24476]: time="2026-02-17T05:36:43+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 05:36:43 volumio go-librespot[24476]: time="2026-02-17T05:36:43+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 05:36:43 volumio go-librespot[24476]: time="2026-02-17T05:36:43+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 05:36:43 volumio go-librespot[24476]: time="2026-02-17T05:36:43+07:00" level=info msg="zeroconf server listening on port 42883" Feb 17 05:36:43 volumio go-librespot[24476]: time="2026-02-17T05:36:43+07:00" level=debug msg="obtained new client token: AAB04bYn/fe7hUGNoT3Dloc7cCb2bZyvfBosTk7ToE8RxIW3pMEWYcG3RnO8a2iXHPoRg0udmWMmWMZFRJVBQ4ESW7krxpmwTSTdgOWfWiHA6IFMYRF5hBKIvnu/WFDqAkz49kZhUnpElUDF0uHz4rJcYQjQ8463DcrLQrJQP96N8vsxHcmZUtOJUZ8IILjCsxXjCWSULG0DBYyGHmS2CwBrMqQgz4pRZCH49qolkg/UDdz8pDdgwxTv0w==" Feb 17 05:36:43 volumio go-librespot[24476]: time="2026-02-17T05:36:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 05:36:43 volumio go-librespot[24476]: time="2026-02-17T05:36:43+07:00" level=debug msg="completed keyexchange" Feb 17 05:36:43 volumio go-librespot[24476]: time="2026-02-17T05:36:43+07:00" level=debug msg="completed challenge" Feb 17 05:36:43 volumio go-librespot[24476]: time="2026-02-17T05:36:43+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 05:36:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 05:36:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 05:36:43 volumio volumio[24460]: info: ------------------------------------------- Feb 17 05:36:43 volumio volumio[24460]: info: ----- Volumio3 ---- Feb 17 05:36:43 volumio volumio[24460]: info: ------------------------------------------- Feb 17 05:36:43 volumio volumio[24460]: info: ----- System startup ---- Feb 17 05:36:43 volumio volumio[24460]: info: ------------------------------------------- Feb 17 05:36:44 volumio volumio-remote-updater[25144]: [2026-02-17 05:36:44] [connect] Successful connection Feb 17 05:36:45 volumio volumio[24460]: info: MYVOLUMIO Environment detected Feb 17 05:36:45 volumio volumio[24460]: info: Plugin folders cleanup Feb 17 05:36:45 volumio volumio[24460]: info: Scanning into folder /volumio/app/plugins/ Feb 17 05:36:45 volumio volumio[24460]: info: Scanning category audio_interface Feb 17 05:36:45 volumio volumio[24460]: info: Scanning category miscellanea Feb 17 05:36:45 volumio volumio[24460]: info: Scanning category music_service Feb 17 05:36:45 volumio volumio[24460]: info: Scanning category plugins.json Feb 17 05:36:45 volumio volumio[24460]: info: Scanning category system_controller Feb 17 05:36:45 volumio volumio[24460]: info: Scanning category user_interface Feb 17 05:36:45 volumio volumio[24460]: info: Scanning into folder /data/plugins/ Feb 17 05:36:45 volumio volumio[24460]: info: Scanning category music_service Feb 17 05:36:45 volumio volumio[24460]: info: Plugin folders cleanup completed Feb 17 05:36:45 volumio volumio[24460]: info: ------------------------------------------- Feb 17 05:36:45 volumio volumio[24460]: info: ----- Core plugins startup ---- Feb 17 05:36:45 volumio volumio[24460]: info: ------------------------------------------- Feb 17 05:36:45 volumio volumio[24460]: info: Loading plugins from folder /volumio/app/plugins/ Feb 17 05:36:45 volumio volumio[24460]: info: Adding plugin upnp to MyMusic Plugins Feb 17 05:36:45 volumio volumio[24460]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 17 05:36:45 volumio volumio[24460]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 17 05:36:45 volumio volumio[24460]: info: Loading plugins from folder /data/plugins/ Feb 17 05:36:45 volumio volumio[24460]: info: Loading plugin "system"... Feb 17 05:36:45 volumio volumio[24460]: info: Loading plugin "appearance"... Feb 17 05:36:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Feb 17 05:36:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:36:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:36:46 volumio go-librespot[24496]: go-librespot daemon starting... Feb 17 05:36:46 volumio go-librespot[24497]: time="2026-02-17T05:36:46+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 05:36:46 volumio go-librespot[24497]: time="2026-02-17T05:36:46+07:00" level=debug msg="app state loaded" Feb 17 05:36:46 volumio go-librespot[24497]: time="2026-02-17T05:36:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 05:36:47 volumio volumio[24460]: info: Loading plugin "network"... Feb 17 05:36:47 volumio volumio[24460]: info: Refreshing Cached IP Addresses Feb 17 05:36:47 volumio sudo[24505]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 05:36:47 volumio sudo[24505]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:36:47 volumio sudo[24505]: pam_unix(sudo:session): session closed for user root Feb 17 05:36:47 volumio sudo[24507]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 05:36:47 volumio sudo[24507]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:36:47 volumio volumio[24460]: info: Loading plugin "services"... Feb 17 05:36:47 volumio volumio[24460]: info: Loading plugin "alsa_controller"... Feb 17 05:36:47 volumio sudo[24507]: pam_unix(sudo:session): session closed for user root Feb 17 05:36:47 volumio go-librespot[24497]: time="2026-02-17T05:36:47+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 05:36:47 volumio go-librespot[24497]: time="2026-02-17T05:36:47+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 05:36:47 volumio go-librespot[24497]: time="2026-02-17T05:36:47+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 05:36:47 volumio sudo[24515]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 17 05:36:47 volumio sudo[24515]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:36:47 volumio go-librespot[24497]: time="2026-02-17T05:36:47+07:00" level=info msg="zeroconf server listening on port 40929" Feb 17 05:36:47 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 05:36:47 volumio volumio[24460]: info: Loading plugin "wizard"... Feb 17 05:36:47 volumio volumio[24460]: info: Loading plugin "networkfs"... Feb 17 05:36:47 volumio volumio[24460]: info: Starting Udev Watcher for removable devices Feb 17 05:36:47 volumio go-librespot[24497]: time="2026-02-17T05:36:47+07:00" level=debug msg="obtained new client token: AADECdZHzGZNfYbvaq9o0GcdC6/5bWM8wr2V17yxxAFZyQCsJgR555wGwWCUw0Z5d/eAnp+il61SSzdytMhEkHRQ8776U3iqVF50A1db/XXg6oAThlvvfjuv1GphAY/vMEclelIk+mwVVZ+JrdUxqv+wNGrckCeDt39OBzz0aPswbhCV3lyUJ3wSb/slAXgjS5CE8lXALqK8BG5uwQ47RoYQieVe4pfhfalOb1nLAdJPeyB/u5U9W0G/hw==" Feb 17 05:36:47 volumio volumio[24460]: info: Ignoring mount for partition: boot Feb 17 05:36:47 volumio volumio[24460]: info: Ignoring mount for partition: volumio Feb 17 05:36:47 volumio volumio[24460]: info: Ignoring mount for partition: volumio_data Feb 17 05:36:47 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 05:36:47 volumio volumio[24460]: info: Loading plugin "volumio_command_line_client"... Feb 17 05:36:47 volumio volumio[24460]: info: Loading plugin "upnp"... Feb 17 05:36:47 volumio volumio[24460]: info: [1771281407754] Starting Upmpd Daemon Feb 17 05:36:47 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 05:36:47 volumio volumio[24460]: info: Loading plugin "my_music"... Feb 17 05:36:47 volumio volumio[24460]: info: Loading plugin "mpd"... Feb 17 05:36:47 volumio go-librespot[24497]: time="2026-02-17T05:36:47+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 05:36:47 volumio go-librespot[24497]: time="2026-02-17T05:36:47+07:00" level=debug msg="completed keyexchange" Feb 17 05:36:47 volumio go-librespot[24497]: time="2026-02-17T05:36:47+07:00" level=debug msg="completed challenge" Feb 17 05:36:47 volumio go-librespot[24497]: time="2026-02-17T05:36:47+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 05:36:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 05:36:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 05:36:48 volumio volumio[24460]: info: Loading plugin "upnp_browser"... Feb 17 05:36:50 volumio sudo[24515]: pam_unix(sudo:session): session closed for user root Feb 17 05:36:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Feb 17 05:36:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:36:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:36:51 volumio go-librespot[24539]: go-librespot daemon starting... Feb 17 05:36:51 volumio go-librespot[24540]: time="2026-02-17T05:36:51+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 05:36:51 volumio go-librespot[24540]: time="2026-02-17T05:36:51+07:00" level=debug msg="app state loaded" Feb 17 05:36:51 volumio go-librespot[24540]: time="2026-02-17T05:36:51+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 05:36:51 volumio volumio[24460]: info: Starting UPNP Browser Feb 17 05:36:51 volumio volumio[24460]: info: Loading plugin "alarm-clock"... Feb 17 05:36:51 volumio volumio[24460]: info: Loading plugin "airplay_emulation"... Feb 17 05:36:51 volumio go-librespot[24540]: time="2026-02-17T05:36:51+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 05:36:51 volumio go-librespot[24540]: time="2026-02-17T05:36:51+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 05:36:51 volumio go-librespot[24540]: time="2026-02-17T05:36:51+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 05:36:51 volumio volumio[24460]: info: Starting Shairport Sync Feb 17 05:36:51 volumio volumio[24460]: info: Loading plugin "last_100"... Feb 17 05:36:51 volumio volumio[24460]: info: Loading plugin "webradio"... Feb 17 05:36:51 volumio go-librespot[24540]: time="2026-02-17T05:36:51+07:00" level=info msg="zeroconf server listening on port 34255" Feb 17 05:36:51 volumio volumio[24460]: info: Loading plugin "i2s_dacs"... Feb 17 05:36:51 volumio go-librespot[24540]: time="2026-02-17T05:36:51+07:00" level=debug msg="obtained new client token: AAC4SuuorRygI9B/G6NCawCwtH/tvpEYGIsteu4qpFeOhSMGPe6/V9dwwrRjFJTajJ9xADdL1KC+6HDK+zX9TdoZNiLw+4XFsZdmN/eX7V9QslJ4w3etJYC4HjAFHL148c2OLvXfYS8mXygCMZBmyu+Lw5AUO/a2Qowvsc2Ri7B4TW92Em0XsCwD4WlM1giRVJV8ePp+KfSFGJ9VfUj8THBgL/Ac4suzDC3Q/5hOGrxa26YalNw6053q6w==" Feb 17 05:36:51 volumio volumio[24460]: info: Loading plugin "volumiodiscovery"... Feb 17 05:36:52 volumio volumio[24460]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 05:36:52 volumio volumio[24460]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 05:36:52 volumio volumio[24460]: *** WARNING *** For more information see Feb 17 05:36:52 volumio volumio[24460]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 05:36:52 volumio volumio[24460]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 05:36:52 volumio volumio[24460]: *** WARNING *** For more information see Feb 17 05:36:52 volumio node[24460]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 05:36:52 volumio node[24460]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 05:36:52 volumio node[24460]: *** WARNING *** For more information see Feb 17 05:36:52 volumio node[24460]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 05:36:52 volumio node[24460]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 05:36:52 volumio node[24460]: *** WARNING *** For more information see Feb 17 05:36:52 volumio volumio[24460]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 17 05:36:52 volumio volumio[24460]: info: Discovery: Started advertising with name: Volumio Feb 17 05:36:52 volumio go-librespot[24540]: time="2026-02-17T05:36:52+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 05:36:52 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 05:36:52 volumio volumio[24460]: info: Loading plugin "spop"... Feb 17 05:36:52 volumio go-librespot[24540]: time="2026-02-17T05:36:52+07:00" level=debug msg="completed keyexchange" Feb 17 05:36:52 volumio go-librespot[24540]: time="2026-02-17T05:36:52+07:00" level=debug msg="completed challenge" Feb 17 05:36:52 volumio go-librespot[24540]: time="2026-02-17T05:36:52+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 05:36:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 05:36:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 05:36:54 volumio volumio[24460]: info: Loading plugin "ytcr"... Feb 17 05:36:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Feb 17 05:36:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:36:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:36:55 volumio go-librespot[24549]: go-librespot daemon starting... Feb 17 05:36:55 volumio go-librespot[24550]: time="2026-02-17T05:36:55+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 05:36:55 volumio go-librespot[24550]: time="2026-02-17T05:36:55+07:00" level=debug msg="app state loaded" Feb 17 05:36:55 volumio go-librespot[24550]: time="2026-02-17T05:36:55+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 05:36:56 volumio go-librespot[24550]: time="2026-02-17T05:36:56+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 05:36:56 volumio go-librespot[24550]: time="2026-02-17T05:36:56+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 05:36:56 volumio go-librespot[24550]: time="2026-02-17T05:36:56+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 05:36:56 volumio go-librespot[24550]: time="2026-02-17T05:36:56+07:00" level=info msg="zeroconf server listening on port 37747" Feb 17 05:36:56 volumio go-librespot[24550]: time="2026-02-17T05:36:56+07:00" level=debug msg="obtained new client token: AADW5eOSVa48qVn/aB2gfjiirDYcpMLMDzZfwEnJK77PZgidSNQDf6TH7Y1FuPTLOZWzsn/l04nLZuOe4oAiFAQKkubiNfcFsi3dOZsXFO/Ufty/9S3HIcrS/NGDYHYmAYbaPE3+c5IDGNiZrgYbcHIXjqe1U2k4dkLfG94hHEgeLdJmlrXZdu6twrUkyMQNFrS8fYolBqP+J1h0ZLA8MoWGDgKiUpaMBYAIz9HCiwM6zW2b3ZLUfgZr3w==" Feb 17 05:36:56 volumio go-librespot[24550]: time="2026-02-17T05:36:56+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 05:36:56 volumio go-librespot[24550]: time="2026-02-17T05:36:56+07:00" level=debug msg="completed keyexchange" Feb 17 05:36:56 volumio go-librespot[24550]: time="2026-02-17T05:36:56+07:00" level=debug msg="completed challenge" Feb 17 05:36:56 volumio volumio[24460]: info: Loading plugin "ytmusic"... Feb 17 05:36:56 volumio go-librespot[24550]: time="2026-02-17T05:36:56+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 05:36:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 05:36:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 05:36:57 volumio volumio-remote-updater[25144]: [2026-02-17 05:36:57] [connect] Successful connection Feb 17 05:36:57 volumio volumio[24460]: info: Loading plugin "outputs"... Feb 17 05:36:57 volumio volumio[24460]: info: Loading plugin "albumart"... Feb 17 05:36:57 volumio volumio[24460]: info: Plugin example_plugin is not enabled Feb 17 05:36:57 volumio volumio[24460]: info: Loading plugin "inputs"... Feb 17 05:36:57 volumio volumio[24460]: info: Loading plugin "updater_comm"... Feb 17 05:36:58 volumio volumio[24460]: info: Plugin mpdemulation is not enabled Feb 17 05:36:58 volumio volumio[24460]: info: Loading plugin "rest_api"... Feb 17 05:36:58 volumio volumio[24460]: info: Loading plugin "websocket"... Feb 17 05:36:58 volumio volumio[24460]: info: Starting Socket.io Server version 1.7.4 Feb 17 05:36:58 volumio volumio[24460]: info: Loading plugin "RoonBridge"... Feb 17 05:36:58 volumio volumio[24460]: info: Applying required configuration parameters for plugin RoonBridge Feb 17 05:36:58 volumio volumio[24460]: info: Loading i18n strings for locale en Feb 17 05:36:58 volumio volumio[24460]: Updating browse sources language Feb 17 05:36:58 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 05:36:58 volumio volumio[24571]: Forking 3 albumart workers Feb 17 05:36:58 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 05:36:58 volumio volumio[24460]: info: CoreCommandRouter::initPlayerControls Feb 17 05:36:58 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:58 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:58 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:58 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:58 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:58 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:58 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:58 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:36:58 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 05:36:58 volumio volumio[24460]: Express server listening on port 3000 Feb 17 05:36:58 volumio volumio[24460]: [Metrics] WebUI: 16s 137.38ms Feb 17 05:36:59 volumio volumio[24460]: info: CoreStateMachine::resetVolumioState Feb 17 05:36:59 volumio volumio[24460]: info: CoreStateMachine::getcurrentVolume Feb 17 05:36:59 volumio volumio[24460]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 05:36:59 volumio sudo[24613]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 05:36:59 volumio sudo[24613]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:36:59 volumio sudo[24613]: pam_unix(sudo:session): session closed for user root Feb 17 05:36:59 volumio sudo[24615]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 05:36:59 volumio sudo[24615]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:36:59 volumio sudo[24615]: pam_unix(sudo:session): session closed for user root Feb 17 05:36:59 volumio volumio[24460]: info: Volumio Network Manager: Network status updated: 1 Feb 17 05:36:59 volumio volumio[24460]: info: VolumeController:: Volume=100 Mute =false Feb 17 05:36:59 volumio volumio[24460]: info: CoreStateMachine::pushState Feb 17 05:36:59 volumio volumio[24460]: info: CorePlayQueue::getTrack 0 Feb 17 05:36:59 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 05:36:59 volumio volumio[24460]: info: CoreCommandRouter::volumioPushState Feb 17 05:36:59 volumio volumio[24460]: info: CoreStateMachine::updateTrackBlock Feb 17 05:36:59 volumio volumio[24460]: info: CorePlayQueue::getTrackBlock Feb 17 05:36:59 volumio volumio[24460]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 05:36:59 volumio volumio-remote-updater[25144]: [2026-02-17 05:36:59] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771281417 101 Feb 17 05:36:59 volumio volumio[24460]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 17 05:36:59 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 05:36:59 volumio volumio[24460]: info: Reloading queue from file Feb 17 05:36:59 volumio volumio[24460]: info: CoreStateMachine::setRepeat null single undefined Feb 17 05:36:59 volumio volumio[24460]: info: CoreStateMachine::pushState Feb 17 05:36:59 volumio volumio[24460]: info: CorePlayQueue::getTrack 0 Feb 17 05:36:59 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 05:36:59 volumio volumio[24460]: info: CoreCommandRouter::volumioPushState Feb 17 05:36:59 volumio volumio[24460]: info: CoreStateMachine::setRandom null Feb 17 05:36:59 volumio volumio[24460]: info: CoreStateMachine::pushState Feb 17 05:36:59 volumio volumio[24460]: info: CorePlayQueue::getTrack 0 Feb 17 05:36:59 volumio volumio[24460]: info: CoreCommandRouter::volumioPushState Feb 17 05:36:59 volumio volumio[24460]: info: Setting Device type: Raspberry PI Feb 17 05:36:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Feb 17 05:36:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:36:59 volumio volumio[24460]: info: Completed loading Core Plugins Feb 17 05:36:59 volumio volumio[24460]: info: Preparing to generate the ALSA configuration file Feb 17 05:36:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:36:59 volumio go-librespot[24629]: go-librespot daemon starting... Feb 17 05:36:59 volumio volumio[24460]: info: VolumeController:: Volume=100 Mute =false Feb 17 05:36:59 volumio volumio[24460]: info: CoreStateMachine::pushState Feb 17 05:36:59 volumio volumio[24460]: info: CorePlayQueue::getTrack 0 Feb 17 05:36:59 volumio volumio[24460]: info: CoreCommandRouter::volumioPushState Feb 17 05:37:00 volumio go-librespot[24630]: time="2026-02-17T05:37:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 05:37:00 volumio go-librespot[24630]: time="2026-02-17T05:37:00+07:00" level=debug msg="app state loaded" Feb 17 05:37:00 volumio go-librespot[24630]: time="2026-02-17T05:37:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 05:37:00 volumio volumio[24460]: info: Asound.conf file unchanged, so no further update is needed Feb 17 05:37:00 volumio volumio[24460]: info: Output device has changed, restarting MPD Feb 17 05:37:00 volumio sudo[24641]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 17 05:37:00 volumio sudo[24641]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:37:00 volumio sudo[24641]: pam_unix(sudo:session): session closed for user root Feb 17 05:37:00 volumio volumio[24460]: info: Output device has changed, restarting Shairport Sync Feb 17 05:37:00 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:37:00 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 05:37:00 volumio sudo[24644]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 05:37:00 volumio sudo[24644]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:37:00 volumio volumio[24460]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 05:37:00 volumio sudo[24644]: pam_unix(sudo:session): session closed for user root Feb 17 05:37:00 volumio volumio[24460]: info: ___________ START PLUGINS ___________ Feb 17 05:37:00 volumio volumio[24460]: info: ControllerMpd::onStart: Initializing MPD Feb 17 05:37:00 volumio volumio[24460]: info: Creating MPD Configuration file Feb 17 05:37:00 volumio sudo[24646]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 05:37:00 volumio sudo[24646]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:37:00 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 05:37:00 volumio volumio[24460]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 05:37:00 volumio volumio[24460]: info: [1771281420471] CoreMusicLibrary::Adding element Media Servers Feb 17 05:37:00 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 05:37:00 volumio sudo[24654]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 05:37:00 volumio sudo[24654]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:37:00 volumio volumio[24460]: info: UPNP Browser: Client initialized successfully Feb 17 05:37:00 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 17 05:37:00 volumio sudo[24654]: pam_unix(sudo:session): session closed for user root Feb 17 05:37:00 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:37:00 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 05:37:00 volumio go-librespot[24630]: time="2026-02-17T05:37:00+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 05:37:00 volumio go-librespot[24630]: time="2026-02-17T05:37:00+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 05:37:00 volumio go-librespot[24630]: time="2026-02-17T05:37:00+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 05:37:00 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 05:37:00 volumio sudo[24657]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 05:37:00 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 05:37:00 volumio systemd[1]: mpd.service: Consumed 7.244s CPU time. Feb 17 05:37:00 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 05:37:00 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 05:37:00 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 05:37:00 volumio sudo[24657]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:37:00 volumio go-librespot[24630]: time="2026-02-17T05:37:00+07:00" level=info msg="zeroconf server listening on port 42119" Feb 17 05:37:00 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 05:37:00 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 05:37:00 volumio volumio[24460]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 05:37:00 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:37:00 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 05:37:00 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 05:37:00 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 05:37:00 volumio volumio[24460]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 05:37:00 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 05:37:00 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 05:37:00 volumio volumio[24460]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 05:37:00 volumio volumio[24460]: info: [1771281420918] CoreMusicLibrary::Adding element Last_100 Feb 17 05:37:00 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 05:37:00 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 05:37:00 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 05:37:00 volumio volumio[24460]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 05:37:00 volumio volumio[24460]: info: [1771281420939] CoreMusicLibrary::Adding element Webradio Feb 17 05:37:00 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 05:37:00 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 05:37:00 volumio go-librespot[24630]: time="2026-02-17T05:37:00+07:00" level=debug msg="obtained new client token: AADWYJ1Kg8AlmVhgm/AmFzCuLWplmfFbmApds8iDYPfV/83TBERK0mYetNhZ87VXkkDJ5213JAoJ7L4M+d8UJwwTKFKEAhiqMxdOsS8HrhxOUxxhqUWs8E6K3wN55h0J70JX4y7DvkiRiBV0nIfKu1cvB2/uIsv4wfX8EhBIIMLmXOUg3u/NkoI3wy52oVbSNlklkpVmX+7yocaN/0wTPr6RqjHkDiWhvXbcupX9RHpXh5JKpfJiGUkHmA==" Feb 17 05:37:01 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 05:37:01 volumio volumio[24460]: info: Initializing BBC Radios Feb 17 05:37:01 volumio go-librespot[24630]: time="2026-02-17T05:37:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 05:37:01 volumio go-librespot[24630]: time="2026-02-17T05:37:01+07:00" level=debug msg="completed keyexchange" Feb 17 05:37:01 volumio go-librespot[24630]: time="2026-02-17T05:37:01+07:00" level=debug msg="completed challenge" Feb 17 05:37:01 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 05:37:01 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 05:37:01 volumio go-librespot[24630]: time="2026-02-17T05:37:01+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 05:37:01 volumio volumio[24460]: info: Creating Spotify config file Feb 17 05:37:01 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:37:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 05:37:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 05:37:01 volumio sudo[24671]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 17 05:37:01 volumio sudo[24671]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 17 05:37:01 volumio sudo[24671]: pam_unix(sudo:session): session closed for user root Feb 17 05:37:02 volumio volumio[24583]: Starting albumart workers Feb 17 05:37:02 volumio volumio[24460]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 05:37:02 volumio volumio[24460]: info: [1771281422299] CoreMusicLibrary::Adding element YouTube Music Feb 17 05:37:02 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 05:37:02 volumio volumio[24460]: Cannot find translation for source YouTube Music Feb 17 05:37:02 volumio volumio[24460]: info: Volumio Calling Home Feb 17 05:37:02 volumio sudo[24688]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 17 05:37:02 volumio sudo[24688]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:37:02 volumio sudo[24688]: pam_unix(sudo:session): session closed for user root Feb 17 05:37:02 volumio volumio[24581]: Starting albumart workers Feb 17 05:37:02 volumio volumio[24582]: Starting albumart workers Feb 17 05:37:03 volumio volumio[24460]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 05:37:03 volumio volumio[24460]: info: Discovery: Found device Volumio Feb 17 05:37:03 volumio volumio[24460]: info: CoreCommandRouter::volumioGetState Feb 17 05:37:03 volumio volumio[24460]: info: CorePlayQueue::getTrack 0 Feb 17 05:37:03 volumio volumio[24460]: info: MPD Permissions set Feb 17 05:37:03 volumio volumio[24460]: info: MPD Permissions set Feb 17 05:37:03 volumio volumio[24460]: info: Upmpdcli Daemon Started Feb 17 05:37:03 volumio volumio[24460]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 05:37:03 volumio volumio[24460]: info: Discovery: Found device Volumio Feb 17 05:37:03 volumio volumio[24460]: info: CoreCommandRouter::volumioGetState Feb 17 05:37:03 volumio volumio[24460]: info: CorePlayQueue::getTrack 0 Feb 17 05:37:03 volumio volumio[24460]: info: Spotify config file written Feb 17 05:37:03 volumio volumio[24460]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 17 05:37:03 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:37:03 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:37:03 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:37:03 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:37:03 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:37:03 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:37:03 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:37:03 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:37:03 volumio sudo[24694]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 17 05:37:03 volumio sudo[24694]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:37:03 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 05:37:03 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:37:03 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:37:03 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:37:03 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:37:03 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:37:03 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:37:03 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:37:03 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:37:03 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:37:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:37:03 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 05:37:03 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 05:37:03 volumio volumio[24460]: info: No need to fix Spotify hosts Feb 17 05:37:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:37:03 volumio go-librespot[24706]: go-librespot daemon starting... Feb 17 05:37:03 volumio sudo[24694]: pam_unix(sudo:session): session closed for user root Feb 17 05:37:03 volumio go-librespot[24707]: time="2026-02-17T05:37:03+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 05:37:03 volumio go-librespot[24707]: time="2026-02-17T05:37:03+07:00" level=debug msg="app state loaded" Feb 17 05:37:03 volumio go-librespot[24707]: time="2026-02-17T05:37:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 05:37:04 volumio go-librespot[24707]: time="2026-02-17T05:37:04+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 05:37:04 volumio go-librespot[24707]: time="2026-02-17T05:37:04+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 17 05:37:04 volumio go-librespot[24707]: time="2026-02-17T05:37:04+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 17 05:37:04 volumio go-librespot[24707]: time="2026-02-17T05:37:04+07:00" level=info msg="zeroconf server listening on port 34069" Feb 17 05:37:04 volumio go-librespot[24707]: time="2026-02-17T05:37:04+07:00" level=debug msg="obtained new client token: AADrCzfBQpI919HnhSLlluyq3L5F+PzMjx9WAP73R4+aT7MRwdCmwLRAEIPjjNxBKrtuQiXzXppQJoyuUubwDfEnqBpToa6PSDOoE3zaPZ87LKW/R46457m0Os80NG4BhyrbnN+T2tvkeVLAFB0/+nH+5BIgNu71zYe79vnRmwo3rg+HJETt+9do9bzWJ67x6dxXbSZ4jdmzuWZt/hCEiFR2AYXDLq2Mu/UsqKKOWYuDTxkeZLCcm08vrQ==" Feb 17 05:37:04 volumio go-librespot[24707]: time="2026-02-17T05:37:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 05:37:04 volumio volumio[24460]: info: Volumio called home Feb 17 05:37:05 volumio go-librespot[24707]: time="2026-02-17T05:37:05+07:00" level=debug msg="completed keyexchange" Feb 17 05:37:05 volumio go-librespot[24707]: time="2026-02-17T05:37:05+07:00" level=debug msg="completed challenge" Feb 17 05:37:05 volumio go-librespot[24707]: time="2026-02-17T05:37:05+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 05:37:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 05:37:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 05:37:05 volumio volumio[24460]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 05:37:05 volumio volumio[24460]: SPOTIFY: BQBpHO7ap_fY4qKsM7GaofDJXYt_Wi22T9nnwocwmVYYh_i5VZkOTk5r69hEq6VAtzqTsIulZEpUww-_FPEYsEkTOF3J5rFc83DQ_1dgBafIYLmXrN9XKTpcHWmTJATAMyd8PbDG8Ya4GF7bPUehf97hEelo5FRX4V-GAxBzAMA0Uiq0Ru67m3dB28OClVdgdgXzB1DJWURnUqkTI05twkn9wI3m4NL1kL-gnJAy549omKjVCNpnrFWKx3Rmwdp821F_mMqEo8MLH5_uyrJtsZrvR6EdiRFe4hrTknE2LNsOC8aL9iB2-dEv Feb 17 05:37:05 volumio volumio[24460]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 05:37:05 volumio volumio[24460]: info: New Spotify access token = BQBpHO7ap_fY4qKsM7GaofDJXYt_Wi22T9nnwocwmVYYh_i5VZkOTk5r69hEq6VAtzqTsIulZEpUww-_FPEYsEkTOF3J5rFc83DQ_1dgBafIYLmXrN9XKTpcHWmTJATAMyd8PbDG8Ya4GF7bPUehf97hEelo5FRX4V-GAxBzAMA0Uiq0Ru67m3dB28OClVdgdgXzB1DJWURnUqkTI05twkn9wI3m4NL1kL-gnJAy549omKjVCNpnrFWKx3Rmwdp821F_mMqEo8MLH5_uyrJtsZrvR6EdiRFe4hrTknE2LNsOC8aL9iB2-dEv Feb 17 05:37:05 volumio volumio[24460]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 17 05:37:05 volumio volumio[24460]: info: Starting Shairport Sync Feb 17 05:37:05 volumio volumio[24460]: info: Starting Shairport Sync Feb 17 05:37:05 volumio volumio[24460]: info: Starting Shairport Sync Feb 17 05:37:05 volumio sudo[24739]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 05:37:05 volumio sudo[24739]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:37:05 volumio sudo[24735]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 05:37:05 volumio sudo[24735]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:37:05 volumio sudo[24737]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 05:37:05 volumio sudo[24737]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:37:05 volumio volumio[24460]: info: CoreCommandRouter::volumioGetState Feb 17 05:37:05 volumio volumio[24460]: info: CorePlayQueue::getTrack 0 Feb 17 05:37:05 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 05:37:05 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 05:37:05 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 05:37:05 volumio systemd[1]: shairport-sync.service: Consumed 2.182s CPU time. Feb 17 05:37:05 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 05:37:05 volumio sudo[24739]: pam_unix(sudo:session): session closed for user root Feb 17 05:37:05 volumio sudo[24735]: pam_unix(sudo:session): session closed for user root Feb 17 05:37:05 volumio sudo[24737]: pam_unix(sudo:session): session closed for user root Feb 17 05:37:05 volumio volumio[24460]: info: Shairport-Sync Started Feb 17 05:37:05 volumio volumio[24460]: Error adding Membership: Error: addMembership EINVAL Feb 17 05:37:05 volumio volumio[24460]: info: Shairport-Sync Started Feb 17 05:37:05 volumio volumio[24460]: info: Shairport-Sync Started Feb 17 05:37:05 volumio volumio[24460]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 17 05:37:05 volumio volumio[24460]: info: Spotify Successfully logged in Feb 17 05:37:05 volumio volumio[24460]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 05:37:05 volumio volumio[24460]: info: [1771281425909] CoreMusicLibrary::Adding element Spotify Feb 17 05:37:05 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 05:37:05 volumio volumio[24460]: Cannot find translation for source YouTube Music Feb 17 05:37:05 volumio volumio[24460]: Cannot find translation for source Spotify Feb 17 05:37:06 volumio volumio[24460]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 17 05:37:06 volumio volumio[24460]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 05:37:06 volumio volumio[24460]: info: VolumeController:: Volume=100 Mute =false Feb 17 05:37:06 volumio volumio[24460]: info: CoreCommandRouter::volumioGetState Feb 17 05:37:06 volumio volumio[24460]: info: CorePlayQueue::getTrack 0 Feb 17 05:37:06 volumio volumio[24460]: info: CoreStateMachine::pushState Feb 17 05:37:06 volumio volumio[24460]: info: CorePlayQueue::getTrack 0 Feb 17 05:37:06 volumio volumio[24460]: info: CoreCommandRouter::volumioPushState Feb 17 05:37:07 volumio volumio[24460]: info: go-librespot daemon successfully initialized Feb 17 05:37:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Feb 17 05:37:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:37:08 volumio mpd[24686]: 2026-02-17T05:37:08 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 17 05:37:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:37:08 volumio go-librespot[24775]: go-librespot daemon starting... Feb 17 05:37:08 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 17 05:37:08 volumio sudo[24646]: pam_unix(sudo:session): session closed for user root Feb 17 05:37:08 volumio sudo[24657]: pam_unix(sudo:session): session closed for user root Feb 17 05:37:08 volumio go-librespot[24778]: time="2026-02-17T05:37:08+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 05:37:08 volumio go-librespot[24778]: time="2026-02-17T05:37:08+07:00" level=debug msg="app state loaded" Feb 17 05:37:08 volumio go-librespot[24778]: time="2026-02-17T05:37:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 05:37:08 volumio volumio[24460]: error: MPD error: The expression evaluated to a falsy value: Feb 17 05:37:08 volumio volumio[24460]: assert.ok(self.idling) Feb 17 05:37:08 volumio volumio[24460]: error: The expression evaluated to a falsy value: Feb 17 05:37:08 volumio volumio[24460]: assert.ok(self.idling) Feb 17 05:37:08 volumio volumio[24460]: info: MPD running with PID24686 Feb 17 05:37:08 volumio volumio[24460]: ,establishing connection Feb 17 05:37:08 volumio volumio[24460]: error: updateQueue error: null Feb 17 05:37:08 volumio volumio[24460]: info: Completed starting Core Plugins Feb 17 05:37:08 volumio volumio[24460]: info: ------------------------------------------- Feb 17 05:37:08 volumio volumio[24460]: info: ----- MyVolumio plugins startup ---- Feb 17 05:37:08 volumio volumio[24460]: info: ------------------------------------------- Feb 17 05:37:08 volumio volumio[24460]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 17 05:37:08 volumio volumio[24460]: error: updateQueue error: null Feb 17 05:37:08 volumio go-librespot[24778]: time="2026-02-17T05:37:08+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 05:37:08 volumio go-librespot[24778]: time="2026-02-17T05:37:08+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 17 05:37:08 volumio go-librespot[24778]: time="2026-02-17T05:37:08+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 17 05:37:08 volumio go-librespot[24778]: time="2026-02-17T05:37:08+07:00" level=info msg="zeroconf server listening on port 43235" Feb 17 05:37:09 volumio go-librespot[24778]: time="2026-02-17T05:37:09+07:00" level=debug msg="obtained new client token: AABvvD32afvJn8DVyGU1FLU5hm02sSlPfIIh8JK2pC4eUyh51T50rJO/cByOwe985U0502hzyRtuEKZTrDpljgXAa5q7zfVgxBQsDUH7naY4jssvFcc0GmYmEIdUd5nkhOm4LNsvchErAGhdlwFhO2VoohesDD+CjaZ92D7EHMPhxQsKnFhJWag0QC9+I+KGFnHD7JzHX4jbSJoC1vAeYxh3vrx7AyPvKaDZuGidIlYUX4IHGPrPvVI=" Feb 17 05:37:09 volumio go-librespot[24778]: time="2026-02-17T05:37:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 05:37:09 volumio go-librespot[24778]: time="2026-02-17T05:37:09+07:00" level=debug msg="completed keyexchange" Feb 17 05:37:09 volumio go-librespot[24778]: time="2026-02-17T05:37:09+07:00" level=debug msg="completed challenge" Feb 17 05:37:09 volumio go-librespot[24778]: time="2026-02-17T05:37:09+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 05:37:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 05:37:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 05:37:10 volumio volumio[24460]: info: Initializing connection to go-librespot Websocket Feb 17 05:37:11 volumio volumio[24460]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 05:37:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Feb 17 05:37:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:37:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:37:12 volumio go-librespot[24788]: go-librespot daemon starting... Feb 17 05:37:12 volumio go-librespot[24789]: time="2026-02-17T05:37:12+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 05:37:12 volumio go-librespot[24789]: time="2026-02-17T05:37:12+07:00" level=debug msg="app state loaded" Feb 17 05:37:12 volumio go-librespot[24789]: time="2026-02-17T05:37:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 05:37:13 volumio go-librespot[24789]: time="2026-02-17T05:37:13+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 05:37:13 volumio go-librespot[24789]: time="2026-02-17T05:37:13+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 05:37:13 volumio go-librespot[24789]: time="2026-02-17T05:37:13+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 05:37:13 volumio go-librespot[24789]: time="2026-02-17T05:37:13+07:00" level=info msg="zeroconf server listening on port 45971" Feb 17 05:37:13 volumio go-librespot[24789]: time="2026-02-17T05:37:13+07:00" level=debug msg="obtained new client token: AAA524VMQLy/N7HXZM224eYVPodaxtN5jPl1FfQGDLJs2/WBxUCBqR+xajo5faffcLVvZla+Ua6FvMzN0e52Px6zce078dPxJl2QeLNMXpbqgailX3YbUEQtCDOUZz4ghk3UbmGEbOAu9gbIWAS7oJxpMBKP2gHUL3XmlrSoOJgx9B4GT30rQ5R5c0/eR2AyY8nDdXLKop7vVkBCZVSTWvK/J2u/4ar0wtBhH6xvvgG5PtOYdZiLGB1tzg==" Feb 17 05:37:13 volumio go-librespot[24789]: time="2026-02-17T05:37:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 05:37:13 volumio volumio[24460]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 17 05:37:13 volumio go-librespot[24789]: time="2026-02-17T05:37:13+07:00" level=debug msg="completed keyexchange" Feb 17 05:37:13 volumio go-librespot[24789]: time="2026-02-17T05:37:13+07:00" level=debug msg="completed challenge" Feb 17 05:37:13 volumio go-librespot[24789]: time="2026-02-17T05:37:13+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 05:37:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 05:37:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 05:37:14 volumio volumio[24460]: info: Initializing connection to go-librespot Websocket Feb 17 05:37:14 volumio volumio[24460]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 05:37:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Feb 17 05:37:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:37:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:37:16 volumio go-librespot[24796]: go-librespot daemon starting... Feb 17 05:37:16 volumio go-librespot[24797]: time="2026-02-17T05:37:16+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 05:37:16 volumio go-librespot[24797]: time="2026-02-17T05:37:16+07:00" level=debug msg="app state loaded" Feb 17 05:37:16 volumio go-librespot[24797]: time="2026-02-17T05:37:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 05:37:17 volumio volumio[24460]: info: Initializing connection to go-librespot Websocket Feb 17 05:37:17 volumio go-librespot[24797]: time="2026-02-17T05:37:17+07:00" level=debug msg="new websocket client" Feb 17 05:37:17 volumio volumio[24460]: info: Connection to go-librespot Websocket established Feb 17 05:37:17 volumio go-librespot[24797]: time="2026-02-17T05:37: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 05:37:17 volumio go-librespot[24797]: time="2026-02-17T05:37:17+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 05:37:17 volumio go-librespot[24797]: time="2026-02-17T05:37:17+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 05:37:17 volumio go-librespot[24797]: time="2026-02-17T05:37:17+07:00" level=info msg="zeroconf server listening on port 41967" Feb 17 05:37:17 volumio volumio[24460]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 17 05:37:17 volumio volumio[24460]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 17 05:37:17 volumio volumio[24460]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 17 05:37:17 volumio volumio[24460]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 17 05:37:17 volumio volumio[24460]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 17 05:37:17 volumio volumio[24460]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 17 05:37:17 volumio volumio[24460]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 17 05:37:17 volumio volumio[24460]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 17 05:37:17 volumio volumio[24460]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 17 05:37:17 volumio volumio[24460]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 17 05:37:17 volumio volumio[24460]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 17 05:37:17 volumio volumio[24460]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 17 05:37:17 volumio volumio[24460]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 17 05:37:17 volumio go-librespot[24797]: time="2026-02-17T05:37:17+07:00" level=debug msg="obtained new client token: AAAzwWONnXsU0nReQslNiXRzo5iFL5Ua8ZIrWIB4hpGYVyuAeVERc7pYj690OguqXqHmt1IiqlMh9aYdoQlLsKIq4pF4oIukayozb8vbCgT8uFOI6SDIUwNhZObeqsgc4HmqAagYXBEmCiUTikjHq5KC1GpG0J4SKyyIS8oB9NXOFvOO8vBxjY1Hc79dNKJzZ+j6hzfi6ZQI3cN2aRUMPXXx19GJPOh9F5Td2T+E5NjS1WYSnbODjW49cw==" Feb 17 05:37:17 volumio volumio[24460]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 17 05:37:17 volumio volumio[24460]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 17 05:37:17 volumio volumio[24460]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 17 05:37:17 volumio volumio[24460]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 17 05:37:17 volumio volumio[24460]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 17 05:37:17 volumio volumio[24460]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 17 05:37:17 volumio volumio[24460]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 17 05:37:17 volumio volumio[24460]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 17 05:37:17 volumio volumio[24460]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 17 05:37:17 volumio volumio[24460]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 17 05:37:17 volumio volumio[24460]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 17 05:37:17 volumio volumio[24460]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 17 05:37:17 volumio volumio[24460]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 17 05:37:17 volumio volumio[24460]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 17 05:37:17 volumio volumio[24460]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 17 05:37:17 volumio volumio[24460]: info: Adding plugin bluetooth to MyMusic Plugins Feb 17 05:37:17 volumio volumio[24460]: info: Adding plugin multiroom to MyMusic Plugins Feb 17 05:37:17 volumio volumio[24460]: info: Adding plugin metavolumio to MyMusic Plugins Feb 17 05:37:17 volumio volumio[24460]: info: Adding plugin cd_controller to MyMusic Plugins Feb 17 05:37:17 volumio volumio[24460]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 17 05:37:17 volumio volumio[24460]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 17 05:37:17 volumio volumio[24460]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 17 05:37:17 volumio volumio[24460]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 17 05:37:17 volumio go-librespot[24797]: time="2026-02-17T05:37:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 05:37:17 volumio go-librespot[24797]: time="2026-02-17T05:37:17+07:00" level=debug msg="completed keyexchange" Feb 17 05:37:17 volumio go-librespot[24797]: time="2026-02-17T05:37:17+07:00" level=debug msg="completed challenge" Feb 17 05:37:17 volumio go-librespot[24797]: time="2026-02-17T05:37:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 05:37:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 05:37:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 05:37:19 volumio volumio[24460]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 17 05:37:19 volumio volumio[24460]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 17 05:37:19 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 05:37:19 volumio volumio[24460]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 05:37:19 volumio volumio[24460]: info: Starting MyVolumio Remote Streaming Endpoints Feb 17 05:37:19 volumio volumio[24460]: info: MyVolumio login type: Token Feb 17 05:37:19 volumio volumio[24460]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 17 05:37:19 volumio volumio[24460]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 17 05:37:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Feb 17 05:37:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:37:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 05:37:21 volumio go-librespot[24818]: go-librespot daemon starting... Feb 17 05:37:21 volumio go-librespot[24819]: time="2026-02-17T05:37:21+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 05:37:21 volumio go-librespot[24819]: time="2026-02-17T05:37:21+07:00" level=debug msg="app state loaded" Feb 17 05:37:21 volumio go-librespot[24819]: time="2026-02-17T05:37:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 05:37:21 volumio volumio[24460]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 17 05:37:21 volumio volumio[24460]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 17 05:37:21 volumio volumio[24460]: info: Streaming services startup Feb 17 05:37:21 volumio volumio[24460]: info: Starting Streaming Daemon Feb 17 05:37:21 volumio sudo[24827]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 17 05:37:21 volumio sudo[24827]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 05:37:21 volumio volumio[24460]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 17 05:37:21 volumio sudo[24827]: pam_unix(sudo:session): session closed for user root Feb 17 05:37:21 volumio volumio[24460]: info: Getting Spotify volume Feb 17 05:37:21 volumio volumio[24460]: info: Connection to go-librespot Websocket closed Feb 17 05:37:21 volumio volumio[24460]: error: Cannot start Volumio Streaming Daemon Feb 17 05:37:21 volumio volumio[24460]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 17 05:37:21 volumio volumio[24460]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 17 05:37:21 volumio volumio[24460]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 17 05:37:21 volumio go-librespot[24819]: time="2026-02-17T05:37: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 05:37:21 volumio go-librespot[24819]: time="2026-02-17T05:37:21+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 05:37:21 volumio go-librespot[24819]: time="2026-02-17T05:37:21+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 05:37:21 volumio go-librespot[24819]: time="2026-02-17T05:37:21+07:00" level=info msg="zeroconf server listening on port 38873" Feb 17 05:37:21 volumio volumio[24460]: info: CoreCommandRouter::volumioGetState Feb 17 05:37:21 volumio volumio[24460]: info: CorePlayQueue::getTrack 0 Feb 17 05:37:21 volumio volumio[24460]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 17 05:37:21 volumio volumio[24460]: SPOTIFY: SPOTIFY VOLUME undefined Feb 17 05:37:21 volumio volumio[24460]: SPOTIFY: VOLUMIO VOLUME 100 Feb 17 05:37:21 volumio volumio[24460]: info: Aligning Spotify Volume to Volumio Volume Feb 17 05:37:21 volumio volumio[24460]: info: CoreCommandRouter::volumioGetState Feb 17 05:37:21 volumio volumio[24460]: info: CorePlayQueue::getTrack 0 Feb 17 05:37:21 volumio volumio[24460]: info: Setting Spotify Volume from Volumio: 100 Feb 17 05:37:21 volumio go-librespot[24819]: time="2026-02-17T05:37:21+07:00" level=debug msg="obtained new client token: AAAEGwD4kI4wAKTOyL8R+X5tVbRcwXwp7v9n6MEkqINlOrhexoL0dgTg+s1S64PQpOP0XyTjlhG9USdopScWqOfxDvuCt6THUb1Z2DxeYjdmGs/UUXpF+FQ3etZxhi3xSAJOtwQTjjichzKVuakdHOXsvldDmSemfn/e7FzmC0QKgHEbP87wSSeaN/H1Lup1EpV9DYgyIPKade85K57zy8rx/GN6lESbuTUHsIgWnSZ1XOHkYUNlAv4rLg==" Feb 17 05:37:22 volumio go-librespot[24819]: time="2026-02-17T05:37:22+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 17 05:37:22 volumio go-librespot[24819]: time="2026-02-17T05:37:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 17 05:37:22 volumio go-librespot[24819]: time="2026-02-17T05:37:22+07:00" level=debug msg="completed keyexchange" Feb 17 05:37:22 volumio go-librespot[24819]: time="2026-02-17T05:37:22+07:00" level=debug msg="completed challenge" Feb 17 05:37:22 volumio go-librespot[24819]: time="2026-02-17T05:37:22+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 05:37:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 05:37:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 05:37:22 volumio volumio[24460]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 05:37:22 volumio volumio[24460]: Error: socket hang up Feb 17 05:37:22 volumio volumio[24460]: at connResetException (node:internal/errors:720:14) Feb 17 05:37:22 volumio volumio[24460]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 17 05:37:22 volumio volumio[24460]: at Socket.emit (node:events:526:35) Feb 17 05:37:22 volumio volumio[24460]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 17 05:37:22 volumio volumio[24460]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 17 05:37:22 volumio volumio[24460]: code: 'ECONNRESET', Feb 17 05:37:22 volumio volumio[24460]: response: undefined Feb 17 05:37:22 volumio volumio[24460]: } Feb 17 05:37:22 volumio volumio[24460]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 05:37:23 volumio sudo[24849]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 05:36' Feb 17 05:37:23 volumio sudo[24849]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"