Feb 11 22:02:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 11 22:02:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:02:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:02:01 volumio go-librespot[26706]: go-librespot daemon starting... Feb 11 22:02:01 volumio go-librespot[26707]: time="2026-02-11T22:02:01+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 22:02:01 volumio go-librespot[26707]: time="2026-02-11T22:02:01+07:00" level=debug msg="app state loaded" Feb 11 22:02:01 volumio go-librespot[26707]: time="2026-02-11T22:02:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 22:02:01 volumio go-librespot[26707]: time="2026-02-11T22:02:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 22:02:01 volumio go-librespot[26707]: time="2026-02-11T22:02:01+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 22:02:01 volumio go-librespot[26707]: time="2026-02-11T22:02:01+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 22:02:01 volumio go-librespot[26707]: time="2026-02-11T22:02:01+07:00" level=info msg="zeroconf server listening on port 35499" Feb 11 22:02:01 volumio go-librespot[26707]: time="2026-02-11T22:02:01+07:00" level=debug msg="obtained new client token: AAAHUg5hfK2Thry8r3nBSvyS/JcuIiifVQYIDFel+wBdryoiv7vweDDQ4e2FxtUrUU8keQUTiqYkJ4t3eByVOqPWgi7kSudfnnNXW5r1rNKfajYjKFr+SwBtK3CLab28e6HGD2bjN41LdTPr1qE6dEtyFK5K/Esw1G4uPnrAHlyCwT6v3X8lKmi6RqQnndGMPwRjusvM5QiywWp47m/pc9iyEXwaPldCNtHGlTUmRQNb6301xX8M+N9quQ==" Feb 11 22:02:02 volumio go-librespot[26707]: time="2026-02-11T22:02:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 22:02:02 volumio go-librespot[26707]: time="2026-02-11T22:02:02+07:00" level=debug msg="completed keyexchange" Feb 11 22:02:02 volumio go-librespot[26707]: time="2026-02-11T22:02:02+07:00" level=debug msg="completed challenge" Feb 11 22:02:02 volumio go-librespot[26707]: time="2026-02-11T22:02:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 22:02:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 22:02:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 22:02:02 volumio volumio[26691]: info: ------------------------------------------- Feb 11 22:02:02 volumio volumio[26691]: info: ----- Volumio3 ---- Feb 11 22:02:02 volumio volumio[26691]: info: ------------------------------------------- Feb 11 22:02:02 volumio volumio[26691]: info: ----- System startup ---- Feb 11 22:02:02 volumio volumio[26691]: info: ------------------------------------------- Feb 11 22:02:03 volumio volumio-remote-updater[643]: [2026-02-11 22:02:03] [connect] Successful connection Feb 11 22:02:03 volumio volumio[26691]: info: MYVOLUMIO Environment detected Feb 11 22:02:03 volumio volumio[26691]: info: Plugin folders cleanup Feb 11 22:02:03 volumio volumio[26691]: info: Scanning into folder /volumio/app/plugins/ Feb 11 22:02:03 volumio volumio[26691]: info: Scanning category audio_interface Feb 11 22:02:03 volumio volumio[26691]: info: Scanning category miscellanea Feb 11 22:02:03 volumio volumio[26691]: info: Scanning category music_service Feb 11 22:02:03 volumio volumio[26691]: info: Scanning category plugins.json Feb 11 22:02:03 volumio volumio[26691]: info: Scanning category system_controller Feb 11 22:02:03 volumio volumio[26691]: info: Scanning category user_interface Feb 11 22:02:03 volumio volumio[26691]: info: Scanning into folder /data/plugins/ Feb 11 22:02:03 volumio volumio[26691]: info: Scanning category music_service Feb 11 22:02:03 volumio volumio[26691]: info: Plugin folders cleanup completed Feb 11 22:02:03 volumio volumio[26691]: info: ------------------------------------------- Feb 11 22:02:03 volumio volumio[26691]: info: ----- Core plugins startup ---- Feb 11 22:02:03 volumio volumio[26691]: info: ------------------------------------------- Feb 11 22:02:03 volumio volumio[26691]: info: Loading plugins from folder /volumio/app/plugins/ Feb 11 22:02:03 volumio volumio[26691]: info: Adding plugin upnp to MyMusic Plugins Feb 11 22:02:03 volumio volumio[26691]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 11 22:02:03 volumio volumio[26691]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 11 22:02:04 volumio volumio[26691]: info: Loading plugins from folder /data/plugins/ Feb 11 22:02:04 volumio volumio[26691]: info: Loading plugin "system"... Feb 11 22:02:04 volumio volumio[26691]: info: Loading plugin "appearance"... Feb 11 22:02:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Feb 11 22:02:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:02:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:02:05 volumio go-librespot[26726]: go-librespot daemon starting... Feb 11 22:02:05 volumio go-librespot[26727]: time="2026-02-11T22:02:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 22:02:05 volumio go-librespot[26727]: time="2026-02-11T22:02:05+07:00" level=debug msg="app state loaded" Feb 11 22:02:05 volumio go-librespot[26727]: time="2026-02-11T22:02:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 22:02:05 volumio go-librespot[26727]: time="2026-02-11T22:02:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 22:02:05 volumio go-librespot[26727]: time="2026-02-11T22:02:05+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 22:02:05 volumio go-librespot[26727]: time="2026-02-11T22:02:05+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 22:02:05 volumio go-librespot[26727]: time="2026-02-11T22:02:05+07:00" level=info msg="zeroconf server listening on port 40083" Feb 11 22:02:05 volumio volumio[26691]: info: Loading plugin "network"... Feb 11 22:02:06 volumio volumio[26691]: info: Refreshing Cached IP Addresses Feb 11 22:02:06 volumio sudo[26738]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 22:02:06 volumio sudo[26738]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:02:06 volumio sudo[26736]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 22:02:06 volumio sudo[26738]: pam_unix(sudo:session): session closed for user root Feb 11 22:02:06 volumio sudo[26736]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:02:06 volumio volumio[26691]: info: Loading plugin "services"... Feb 11 22:02:06 volumio sudo[26736]: pam_unix(sudo:session): session closed for user root Feb 11 22:02:06 volumio volumio[26691]: info: Loading plugin "alsa_controller"... Feb 11 22:02:06 volumio sudo[26746]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 11 22:02:06 volumio sudo[26746]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:02:06 volumio go-librespot[26727]: time="2026-02-11T22:02:06+07:00" level=debug msg="obtained new client token: AACrXk5wfEuz2+IQJKeIAuY6UrKXUsOsNg5MWUVaVfsk75WhBZ4md4kDuZVJlapDdTpMIWqr0RvGBKtrvopSfURqWcxPbuFGt6SHxosRurMBVDj9X/kbSayR9dWxxV8WuPrwTJmfNSqNeoQkGmcJtPXLzHeR/cMoU0N+z6kBE1U7hgL14O0OFwT1g/4RQJC3XhE8HZ3B4OQKuridV1N65OsC4nwwkIoLOLFMlqM5sO5iOVW/mrenxXE=" Feb 11 22:02:06 volumio go-librespot[26727]: time="2026-02-11T22:02:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 22:02:06 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 22:02:06 volumio volumio[26691]: info: Loading plugin "wizard"... Feb 11 22:02:06 volumio volumio[26691]: info: Loading plugin "networkfs"... Feb 11 22:02:06 volumio volumio[26691]: info: Starting Udev Watcher for removable devices Feb 11 22:02:06 volumio go-librespot[26727]: time="2026-02-11T22:02:06+07:00" level=debug msg="completed keyexchange" Feb 11 22:02:06 volumio go-librespot[26727]: time="2026-02-11T22:02:06+07:00" level=debug msg="completed challenge" Feb 11 22:02:06 volumio volumio[26691]: info: Ignoring mount for partition: boot Feb 11 22:02:06 volumio volumio[26691]: info: Ignoring mount for partition: volumio Feb 11 22:02:06 volumio volumio[26691]: info: Ignoring mount for partition: volumio_data Feb 11 22:02:06 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 22:02:06 volumio volumio[26691]: info: Loading plugin "volumio_command_line_client"... Feb 11 22:02:06 volumio volumio[26691]: info: Loading plugin "upnp"... Feb 11 22:02:06 volumio go-librespot[26727]: time="2026-02-11T22:02:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 22:02:06 volumio volumio[26691]: info: [1770822126448] Starting Upmpd Daemon Feb 11 22:02:06 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 22:02:06 volumio volumio[26691]: info: Loading plugin "my_music"... Feb 11 22:02:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 22:02:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 22:02:06 volumio volumio[26691]: info: Loading plugin "mpd"... Feb 11 22:02:07 volumio volumio[26691]: info: Loading plugin "upnp_browser"... Feb 11 22:02:08 volumio sudo[26746]: pam_unix(sudo:session): session closed for user root Feb 11 22:02:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Feb 11 22:02:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:02:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:02:09 volumio go-librespot[26770]: go-librespot daemon starting... Feb 11 22:02:09 volumio go-librespot[26771]: time="2026-02-11T22:02:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 22:02:09 volumio go-librespot[26771]: time="2026-02-11T22:02:09+07:00" level=debug msg="app state loaded" Feb 11 22:02:09 volumio go-librespot[26771]: time="2026-02-11T22:02:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 22:02:10 volumio volumio[26691]: info: Starting UPNP Browser Feb 11 22:02:10 volumio volumio[26691]: info: Loading plugin "alarm-clock"... Feb 11 22:02:10 volumio go-librespot[26771]: time="2026-02-11T22:02:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 22:02:10 volumio go-librespot[26771]: time="2026-02-11T22:02:10+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 22:02:10 volumio go-librespot[26771]: time="2026-02-11T22:02:10+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 22:02:10 volumio go-librespot[26771]: time="2026-02-11T22:02:10+07:00" level=info msg="zeroconf server listening on port 41389" Feb 11 22:02:10 volumio go-librespot[26771]: time="2026-02-11T22:02:10+07:00" level=debug msg="obtained new client token: AAC+1WdWjTj300DAnvGb5Rnur8EKKdEgtOG4bb+3XV129DU8b53dQnB6ROjCqodzP74PH2Vi06hOCxYdnSPhIgLuRBtVUBc6lbMhsfaZyk8sX91NGVJbZA+eW1HWWC8Q33Yutnpnu+NS2BiapFT29RnBguus8q/R8eWy1BlI3NMlcHFLuATCVHzdK6YuOuwmMWQqewAmAjzMP73UZqVcwu46bR1NfefttyAWNzMHhD+nSDwt8JJz1foewQ==" Feb 11 22:02:10 volumio volumio[26691]: info: Loading plugin "airplay_emulation"... Feb 11 22:02:10 volumio volumio[26691]: info: Starting Shairport Sync Feb 11 22:02:10 volumio volumio[26691]: info: Loading plugin "last_100"... Feb 11 22:02:10 volumio go-librespot[26771]: time="2026-02-11T22:02:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 22:02:10 volumio volumio[26691]: info: Loading plugin "webradio"... Feb 11 22:02:10 volumio go-librespot[26771]: time="2026-02-11T22:02:10+07:00" level=debug msg="completed keyexchange" Feb 11 22:02:10 volumio go-librespot[26771]: time="2026-02-11T22:02:10+07:00" level=debug msg="completed challenge" Feb 11 22:02:10 volumio volumio[26691]: info: Loading plugin "i2s_dacs"... Feb 11 22:02:10 volumio volumio[26691]: info: Loading plugin "volumiodiscovery"... Feb 11 22:02:10 volumio go-librespot[26771]: time="2026-02-11T22:02:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 22:02:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 22:02:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 22:02:10 volumio volumio[26691]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 11 22:02:10 volumio volumio[26691]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 22:02:10 volumio volumio[26691]: *** WARNING *** For more information see Feb 11 22:02:10 volumio volumio[26691]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 11 22:02:10 volumio volumio[26691]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 22:02:10 volumio volumio[26691]: *** WARNING *** For more information see Feb 11 22:02:10 volumio node[26691]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 11 22:02:10 volumio node[26691]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 22:02:10 volumio node[26691]: *** WARNING *** For more information see Feb 11 22:02:10 volumio node[26691]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 11 22:02:10 volumio node[26691]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 22:02:10 volumio node[26691]: *** WARNING *** For more information see Feb 11 22:02:10 volumio volumio[26691]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 11 22:02:10 volumio volumio[26691]: info: Discovery: Started advertising with name: Volumio Feb 11 22:02:10 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 22:02:10 volumio volumio[26691]: info: Loading plugin "spop"... Feb 11 22:02:12 volumio volumio[26691]: info: Loading plugin "ytcr"... Feb 11 22:02:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Feb 11 22:02:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:02:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:02:13 volumio go-librespot[26781]: go-librespot daemon starting... Feb 11 22:02:13 volumio go-librespot[26782]: time="2026-02-11T22:02:13+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 22:02:13 volumio go-librespot[26782]: time="2026-02-11T22:02:13+07:00" level=debug msg="app state loaded" Feb 11 22:02:13 volumio go-librespot[26782]: time="2026-02-11T22:02:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 22:02:14 volumio go-librespot[26782]: time="2026-02-11T22:02:14+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 22:02:14 volumio go-librespot[26782]: time="2026-02-11T22:02:14+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 11 22:02:14 volumio go-librespot[26782]: time="2026-02-11T22:02:14+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 11 22:02:14 volumio go-librespot[26782]: time="2026-02-11T22:02:14+07:00" level=info msg="zeroconf server listening on port 33697" Feb 11 22:02:14 volumio go-librespot[26782]: time="2026-02-11T22:02:14+07:00" level=debug msg="obtained new client token: AABPtT0S91bDAAyEd3mRTcLMvnj2uhCX8A7OjFILkG8pqrqeiPPRcFibzO73fKM7ZwqpiG8TyMzA9klz7WvzW9o7b6iZxACpmPTh842tULAdeCHhqgqzwrRerrQ1pfYWN1GaZDDXoqEQqiRoxjmvcnC9L2ckX+zlyLfw/Amc8kfrfJF44f28Fj/qzml/SgJ99b7Sw0S93jn+sG64j99Ji9U6MwFNfZMYZa3g+Cg1xCt+TSflvAvsuwqS9w==" Feb 11 22:02:14 volumio go-librespot[26782]: time="2026-02-11T22:02:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 22:02:14 volumio go-librespot[26782]: time="2026-02-11T22:02:14+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 22:02:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 22:02:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 22:02:15 volumio volumio[26691]: info: Loading plugin "ytmusic"... Feb 11 22:02:16 volumio volumio-remote-updater[643]: [2026-02-11 22:02:16] [connect] Successful connection Feb 11 22:02:16 volumio volumio[26691]: info: Loading plugin "outputs"... Feb 11 22:02:16 volumio volumio[26691]: info: Loading plugin "albumart"... Feb 11 22:02:16 volumio volumio[26691]: info: Plugin example_plugin is not enabled Feb 11 22:02:16 volumio volumio[26691]: info: Loading plugin "inputs"... Feb 11 22:02:16 volumio volumio[26691]: info: Loading plugin "updater_comm"... Feb 11 22:02:16 volumio volumio[26691]: info: Plugin mpdemulation is not enabled Feb 11 22:02:16 volumio volumio[26691]: info: Loading plugin "rest_api"... Feb 11 22:02:16 volumio volumio[26691]: info: Loading plugin "websocket"... Feb 11 22:02:16 volumio volumio[26691]: info: Starting Socket.io Server version 1.7.4 Feb 11 22:02:16 volumio volumio[26691]: info: Loading plugin "RoonBridge"... Feb 11 22:02:17 volumio volumio[26691]: info: Applying required configuration parameters for plugin RoonBridge Feb 11 22:02:17 volumio volumio[26691]: info: Loading i18n strings for locale en Feb 11 22:02:17 volumio volumio[26691]: Updating browse sources language Feb 11 22:02:17 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 22:02:17 volumio volumio[26803]: Forking 3 albumart workers Feb 11 22:02:17 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 22:02:17 volumio volumio[26691]: info: CoreCommandRouter::initPlayerControls Feb 11 22:02:17 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:02:17 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:02:17 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:02:17 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:02:17 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:02:17 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:02:17 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:02:17 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:02:17 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 22:02:17 volumio volumio[26691]: Express server listening on port 3000 Feb 11 22:02:17 volumio volumio[26691]: [Metrics] WebUI: 16s 251.44ms Feb 11 22:02:17 volumio volumio[26691]: info: CoreStateMachine::resetVolumioState Feb 11 22:02:17 volumio volumio[26691]: info: CoreStateMachine::getcurrentVolume Feb 11 22:02:17 volumio volumio[26691]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 22:02:17 volumio sudo[26848]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 22:02:17 volumio sudo[26848]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:02:17 volumio sudo[26848]: pam_unix(sudo:session): session closed for user root Feb 11 22:02:18 volumio sudo[26850]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 22:02:18 volumio volumio[26691]: info: Volumio Network Manager: Network status updated: 1 Feb 11 22:02:18 volumio sudo[26850]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:02:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Feb 11 22:02:18 volumio sudo[26850]: pam_unix(sudo:session): session closed for user root Feb 11 22:02:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:02:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:02:18 volumio go-librespot[26853]: go-librespot daemon starting... Feb 11 22:02:18 volumio go-librespot[26855]: time="2026-02-11T22:02:18+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 22:02:18 volumio go-librespot[26855]: time="2026-02-11T22:02:18+07:00" level=debug msg="app state loaded" Feb 11 22:02:18 volumio go-librespot[26855]: time="2026-02-11T22:02:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 22:02:18 volumio volumio-remote-updater[643]: [2026-02-11 22:02:18] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770822136 101 Feb 11 22:02:18 volumio volumio[26691]: 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 11 22:02:18 volumio volumio[26691]: info: VolumeController:: Volume=100 Mute =false Feb 11 22:02:18 volumio volumio[26691]: info: CoreStateMachine::pushState Feb 11 22:02:18 volumio volumio[26691]: info: CorePlayQueue::getTrack 0 Feb 11 22:02:18 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 22:02:18 volumio volumio[26691]: info: CoreCommandRouter::volumioPushState Feb 11 22:02:18 volumio volumio[26691]: info: CoreStateMachine::updateTrackBlock Feb 11 22:02:18 volumio volumio[26691]: info: CorePlayQueue::getTrackBlock Feb 11 22:02:18 volumio volumio[26691]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 22:02:18 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 22:02:18 volumio volumio[26691]: info: Reloading queue from file Feb 11 22:02:18 volumio volumio[26691]: info: CoreStateMachine::setRepeat null single undefined Feb 11 22:02:18 volumio volumio[26691]: info: CoreStateMachine::pushState Feb 11 22:02:18 volumio volumio[26691]: info: CorePlayQueue::getTrack 0 Feb 11 22:02:18 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 22:02:18 volumio volumio[26691]: info: CoreCommandRouter::volumioPushState Feb 11 22:02:18 volumio volumio[26691]: info: CoreStateMachine::setRandom null Feb 11 22:02:18 volumio volumio[26691]: info: CoreStateMachine::pushState Feb 11 22:02:18 volumio volumio[26691]: info: CorePlayQueue::getTrack 0 Feb 11 22:02:18 volumio volumio[26691]: info: CoreCommandRouter::volumioPushState Feb 11 22:02:18 volumio volumio[26691]: info: Setting Device type: Raspberry PI Feb 11 22:02:18 volumio volumio[26691]: info: Completed loading Core Plugins Feb 11 22:02:18 volumio volumio[26691]: info: Preparing to generate the ALSA configuration file Feb 11 22:02:18 volumio go-librespot[26855]: time="2026-02-11T22:02:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 22:02:18 volumio go-librespot[26855]: time="2026-02-11T22:02:18+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 11 22:02:18 volumio go-librespot[26855]: time="2026-02-11T22:02:18+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 11 22:02:18 volumio go-librespot[26855]: time="2026-02-11T22:02:18+07:00" level=info msg="zeroconf server listening on port 36467" Feb 11 22:02:19 volumio volumio[26691]: info: VolumeController:: Volume=100 Mute =false Feb 11 22:02:19 volumio volumio[26691]: info: CoreStateMachine::pushState Feb 11 22:02:19 volumio volumio[26691]: info: CorePlayQueue::getTrack 0 Feb 11 22:02:19 volumio volumio[26691]: info: CoreCommandRouter::volumioPushState Feb 11 22:02:19 volumio volumio[26691]: info: Asound.conf file unchanged, so no further update is needed Feb 11 22:02:19 volumio volumio[26691]: info: Output device has changed, restarting MPD Feb 11 22:02:19 volumio volumio[26691]: info: Output device has changed, restarting Shairport Sync Feb 11 22:02:19 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:02:19 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 22:02:19 volumio sudo[26871]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 11 22:02:19 volumio sudo[26871]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:02:19 volumio volumio[26691]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 22:02:19 volumio volumio[26691]: info: ___________ START PLUGINS ___________ Feb 11 22:02:19 volumio sudo[26875]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 22:02:19 volumio volumio[26691]: info: ControllerMpd::onStart: Initializing MPD Feb 11 22:02:19 volumio volumio[26691]: info: Creating MPD Configuration file Feb 11 22:02:19 volumio sudo[26875]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:02:19 volumio go-librespot[26855]: time="2026-02-11T22:02:19+07:00" level=debug msg="obtained new client token: AACE8CAQAdEOX3F23ZiBMHFf6ILNHWeDDmLnNcj9TSJHk4f3o1bxuq+VKJfBJRE7JFGMWWZ2GBCYJ6ozPaI6veiwblRHAMyztcFv2O+mFN/vNBih8zRQZA2QqLlbdLFass3pcKBd8dQmOp5UX3emI8uBNruMRYLon9fAk01QumSi1LWuuJeMZT64RGDNuhpWWg8ZKSXdoRMuPXkwwUJnk2ah8kiEB8ra2CJnOHsjQkWJMT/UfaKyIWY=" Feb 11 22:02:19 volumio sudo[26873]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 22:02:19 volumio sudo[26873]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:02:19 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 22:02:19 volumio sudo[26873]: pam_unix(sudo:session): session closed for user root Feb 11 22:02:19 volumio volumio[26691]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 22:02:19 volumio volumio[26691]: info: [1770822139315] CoreMusicLibrary::Adding element Media Servers Feb 11 22:02:19 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 22:02:19 volumio sudo[26871]: pam_unix(sudo:session): session closed for user root Feb 11 22:02:19 volumio go-librespot[26855]: time="2026-02-11T22:02:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 22:02:19 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 11 22:02:19 volumio go-librespot[26855]: time="2026-02-11T22:02:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 22:02:19 volumio volumio[26691]: info: UPNP Browser: Client initialized successfully Feb 11 22:02:19 volumio sudo[26883]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 22:02:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 22:02:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 22:02:19 volumio sudo[26883]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:02:19 volumio sudo[26886]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 22:02:19 volumio sudo[26886]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:02:19 volumio sudo[26883]: pam_unix(sudo:session): session closed for user root Feb 11 22:02:19 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 11 22:02:19 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 11 22:02:19 volumio systemd[1]: mpd.service: Consumed 7.203s CPU time. Feb 11 22:02:19 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 11 22:02:19 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 11 22:02:19 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 11 22:02:19 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:02:19 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 22:02:19 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 11 22:02:19 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 11 22:02:19 volumio volumio[26691]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 22:02:19 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:02:19 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 22:02:19 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 11 22:02:19 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 11 22:02:19 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 11 22:02:19 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 11 22:02:19 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 11 22:02:19 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 11 22:02:19 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 11 22:02:19 volumio volumio[26691]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 22:02:19 volumio volumio[26691]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 22:02:19 volumio volumio[26691]: info: [1770822139792] CoreMusicLibrary::Adding element Last_100 Feb 11 22:02:19 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 22:02:19 volumio volumio[26691]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 22:02:19 volumio volumio[26691]: info: [1770822139812] CoreMusicLibrary::Adding element Webradio Feb 11 22:02:19 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 22:02:19 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 22:02:19 volumio volumio[26691]: info: Initializing BBC Radios Feb 11 22:02:20 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 22:02:20 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 22:02:20 volumio volumio[26691]: info: Creating Spotify config file Feb 11 22:02:20 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:02:20 volumio sudo[26900]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 11 22:02:20 volumio sudo[26900]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 11 22:02:20 volumio sudo[26900]: pam_unix(sudo:session): session closed for user root Feb 11 22:02:20 volumio volumio[26815]: Starting albumart workers Feb 11 22:02:20 volumio volumio[26813]: Starting albumart workers Feb 11 22:02:21 volumio volumio[26814]: Starting albumart workers Feb 11 22:02:21 volumio volumio[26691]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 22:02:21 volumio volumio[26691]: info: [1770822141670] CoreMusicLibrary::Adding element YouTube Music Feb 11 22:02:21 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 22:02:21 volumio volumio[26691]: Cannot find translation for source YouTube Music Feb 11 22:02:21 volumio volumio[26691]: info: Volumio Calling Home Feb 11 22:02:21 volumio sudo[26917]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 11 22:02:21 volumio sudo[26917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:02:22 volumio sudo[26917]: pam_unix(sudo:session): session closed for user root Feb 11 22:02:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Feb 11 22:02:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:02:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:02:22 volumio go-librespot[26934]: go-librespot daemon starting... Feb 11 22:02:22 volumio volumio[26691]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 11 22:02:22 volumio volumio[26691]: info: Discovery: Found device Volumio Feb 11 22:02:22 volumio volumio[26691]: info: CoreCommandRouter::volumioGetState Feb 11 22:02:22 volumio volumio[26691]: info: CorePlayQueue::getTrack 0 Feb 11 22:02:22 volumio go-librespot[26935]: time="2026-02-11T22:02:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 22:02:22 volumio go-librespot[26935]: time="2026-02-11T22:02:22+07:00" level=debug msg="app state loaded" Feb 11 22:02:22 volumio go-librespot[26935]: time="2026-02-11T22:02:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 22:02:22 volumio volumio[26691]: info: MPD Permissions set Feb 11 22:02:22 volumio volumio[26691]: info: MPD Permissions set Feb 11 22:02:22 volumio volumio[26691]: info: Upmpdcli Daemon Started Feb 11 22:02:22 volumio volumio[26691]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 11 22:02:22 volumio volumio[26691]: info: Discovery: Found device Volumio Feb 11 22:02:22 volumio volumio[26691]: info: CoreCommandRouter::volumioGetState Feb 11 22:02:22 volumio volumio[26691]: info: CorePlayQueue::getTrack 0 Feb 11 22:02:22 volumio volumio[26691]: info: Spotify config file written Feb 11 22:02:22 volumio volumio[26691]: 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 11 22:02:22 volumio volumio[26691]: info: Volumio called home Feb 11 22:02:22 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:02:22 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:02:22 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:02:22 volumio sudo[26942]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 11 22:02:22 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:02:22 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:02:22 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:02:22 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:02:22 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:02:22 volumio sudo[26942]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:02:22 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 22:02:22 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:02:22 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:02:22 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:02:22 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:02:22 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:02:22 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:02:22 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:02:22 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:02:22 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:02:23 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 22:02:23 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:02:23 volumio volumio[26691]: info: No need to fix Spotify hosts Feb 11 22:02:23 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 11 22:02:23 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 11 22:02:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:02:23 volumio go-librespot[26955]: go-librespot daemon starting... Feb 11 22:02:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:02:23 volumio sudo[26942]: pam_unix(sudo:session): session closed for user root Feb 11 22:02:23 volumio go-librespot[26961]: time="2026-02-11T22:02:23+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 22:02:23 volumio go-librespot[26961]: time="2026-02-11T22:02:23+07:00" level=debug msg="app state loaded" Feb 11 22:02:23 volumio go-librespot[26961]: time="2026-02-11T22:02:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 22:02:23 volumio go-librespot[26961]: time="2026-02-11T22:02:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 22:02:23 volumio go-librespot[26961]: time="2026-02-11T22:02:23+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 11 22:02:23 volumio go-librespot[26961]: time="2026-02-11T22:02:23+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 11 22:02:23 volumio go-librespot[26961]: time="2026-02-11T22:02:23+07:00" level=info msg="zeroconf server listening on port 36845" Feb 11 22:02:23 volumio volumio[26691]: info: Starting Shairport Sync Feb 11 22:02:23 volumio volumio[26691]: info: Starting Shairport Sync Feb 11 22:02:23 volumio volumio[26691]: info: Starting Shairport Sync Feb 11 22:02:24 volumio sudo[26969]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 22:02:24 volumio sudo[26969]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:02:24 volumio sudo[26971]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 22:02:24 volumio sudo[26971]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:02:24 volumio sudo[26973]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 22:02:24 volumio sudo[26973]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:02:24 volumio go-librespot[26961]: time="2026-02-11T22:02:24+07:00" level=debug msg="obtained new client token: AACGipz2gluZlnH+/TrvKmJgDK3/pvEYuqL5ID+539UXmZ/7nqRiA1hQjOCQs9vkbeE4vDjReL8dclHHgjirnvdzSK23H6mrrfeZdWHFkT6nBrY4BEv4ObTFGE1WQ+XpZsQtUivSveufpqCgV+AaBCSHdqAhRwAynMPhco4Kz1WFKIWdqjzB3vD2P8oDvzBBe3tCxEn+z1g536FynVCkNnEQmIzNemVSgZRcjRNwlGKxCwOUE2Pf/zo=" Feb 11 22:02:24 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 11 22:02:24 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 11 22:02:24 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 22:02:24 volumio systemd[1]: shairport-sync.service: Consumed 2.228s CPU time. Feb 11 22:02:24 volumio go-librespot[26961]: time="2026-02-11T22:02:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 22:02:24 volumio go-librespot[26961]: time="2026-02-11T22:02:24+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 22:02:24 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 22:02:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 22:02:24 volumio sudo[26969]: pam_unix(sudo:session): session closed for user root Feb 11 22:02:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 22:02:24 volumio sudo[26971]: pam_unix(sudo:session): session closed for user root Feb 11 22:02:24 volumio volumio[26691]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 11 22:02:24 volumio volumio[26691]: SPOTIFY: BQBrW9Hvtehq0qvGJy0efBKhnG5QSpcLrpC2rL9B21Du9-P3Zt1JNQwyr9ct2_jeRLzMDXCd3Iv1FOU12PnQEwUMs1CqgoFon5wm5DQKans_VX82sRL3paylKoTmwXBqRLHJDRm3Q68BN7uTo5W54RaZYMaVrp9OxW13Op1lURELMYcOJsg1DdwmcwWM9Vm2mJ7yTp9TPmu4QltBNV6teHuTB0wKrf24vGFn_9gNfDBMu98Jkgel8fRhfnz_sJsVJPiATzLIMrSUbK512GN4ObkPcW-iV77fm2ifBu2HPc9Z76WPkI2arBew Feb 11 22:02:24 volumio volumio[26691]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 11 22:02:24 volumio volumio[26691]: info: New Spotify access token = BQBrW9Hvtehq0qvGJy0efBKhnG5QSpcLrpC2rL9B21Du9-P3Zt1JNQwyr9ct2_jeRLzMDXCd3Iv1FOU12PnQEwUMs1CqgoFon5wm5DQKans_VX82sRL3paylKoTmwXBqRLHJDRm3Q68BN7uTo5W54RaZYMaVrp9OxW13Op1lURELMYcOJsg1DdwmcwWM9Vm2mJ7yTp9TPmu4QltBNV6teHuTB0wKrf24vGFn_9gNfDBMu98Jkgel8fRhfnz_sJsVJPiATzLIMrSUbK512GN4ObkPcW-iV77fm2ifBu2HPc9Z76WPkI2arBew Feb 11 22:02:24 volumio sudo[26973]: pam_unix(sudo:session): session closed for user root Feb 11 22:02:24 volumio volumio[26691]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 11 22:02:24 volumio volumio[26691]: info: Shairport-Sync Started Feb 11 22:02:24 volumio volumio[26691]: Error adding Membership: Error: addMembership EINVAL Feb 11 22:02:24 volumio volumio[26691]: info: Shairport-Sync Started Feb 11 22:02:24 volumio volumio[26691]: info: Shairport-Sync Started Feb 11 22:02:24 volumio volumio[26691]: info: CoreCommandRouter::volumioGetState Feb 11 22:02:24 volumio volumio[26691]: info: CorePlayQueue::getTrack 0 Feb 11 22:02:24 volumio volumio[26691]: 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 11 22:02:24 volumio volumio[26691]: info: Spotify Successfully logged in Feb 11 22:02:24 volumio volumio[26691]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 22:02:24 volumio volumio[26691]: info: [1770822144908] CoreMusicLibrary::Adding element Spotify Feb 11 22:02:24 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 22:02:24 volumio volumio[26691]: Cannot find translation for source YouTube Music Feb 11 22:02:24 volumio volumio[26691]: Cannot find translation for source Spotify Feb 11 22:02:25 volumio volumio[26691]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 11 22:02:25 volumio volumio[26691]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 22:02:25 volumio volumio[26691]: info: VolumeController:: Volume=100 Mute =false Feb 11 22:02:25 volumio volumio[26691]: info: CoreCommandRouter::volumioGetState Feb 11 22:02:25 volumio volumio[26691]: info: CorePlayQueue::getTrack 0 Feb 11 22:02:25 volumio volumio[26691]: info: CoreStateMachine::pushState Feb 11 22:02:25 volumio volumio[26691]: info: CorePlayQueue::getTrack 0 Feb 11 22:02:25 volumio volumio[26691]: info: CoreCommandRouter::volumioPushState Feb 11 22:02:26 volumio nmbd[966]: [2026/02/11 22:02:26.007531, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Feb 11 22:02:26 volumio nmbd[966]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.1.23 for name WORKGROUP<1d>. Feb 11 22:02:26 volumio nmbd[966]: This response was from IP 192.168.1.237, reporting an IP address of 192.168.1.237. Feb 11 22:02:26 volumio volumio[26691]: info: go-librespot daemon successfully initialized Feb 11 22:02:27 volumio mpd[26915]: 2026-02-11T22:02:27 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 11 22:02:27 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 11 22:02:27 volumio sudo[26875]: pam_unix(sudo:session): session closed for user root Feb 11 22:02:27 volumio sudo[26886]: pam_unix(sudo:session): session closed for user root Feb 11 22:02:27 volumio volumio[26691]: error: MPD error: The expression evaluated to a falsy value: Feb 11 22:02:27 volumio volumio[26691]: assert.ok(self.idling) Feb 11 22:02:27 volumio volumio[26691]: error: The expression evaluated to a falsy value: Feb 11 22:02:27 volumio volumio[26691]: assert.ok(self.idling) Feb 11 22:02:27 volumio volumio[26691]: info: MPD running with PID26915 Feb 11 22:02:27 volumio volumio[26691]: ,establishing connection Feb 11 22:02:27 volumio volumio[26691]: error: updateQueue error: null Feb 11 22:02:27 volumio volumio[26691]: info: Completed starting Core Plugins Feb 11 22:02:27 volumio volumio[26691]: info: ------------------------------------------- Feb 11 22:02:27 volumio volumio[26691]: info: ----- MyVolumio plugins startup ---- Feb 11 22:02:27 volumio volumio[26691]: info: ------------------------------------------- Feb 11 22:02:27 volumio volumio[26691]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 11 22:02:27 volumio volumio[26691]: error: updateQueue error: null Feb 11 22:02:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 11 22:02:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:02:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:02:27 volumio go-librespot[27014]: go-librespot daemon starting... Feb 11 22:02:27 volumio go-librespot[27015]: time="2026-02-11T22:02:27+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 22:02:27 volumio go-librespot[27015]: time="2026-02-11T22:02:27+07:00" level=debug msg="app state loaded" Feb 11 22:02:27 volumio go-librespot[27015]: time="2026-02-11T22:02:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 22:02:28 volumio go-librespot[27015]: time="2026-02-11T22:02:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 22:02:28 volumio go-librespot[27015]: time="2026-02-11T22:02:28+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 22:02:28 volumio go-librespot[27015]: time="2026-02-11T22:02:28+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 22:02:28 volumio go-librespot[27015]: time="2026-02-11T22:02:28+07:00" level=info msg="zeroconf server listening on port 36511" Feb 11 22:02:28 volumio go-librespot[27015]: time="2026-02-11T22:02:28+07:00" level=debug msg="obtained new client token: AACxnmiYbKCntwx16UICF0/pNSTgvnxuQ5PZveZPBwdp5qWfOTGWccN4hEzXyKZfgfhDwQzv1cLPYjrZQU8kHRNv1kR2qQuOF5/PKsuFQiyB/iMGo7jzOEkTKWalVHXksIN7LXxYvPRJoUlbtPS169ZvIvl1kwqVPjGHUD2R59sdWkoogSRoUc7GKLKwvuMCGsUVLWL6PylA/dkMj3ou+CJNryEZXIcRsPAmJr0hen3D8WEzrw1o3kzjlg==" Feb 11 22:02:28 volumio go-librespot[27015]: time="2026-02-11T22:02:28+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 11 22:02:28 volumio go-librespot[27015]: time="2026-02-11T22:02:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 11 22:02:28 volumio go-librespot[27015]: time="2026-02-11T22:02:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 22:02:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 22:02:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 22:02:29 volumio volumio[26691]: info: Initializing connection to go-librespot Websocket Feb 11 22:02:29 volumio volumio[26691]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 22:02:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 11 22:02:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:02:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:02:31 volumio go-librespot[27022]: go-librespot daemon starting... Feb 11 22:02:31 volumio go-librespot[27023]: time="2026-02-11T22:02:31+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 22:02:31 volumio go-librespot[27023]: time="2026-02-11T22:02:31+07:00" level=debug msg="app state loaded" Feb 11 22:02:31 volumio go-librespot[27023]: time="2026-02-11T22:02:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 22:02:32 volumio volumio[26691]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 11 22:02:32 volumio go-librespot[27023]: time="2026-02-11T22:02:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 22:02:32 volumio go-librespot[27023]: time="2026-02-11T22:02:32+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 11 22:02:32 volumio go-librespot[27023]: time="2026-02-11T22:02:32+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 11 22:02:32 volumio go-librespot[27023]: time="2026-02-11T22:02:32+07:00" level=info msg="zeroconf server listening on port 38449" Feb 11 22:02:32 volumio go-librespot[27023]: time="2026-02-11T22:02:32+07:00" level=debug msg="obtained new client token: AAAYclaR/WyqFu6ZNLZaqnkui7hXP04Zck8Wq25mPj98T+oNEmFy+4F+ZSGCm3742JiV65gLl8CZjRM4/sWKOn492xHhhciulf7pS1B4uwRnGXRAhY7igRamm+gov8YeaIf2mnkP5ll41TAs2TJ+PJzdw7NKWPX/PXHVgVEogkX6LmKy28A2iELsfqVukEigWNdewHmOmiS2XUDrK2x9yomJjNTAYzdCcTDEdgwPnYL1EM5M9w8wk9Ywsw==" Feb 11 22:02:32 volumio go-librespot[27023]: time="2026-02-11T22:02:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 22:02:32 volumio go-librespot[27023]: time="2026-02-11T22:02:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.23:57994->104.199.241.202:4070: read: connection reset by peer" Feb 11 22:02:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 22:02:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 22:02:32 volumio volumio[26691]: info: Initializing connection to go-librespot Websocket Feb 11 22:02:32 volumio volumio[26691]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 22:02:35 volumio volumio[26691]: info: Initializing connection to go-librespot Websocket Feb 11 22:02:35 volumio volumio[26691]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 22:02:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 11 22:02:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:02:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:02:36 volumio go-librespot[27031]: go-librespot daemon starting... Feb 11 22:02:36 volumio go-librespot[27032]: time="2026-02-11T22:02:36+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 22:02:36 volumio go-librespot[27032]: time="2026-02-11T22:02:36+07:00" level=debug msg="app state loaded" Feb 11 22:02:36 volumio go-librespot[27032]: time="2026-02-11T22:02:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 22:02:36 volumio volumio[26691]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 11 22:02:36 volumio volumio[26691]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 11 22:02:36 volumio volumio[26691]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 11 22:02:36 volumio volumio[26691]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 11 22:02:36 volumio volumio[26691]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 11 22:02:36 volumio volumio[26691]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 11 22:02:36 volumio volumio[26691]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 11 22:02:36 volumio volumio[26691]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 11 22:02:36 volumio volumio[26691]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 11 22:02:36 volumio volumio[26691]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 11 22:02:36 volumio volumio[26691]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 11 22:02:36 volumio volumio[26691]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 11 22:02:36 volumio volumio[26691]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 11 22:02:36 volumio volumio[26691]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 11 22:02:36 volumio volumio[26691]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 11 22:02:36 volumio volumio[26691]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 11 22:02:36 volumio volumio[26691]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 11 22:02:36 volumio volumio[26691]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 11 22:02:36 volumio volumio[26691]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 11 22:02:36 volumio volumio[26691]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 11 22:02:36 volumio volumio[26691]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 11 22:02:36 volumio volumio[26691]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 11 22:02:36 volumio volumio[26691]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 11 22:02:36 volumio volumio[26691]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 11 22:02:36 volumio volumio[26691]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 11 22:02:36 volumio volumio[26691]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 11 22:02:36 volumio volumio[26691]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 11 22:02:36 volumio volumio[26691]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 11 22:02:36 volumio volumio[26691]: info: Adding plugin bluetooth to MyMusic Plugins Feb 11 22:02:36 volumio volumio[26691]: info: Adding plugin multiroom to MyMusic Plugins Feb 11 22:02:36 volumio volumio[26691]: info: Adding plugin metavolumio to MyMusic Plugins Feb 11 22:02:36 volumio volumio[26691]: info: Adding plugin cd_controller to MyMusic Plugins Feb 11 22:02:36 volumio volumio[26691]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 11 22:02:36 volumio volumio[26691]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 11 22:02:36 volumio volumio[26691]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 11 22:02:36 volumio volumio[26691]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 11 22:02:36 volumio go-librespot[27032]: time="2026-02-11T22:02:36+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 22:02:36 volumio go-librespot[27032]: time="2026-02-11T22:02:36+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 11 22:02:36 volumio go-librespot[27032]: time="2026-02-11T22:02:36+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 11 22:02:36 volumio go-librespot[27032]: time="2026-02-11T22:02:36+07:00" level=info msg="zeroconf server listening on port 34529" Feb 11 22:02:36 volumio go-librespot[27032]: time="2026-02-11T22:02:36+07:00" level=debug msg="obtained new client token: AABpe4odn7LeecrnU6iSHkQnTqQz5rYWvBaGyly6Jthd8fSL1mb9Dwxz7r0TcDIlNBEuF88eefFoha+eikq+X7aMr9XO+IA+Qe4Libji4H/I3vT0q5UvHyWX+rUcvj8MvfgtcVXSG4kboJACrT63vr8I6hxKL8xfM9b486kqFuxuJuu66FtfPEE3PmbXHSlShDcsKPco9i4heWSIkf1amIqj0ujtwMo7ArVOFRdMdnUbd8fWmYdp7/QYYw==" Feb 11 22:02:37 volumio go-librespot[27032]: time="2026-02-11T22:02:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 22:02:37 volumio go-librespot[27032]: time="2026-02-11T22:02:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 22:02:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 22:02:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 22:02:38 volumio volumio[26691]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 11 22:02:38 volumio volumio[26691]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 11 22:02:38 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 22:02:38 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 22:02:38 volumio volumio[26691]: info: Starting MyVolumio Remote Streaming Endpoints Feb 11 22:02:38 volumio volumio[26691]: info: MyVolumio login type: Token Feb 11 22:02:38 volumio volumio[26691]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 11 22:02:38 volumio volumio[26691]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 11 22:02:40 volumio volumio[26691]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 11 22:02:40 volumio volumio[26691]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 11 22:02:40 volumio volumio[26691]: info: Streaming services startup Feb 11 22:02:40 volumio volumio[26691]: info: Starting Streaming Daemon Feb 11 22:02:40 volumio sudo[27054]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 11 22:02:40 volumio volumio[26691]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 11 22:02:40 volumio sudo[27054]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:02:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 11 22:02:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:02:40 volumio volumio[26691]: info: Initializing connection to go-librespot Websocket Feb 11 22:02:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:02:40 volumio go-librespot[27060]: go-librespot daemon starting... Feb 11 22:02:40 volumio sudo[27054]: pam_unix(sudo:session): session closed for user root Feb 11 22:02:40 volumio volumio[26691]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 22:02:40 volumio volumio[26691]: error: Cannot start Volumio Streaming Daemon Feb 11 22:02:40 volumio volumio[26691]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 11 22:02:40 volumio volumio[26691]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 11 22:02:40 volumio go-librespot[27061]: time="2026-02-11T22:02:40+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 22:02:40 volumio go-librespot[27061]: time="2026-02-11T22:02:40+07:00" level=debug msg="app state loaded" Feb 11 22:02:40 volumio go-librespot[27061]: time="2026-02-11T22:02:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 22:02:40 volumio go-librespot[27061]: time="2026-02-11T22:02:40+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 11 22:02:40 volumio go-librespot[27061]: time="2026-02-11T22:02:40+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 11 22:02:40 volumio go-librespot[27061]: time="2026-02-11T22:02:40+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 11 22:02:40 volumio go-librespot[27061]: time="2026-02-11T22:02:40+07:00" level=info msg="zeroconf server listening on port 34387" Feb 11 22:02:41 volumio go-librespot[27061]: time="2026-02-11T22:02:41+07:00" level=debug msg="obtained new client token: AAAHZMcJy+9AX44Q5k+1Cg2Zbe+4aPBwmA3Fi2Uoj4F+8zDOhE6xm9xZ1VbuHsqsZemQPrYNb7VHcFLiPjClQFHHJbqRGDXxZn0WEAngtBAuJAUpc/HPcWFjvcQEsURmYLqJntzsYxfgd+gTe4zcum1uOuLuWeznPp4nmdQbBD7wiwz/rH83vqUUx0F2mU2n6yJAu/e3Ltc+8dg6fEg31/uOwYEkGWQfaWbJtcw0rkimWouXczSx7mg=" Feb 11 22:02:41 volumio go-librespot[27061]: time="2026-02-11T22:02:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 22:02:41 volumio go-librespot[27061]: time="2026-02-11T22:02:41+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 22:02:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 22:02:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 22:02:41 volumio volumio[26691]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 11 22:02:41 volumio volumio[26691]: info: MyVolumio token set successfully Feb 11 22:02:41 volumio volumio[26691]: info: MYVOLUMIO: Adding device Feb 11 22:02:41 volumio volumio[26691]: info: MYVOLUMIO: Evaluating Server Feb 11 22:02:42 volumio volumio[26691]: info: MyVolumio status changed Feb 11 22:02:42 volumio volumio[26691]: info: Streaming services startup Feb 11 22:02:42 volumio volumio[26691]: info: Starting Streaming Daemon Feb 11 22:02:42 volumio volumio[26691]: info: Removing browser output: myVolumio user plan is not superstar Feb 11 22:02:42 volumio volumio[26691]: info: Removing audio output: Feb 11 22:02:42 volumio volumio[26691]: info: Stoppping Tunnel 1 Feb 11 22:02:42 volumio sudo[27090]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 11 22:02:42 volumio sudo[27090]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:02:42 volumio sudo[27093]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 11 22:02:42 volumio sudo[27093]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:02:42 volumio sudo[27090]: pam_unix(sudo:session): session closed for user root Feb 11 22:02:42 volumio volumio[26691]: error: Cannot start Volumio Streaming Daemon Feb 11 22:02:42 volumio volumio[26691]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 11 22:02:42 volumio volumio[26691]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 11 22:02:42 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 11 22:02:42 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 11 22:02:42 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 11 22:02:42 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 11 22:02:42 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 11 22:02:42 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 11 22:02:42 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 11 22:02:42 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 11 22:02:42 volumio sudo[27093]: pam_unix(sudo:session): session closed for user root Feb 11 22:02:42 volumio volumio[26691]: info: Remote SSH Stopped Feb 11 22:02:43 volumio volumio[26691]: info: Setting Geolocation for MyVolumio to as1 Feb 11 22:02:43 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 22:02:43 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 22:02:43 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 22:02:43 volumio volumio[26691]: info: Initializing connection to go-librespot Websocket Feb 11 22:02:43 volumio volumio[26691]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 22:02:43 volumio volumio[26691]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 11 22:02:44 volumio volumio[26691]: info: Updating MyVolumio device info Feb 11 22:02:44 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 22:02:44 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 22:02:44 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 22:02:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 11 22:02:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:02:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:02:44 volumio go-librespot[27095]: go-librespot daemon starting... Feb 11 22:02:44 volumio go-librespot[27096]: time="2026-02-11T22:02:44+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 22:02:44 volumio go-librespot[27096]: time="2026-02-11T22:02:44+07:00" level=debug msg="app state loaded" Feb 11 22:02:44 volumio go-librespot[27096]: time="2026-02-11T22:02:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 22:02:44 volumio volumio[26691]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 11 22:02:44 volumio go-librespot[27096]: time="2026-02-11T22:02:44+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 11 22:02:44 volumio go-librespot[27096]: time="2026-02-11T22:02:44+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 11 22:02:44 volumio go-librespot[27096]: time="2026-02-11T22:02:44+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 11 22:02:44 volumio go-librespot[27096]: time="2026-02-11T22:02:44+07:00" level=info msg="zeroconf server listening on port 33743" Feb 11 22:02:45 volumio go-librespot[27096]: time="2026-02-11T22:02:45+07:00" level=debug msg="obtained new client token: AACIsd54MPMujmoX7U7F8lHayjtohOQ7iNM6sayQAg+sh8zo7/R7lX4vpKakGEUZrLxvsWANh7ula7sXIDf55GhuxFUg54qm3yIFe9FW6a4fPTV9Quw8VUpbjb5xyvh3kYVYrejlFmNqsGn+9EJrtsa87N3cyyJXAep1yTzbbLOTiGzIOZNAYjU4eQXooZnByMpu4fNuxU4sQopPfpDrwwRycvGO8cM2HW1yPWKYpTING/34iHUjS3I=" Feb 11 22:02:45 volumio go-librespot[27096]: time="2026-02-11T22:02:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 22:02:45 volumio go-librespot[27096]: time="2026-02-11T22:02:45+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 22:02:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 22:02:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 22:02:46 volumio volumio[26691]: info: Initializing connection to go-librespot Websocket Feb 11 22:02:46 volumio volumio[26691]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 22:02:47 volumio volumio[26691]: info: MYVOLUMIO: Adding device Feb 11 22:02:47 volumio volumio[26691]: info: MYVOLUMIO: Evaluating Server Feb 11 22:02:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 11 22:02:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:02:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:02:48 volumio go-librespot[27136]: go-librespot daemon starting... Feb 11 22:02:48 volumio go-librespot[27137]: time="2026-02-11T22:02:48+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 22:02:48 volumio go-librespot[27137]: time="2026-02-11T22:02:48+07:00" level=debug msg="app state loaded" Feb 11 22:02:48 volumio go-librespot[27137]: time="2026-02-11T22:02:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 22:02:48 volumio volumio[26691]: info: Setting Geolocation for MyVolumio to as1 Feb 11 22:02:48 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 22:02:48 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 22:02:48 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 22:02:48 volumio go-librespot[27137]: time="2026-02-11T22:02:48+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 11 22:02:48 volumio go-librespot[27137]: time="2026-02-11T22:02:48+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 11 22:02:48 volumio go-librespot[27137]: time="2026-02-11T22:02:48+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 11 22:02:48 volumio go-librespot[27137]: time="2026-02-11T22:02:48+07:00" level=info msg="zeroconf server listening on port 33095" Feb 11 22:02:49 volumio go-librespot[27137]: time="2026-02-11T22:02:49+07:00" level=debug msg="obtained new client token: AACrj5rDhr9cvMsENbmPpj3iGRyhq3K0ZIh6OAd7FnM2MBiYvrYVES+rBJ+bt/wD3m/PORbRMFe/ExjqwVqKltWQI7iK0/LmTXYUmufS1CqAQ3hgFZ7tQjmk0oxk2JVMQr+/47DKB+n6bW2opRxsBb72zo/iMHiYJGD7REDieaVZNM6S3p/fB3HTnXCpxR6kPB0u7IBdpvK6YZVCSRiyfUwuN6+dUkIXl8d4nFRh8ZFfGouL4Tr3E78=" Feb 11 22:02:49 volumio volumio[26691]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 11 22:02:49 volumio go-librespot[27137]: time="2026-02-11T22:02:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 22:02:49 volumio go-librespot[27137]: time="2026-02-11T22:02:49+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 22:02:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 22:02:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 22:02:49 volumio volumio[26691]: info: Initializing connection to go-librespot Websocket Feb 11 22:02:49 volumio volumio[26691]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 22:02:49 volumio volumio[26691]: info: Updating MyVolumio device info Feb 11 22:02:49 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 22:02:49 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 22:02:49 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 22:02:50 volumio volumio[26691]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 11 22:02:51 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 22:02:51 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 22:02:51 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 11 22:02:51 volumio volumio-remote-updater[643]: Test mode disabled Feb 11 22:02:51 volumio volumio-remote-updater[643]: Alpha mode disabled Feb 11 22:02:51 volumio volumio-remote-updater[643]: Alpha legacy test mode disabled Feb 11 22:02:51 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Feb 11 22:02:52 volumio volumio[26691]: info: Initializing connection to go-librespot Websocket Feb 11 22:02:52 volumio volumio[26691]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 22:02:52 volumio volumio[26691]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

FIXES

\n
    \n
  • Fix for CPU utilization spike
    • \n
  • Fix for triggerhappy input permission
    • \n
\n

NEW ADDITIONS

\n
    \n
  • Add BLE onboarding plugin
    • \n
  • Enable vc4-kms-v3d for all compatible RPi models
    • \n
  • Update Tidal SDK
    • \n
\n","title":"Update v4.096","updateavailable":true} Feb 11 22:02:52 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 11 22:02:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 11 22:02:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:02:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:02:52 volumio go-librespot[27149]: go-librespot daemon starting... Feb 11 22:02:52 volumio go-librespot[27150]: time="2026-02-11T22:02:52+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 22:02:52 volumio go-librespot[27150]: time="2026-02-11T22:02:52+07:00" level=debug msg="app state loaded" Feb 11 22:02:52 volumio go-librespot[27150]: time="2026-02-11T22:02:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 22:02:53 volumio go-librespot[27150]: time="2026-02-11T22:02:53+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 22:02:53 volumio go-librespot[27150]: time="2026-02-11T22:02:53+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 22:02:53 volumio go-librespot[27150]: time="2026-02-11T22:02:53+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 22:02:53 volumio go-librespot[27150]: time="2026-02-11T22:02:53+07:00" level=info msg="zeroconf server listening on port 33329" Feb 11 22:02:53 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 11 22:02:53 volumio volumio[26691]: 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 11 22:02:53 volumio go-librespot[27150]: time="2026-02-11T22:02:53+07:00" level=debug msg="obtained new client token: AADFeFeFvIQJMoCU8XS8Xt50I+B0YUO4mPrdMbOJ1tPz/ICLdcs/fVtxIt5O0vu3brCsQgBT1Dbn9IAtu9S5g1PiRtZ67YiSFmpqiRk99UbwWOpOQVXR2IMYQwCkDnrh3ztjxYJkmkbHYK8+cawf92Fd+/hnXclrQP/rJ910szFpEE/9S4mZ5gz9A3zn+RI/iL1R9ThdPprYtbbUeZYh9kXfLJ/1Ki8LJmXYLL1bjEFN8OaOj4buDfOLcA==" Feb 11 22:02:53 volumio volumio[26691]: info: CoreCommandRouter::volumioGetState Feb 11 22:02:53 volumio volumio[26691]: info: CorePlayQueue::getTrack 0 Feb 11 22:02:53 volumio go-librespot[27150]: time="2026-02-11T22:02:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 22:02:53 volumio go-librespot[27150]: time="2026-02-11T22:02:53+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 22:02:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 22:02:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 22:02:55 volumio volumio[26691]: info: Initializing connection to go-librespot Websocket Feb 11 22:02:55 volumio volumio[26691]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 22:02:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 11 22:02:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:02:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:02:56 volumio go-librespot[27171]: go-librespot daemon starting... Feb 11 22:02:56 volumio go-librespot[27172]: time="2026-02-11T22:02:56+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 22:02:56 volumio go-librespot[27172]: time="2026-02-11T22:02:56+07:00" level=debug msg="app state loaded" Feb 11 22:02:56 volumio go-librespot[27172]: time="2026-02-11T22:02:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 22:02:57 volumio go-librespot[27172]: time="2026-02-11T22:02:57+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 22:02:57 volumio go-librespot[27172]: time="2026-02-11T22:02:57+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 11 22:02:57 volumio go-librespot[27172]: time="2026-02-11T22:02:57+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 11 22:02:57 volumio go-librespot[27172]: time="2026-02-11T22:02:57+07:00" level=info msg="zeroconf server listening on port 41871" Feb 11 22:02:57 volumio go-librespot[27172]: time="2026-02-11T22:02:57+07:00" level=debug msg="obtained new client token: AAAU1ngkKNDifIQABUC59FfHvUmyEAi/8cNeQCP/wqFOeu983YiJAdOE2Qnu3dDmBuWGtyOLAqa/31zqlwQjhgLT6wOmFHt+CvPkzMfGLar7KD9MO+zq7tmoC+K1LQZJe6dhtZEDhLQyrmdoP7yTuPn6Yqal2xphZWwkcE7NQLfrpHUN334yfGDTCm5FKEK1VavdUNLv2LWIPJKFS2Y6tF9tTT+moezgguNfctLpfaQRBFMCJpP2cpzFEg==" Feb 11 22:02:57 volumio go-librespot[27172]: time="2026-02-11T22:02:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 22:02:57 volumio go-librespot[27172]: time="2026-02-11T22:02:57+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 22:02:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 22:02:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 22:02:58 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:02:58 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:02:58 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Feb 11 22:02:58 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Feb 11 22:02:58 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Feb 11 22:02:58 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Feb 11 22:02:58 volumio volumio[26691]: info: CoreCommandRouter::volumioGetBrowseSources Feb 11 22:02:58 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 22:02:58 volumio volumio[26691]: info: Initializing connection to go-librespot Websocket Feb 11 22:02:58 volumio volumio[26691]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 22:03:00 volumio volumio[26691]: error: MyVolumio Plugin failed to authenticate in a timely fashion Feb 11 22:03:00 volumio volumio[26691]: info: Completed starting MyVolumio Plugin Feb 11 22:03:00 volumio volumio[26691]: [Metrics] CommandRouter: 57s 689.78ms Feb 11 22:03:00 volumio volumio[26691]: info: CoreCommandRouter::volumiosetStartupVolume Feb 11 22:03:00 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:03:00 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 22:03:00 volumio volumio[26691]: info: CoreCommandRouter::Close All Modals sent Feb 11 22:03:00 volumio volumio[26691]: info: CoreCommandRouter::Close All Modals sent Feb 11 22:03:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 11 22:03:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:03:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:03:00 volumio go-librespot[27181]: go-librespot daemon starting... Feb 11 22:03:00 volumio go-librespot[27182]: time="2026-02-11T22:03:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 22:03:00 volumio go-librespot[27182]: time="2026-02-11T22:03:00+07:00" level=debug msg="app state loaded" Feb 11 22:03:00 volumio go-librespot[27182]: time="2026-02-11T22:03:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 22:03:01 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Feb 11 22:03:01 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 11 22:03:01 volumio volumio[26691]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Feb 11 22:03:01 volumio volumio[26691]: info: Initializing connection to go-librespot Websocket Feb 11 22:03:01 volumio go-librespot[27182]: time="2026-02-11T22:03:01+07:00" level=debug msg="new websocket client" Feb 11 22:03:01 volumio go-librespot[27182]: time="2026-02-11T22:03:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 22:03:01 volumio go-librespot[27182]: time="2026-02-11T22:03:01+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 22:03:01 volumio go-librespot[27182]: time="2026-02-11T22:03:01+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 22:03:01 volumio volumio[26691]: info: Connection to go-librespot Websocket established Feb 11 22:03:01 volumio go-librespot[27182]: time="2026-02-11T22:03:01+07:00" level=info msg="zeroconf server listening on port 34617" Feb 11 22:03:01 volumio go-librespot[27182]: time="2026-02-11T22:03:01+07:00" level=debug msg="obtained new client token: AADjiHaCrOlu3oNONJcPK7QJHfugtTm6CetLdElnJOVmd3EmjbgoQigUhuv5oMxsQIluutRFom1Kb1R/JtnVR1LoWg0fXZwhnuw1DJDSbhzaqgm6sEkvmNGxuqaORTh/M+9ohaCpBYlnM3Rq5MSWqQDNvhuginvDoVFrqSNPTYl+H07N3chRhLK2qf0x1hoblgn2B48QSdQd+0dSFsxZsT/Xuq9LqV8SSqDam20wSAI0CRt/ly4/thiC/A==" Feb 11 22:03:01 volumio go-librespot[27182]: time="2026-02-11T22:03:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 22:03:01 volumio go-librespot[27182]: time="2026-02-11T22:03:01+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 22:03:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 22:03:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 22:03:01 volumio volumio[26691]: info: Connection to go-librespot Websocket closed Feb 11 22:03:04 volumio volumio[26691]: info: Getting Spotify volume Feb 11 22:03:04 volumio volumio[26691]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 22:03:04 volumio volumio[26691]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 22:03:04 volumio volumio[26691]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 11 22:03:04 volumio volumio[26691]: errno: -111, Feb 11 22:03:04 volumio volumio[26691]: code: 'ECONNREFUSED', Feb 11 22:03:04 volumio volumio[26691]: syscall: 'connect', Feb 11 22:03:04 volumio volumio[26691]: address: '127.0.0.1', Feb 11 22:03:04 volumio volumio[26691]: port: 9879, Feb 11 22:03:04 volumio volumio[26691]: response: undefined Feb 11 22:03:04 volumio volumio[26691]: } Feb 11 22:03:04 volumio volumio[26691]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 22:03:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 11 22:03:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:03:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:03:05 volumio go-librespot[27201]: go-librespot daemon starting... Feb 11 22:03:05 volumio go-librespot[27202]: time="2026-02-11T22:03:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 22:03:05 volumio go-librespot[27202]: time="2026-02-11T22:03:05+07:00" level=debug msg="app state loaded" Feb 11 22:03:05 volumio go-librespot[27202]: time="2026-02-11T22:03:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 22:03:05 volumio go-librespot[27202]: time="2026-02-11T22:03:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 11 22:03:05 volumio go-librespot[27202]: time="2026-02-11T22:03:05+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 11 22:03:05 volumio go-librespot[27202]: time="2026-02-11T22:03:05+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 11 22:03:05 volumio go-librespot[27202]: time="2026-02-11T22:03:05+07:00" level=info msg="zeroconf server listening on port 41871" Feb 11 22:03:05 volumio sudo[27211]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-11 22:02' Feb 11 22:03:05 volumio sudo[27211]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:03:05 volumio go-librespot[27202]: time="2026-02-11T22:03:05+07:00" level=debug msg="obtained new client token: AACbxCEDj8ceLGNt/eGotWuNzfNGtWthPJmpkHIPDcP2xFeGFiNYzjq0dMQ5LncxboRH9R0GRZSEX8TX+fJWaKkw6/XxAzYBfpUzl5XBgiQPchDYCw2VhpH05DtsP6GJSbhL0SPobvd0NsuxhOoqJjFMwNPGWs3/cunrkWoW7ACYsB2uxxdXg3eVyRB7D+q2K6mQ3AlvsaNJszRjloFU+GedpH3Hng7GFc9DMTjCcxBkrK1kkAZ4+nM2JA==" Feb 11 22:03:06 volumio go-librespot[27202]: time="2026-02-11T22:03:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 22:03:06 volumio sudo[27211]: pam_unix(sudo:session): session closed for user root Feb 11 22:03:06 volumio go-librespot[27202]: time="2026-02-11T22:03:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 22:03:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 22:03:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 22:03:06 volumio volumio-remote-updater[643]: [2026-02-11 22:03:06] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 11 22:03:06 volumio volumio-remote-updater[643]: [2026-02-11 22:03:06] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 11 22:03:06 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 11 22:03:06 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 11 22:03:06 volumio systemd[1]: volumio.service: Consumed 59.786s CPU time. Feb 11 22:03:06 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 11 22:03:06 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 11 22:03:06 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 12273. Feb 11 22:03:06 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 11 22:03:06 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 11 22:03:06 volumio systemd[1]: volumio.service: Consumed 59.786s CPU time. Feb 11 22:03:06 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 11 22:03:06 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 11 22:03:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 11 22:03:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:03:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:03:09 volumio go-librespot[27245]: go-librespot daemon starting... Feb 11 22:03:09 volumio go-librespot[27246]: time="2026-02-11T22:03:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 22:03:09 volumio go-librespot[27246]: time="2026-02-11T22:03:09+07:00" level=debug msg="app state loaded" Feb 11 22:03:09 volumio go-librespot[27246]: time="2026-02-11T22:03:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 22:03:09 volumio go-librespot[27246]: time="2026-02-11T22:03:09+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 22:03:09 volumio go-librespot[27246]: time="2026-02-11T22:03:09+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 11 22:03:09 volumio go-librespot[27246]: time="2026-02-11T22:03:09+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 11 22:03:09 volumio go-librespot[27246]: time="2026-02-11T22:03:09+07:00" level=info msg="zeroconf server listening on port 34551" Feb 11 22:03:10 volumio go-librespot[27246]: time="2026-02-11T22:03:10+07:00" level=debug msg="obtained new client token: AABYoV3/DLxXabUUnf/paSXOYpqsmijfywAe1Ohn7tQQ5NzXV7bDP7buJs9PXtqiSITIzMsmD0BA6gCDy2DXyDEZmagi+djRqUqLigvXyOifEX/lBNbYFbg1NEWjPWgfN8jOUZA6lh02rxDTtk2nJUkE5XDTbzUCBsnJT7UCDD2hFwDIrC4ILISJcLhUA/vKCw6raDLjMPvxuzI8K5tbpALa02t9Hf8pkeQrgZ9QaKbFhvILeyQs2mA=" Feb 11 22:03:10 volumio volumio[27224]: info: ------------------------------------------- Feb 11 22:03:10 volumio volumio[27224]: info: ----- Volumio3 ---- Feb 11 22:03:10 volumio volumio[27224]: info: ------------------------------------------- Feb 11 22:03:10 volumio volumio[27224]: info: ----- System startup ---- Feb 11 22:03:10 volumio volumio[27224]: info: ------------------------------------------- Feb 11 22:03:10 volumio go-librespot[27246]: time="2026-02-11T22:03:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 22:03:10 volumio go-librespot[27246]: time="2026-02-11T22:03:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 22:03:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 22:03:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 22:03:11 volumio volumio-remote-updater[643]: [2026-02-11 22:03:11] [connect] Successful connection Feb 11 22:03:11 volumio volumio[27224]: info: MYVOLUMIO Environment detected Feb 11 22:03:11 volumio volumio[27224]: info: Plugin folders cleanup Feb 11 22:03:11 volumio volumio[27224]: info: Scanning into folder /volumio/app/plugins/ Feb 11 22:03:11 volumio volumio[27224]: info: Scanning category audio_interface Feb 11 22:03:11 volumio volumio[27224]: info: Scanning category miscellanea Feb 11 22:03:11 volumio volumio[27224]: info: Scanning category music_service Feb 11 22:03:11 volumio volumio[27224]: info: Scanning category plugins.json Feb 11 22:03:11 volumio volumio[27224]: info: Scanning category system_controller Feb 11 22:03:11 volumio volumio[27224]: info: Scanning category user_interface Feb 11 22:03:11 volumio volumio[27224]: info: Scanning into folder /data/plugins/ Feb 11 22:03:11 volumio volumio[27224]: info: Scanning category music_service Feb 11 22:03:11 volumio volumio[27224]: info: Plugin folders cleanup completed Feb 11 22:03:11 volumio volumio[27224]: info: ------------------------------------------- Feb 11 22:03:11 volumio volumio[27224]: info: ----- Core plugins startup ---- Feb 11 22:03:11 volumio volumio[27224]: info: ------------------------------------------- Feb 11 22:03:11 volumio volumio[27224]: info: Loading plugins from folder /volumio/app/plugins/ Feb 11 22:03:11 volumio volumio[27224]: info: Adding plugin upnp to MyMusic Plugins Feb 11 22:03:11 volumio volumio[27224]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 11 22:03:11 volumio volumio[27224]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 11 22:03:11 volumio volumio[27224]: info: Loading plugins from folder /data/plugins/ Feb 11 22:03:11 volumio volumio[27224]: info: Loading plugin "system"... Feb 11 22:03:11 volumio volumio[27224]: info: Loading plugin "appearance"... Feb 11 22:03:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 11 22:03:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:03:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:03:13 volumio go-librespot[27265]: go-librespot daemon starting... Feb 11 22:03:13 volumio go-librespot[27266]: time="2026-02-11T22:03:13+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 22:03:13 volumio go-librespot[27266]: time="2026-02-11T22:03:13+07:00" level=debug msg="app state loaded" Feb 11 22:03:13 volumio go-librespot[27266]: time="2026-02-11T22:03:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 22:03:13 volumio volumio[27224]: info: Loading plugin "network"... Feb 11 22:03:13 volumio volumio[27224]: info: Refreshing Cached IP Addresses Feb 11 22:03:13 volumio sudo[27274]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 22:03:13 volumio sudo[27274]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:03:13 volumio sudo[27276]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 22:03:13 volumio sudo[27274]: pam_unix(sudo:session): session closed for user root Feb 11 22:03:13 volumio sudo[27276]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:03:13 volumio volumio[27224]: info: Loading plugin "services"... Feb 11 22:03:13 volumio sudo[27276]: pam_unix(sudo:session): session closed for user root Feb 11 22:03:13 volumio volumio[27224]: info: Loading plugin "alsa_controller"... Feb 11 22:03:14 volumio sudo[27285]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 11 22:03:14 volumio sudo[27285]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:03:14 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 22:03:14 volumio volumio[27224]: info: Loading plugin "wizard"... Feb 11 22:03:14 volumio volumio[27224]: info: Loading plugin "networkfs"... Feb 11 22:03:14 volumio volumio[27224]: info: Starting Udev Watcher for removable devices Feb 11 22:03:14 volumio go-librespot[27266]: time="2026-02-11T22:03:14+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 22:03:14 volumio go-librespot[27266]: time="2026-02-11T22:03:14+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 22:03:14 volumio go-librespot[27266]: time="2026-02-11T22:03:14+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 22:03:14 volumio go-librespot[27266]: time="2026-02-11T22:03:14+07:00" level=info msg="zeroconf server listening on port 38159" Feb 11 22:03:14 volumio volumio[27224]: info: Ignoring mount for partition: boot Feb 11 22:03:14 volumio volumio[27224]: info: Ignoring mount for partition: volumio Feb 11 22:03:14 volumio volumio[27224]: info: Ignoring mount for partition: volumio_data Feb 11 22:03:14 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 22:03:14 volumio volumio[27224]: info: Loading plugin "volumio_command_line_client"... Feb 11 22:03:14 volumio volumio[27224]: info: Loading plugin "upnp"... Feb 11 22:03:14 volumio volumio[27224]: info: [1770822194350] Starting Upmpd Daemon Feb 11 22:03:14 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 22:03:14 volumio volumio[27224]: info: Loading plugin "my_music"... Feb 11 22:03:14 volumio volumio[27224]: info: Loading plugin "mpd"... Feb 11 22:03:14 volumio go-librespot[27266]: time="2026-02-11T22:03:14+07:00" level=debug msg="obtained new client token: AAC43nKgDX5d6P2iw2NGypqq3crqGPQ/7rM0Vj4mkkBP6uuLjasTQXzsInwOjw7dBVeurV7cUlSZYoZx74lodhdDzlTgozG4JuuE9lRSG3/F0RV6INin9psT+9T7I6xltxxkRdEqFE/PAKiCD7BO8m5cUqxjQD0Wfd/Q4TLgGV74JkeKalZN+PeVBzraL32Hi8mJ55FM8Srp9mMI40R7JMClg6JoYLHBxwEDageYPkS6WqSgtdo1CjUA8g==" Feb 11 22:03:14 volumio go-librespot[27266]: time="2026-02-11T22:03:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 22:03:14 volumio go-librespot[27266]: time="2026-02-11T22:03:14+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 22:03:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 22:03:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 22:03:15 volumio volumio[27224]: info: Loading plugin "upnp_browser"... Feb 11 22:03:16 volumio sudo[27285]: pam_unix(sudo:session): session closed for user root Feb 11 22:03:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 11 22:03:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:03:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:03:17 volumio go-librespot[27307]: go-librespot daemon starting... Feb 11 22:03:17 volumio go-librespot[27308]: time="2026-02-11T22:03:17+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 22:03:17 volumio go-librespot[27308]: time="2026-02-11T22:03:17+07:00" level=debug msg="app state loaded" Feb 11 22:03:17 volumio go-librespot[27308]: time="2026-02-11T22:03:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 22:03:17 volumio volumio[27224]: info: Starting UPNP Browser Feb 11 22:03:17 volumio volumio[27224]: info: Loading plugin "alarm-clock"... Feb 11 22:03:18 volumio volumio[27224]: info: Loading plugin "airplay_emulation"... Feb 11 22:03:18 volumio volumio[27224]: info: Starting Shairport Sync Feb 11 22:03:18 volumio volumio[27224]: info: Loading plugin "last_100"... Feb 11 22:03:18 volumio volumio[27224]: info: Loading plugin "webradio"... Feb 11 22:03:18 volumio go-librespot[27308]: time="2026-02-11T22:03:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 11 22:03:18 volumio go-librespot[27308]: time="2026-02-11T22:03:18+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 11 22:03:18 volumio go-librespot[27308]: time="2026-02-11T22:03:18+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 11 22:03:18 volumio go-librespot[27308]: time="2026-02-11T22:03:18+07:00" level=info msg="zeroconf server listening on port 34023" Feb 11 22:03:18 volumio volumio[27224]: info: Loading plugin "i2s_dacs"... Feb 11 22:03:18 volumio volumio[27224]: info: Loading plugin "volumiodiscovery"... Feb 11 22:03:18 volumio volumio[27224]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 11 22:03:18 volumio volumio[27224]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 22:03:18 volumio volumio[27224]: *** WARNING *** For more information see Feb 11 22:03:18 volumio volumio[27224]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 11 22:03:18 volumio volumio[27224]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 22:03:18 volumio volumio[27224]: *** WARNING *** For more information see Feb 11 22:03:18 volumio node[27224]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 11 22:03:18 volumio node[27224]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 22:03:18 volumio node[27224]: *** WARNING *** For more information see Feb 11 22:03:18 volumio node[27224]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 11 22:03:18 volumio node[27224]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 22:03:18 volumio node[27224]: *** WARNING *** For more information see Feb 11 22:03:18 volumio volumio[27224]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 11 22:03:18 volumio volumio[27224]: info: Discovery: Started advertising with name: Volumio Feb 11 22:03:18 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 22:03:18 volumio volumio[27224]: info: Loading plugin "spop"... Feb 11 22:03:18 volumio go-librespot[27308]: time="2026-02-11T22:03:18+07:00" level=debug msg="obtained new client token: AADmmmxppZ8SFpgPDKmLQDX+jDDEJR9J06n1M8gTZAu25waq2J3puUg96lMooWy5iaq9N0/rCbq1aS4Yc+jR9PyS7T4aaJnIuXg3m++24ksCVvs8tlmy5qDiwrFC5cF1xWSjmCM2Ajs0wO5WJR6h+Eri3WyiVFYRgwo3esCV8MLlqISazv9CVmsQes5BcBFCjFhIs4kK6m4UcFG7osfDjLSRk6angOIdvM2+Bg7upXD1MlNEph5EH7HXSg==" Feb 11 22:03:18 volumio go-librespot[27308]: time="2026-02-11T22:03:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 22:03:18 volumio go-librespot[27308]: time="2026-02-11T22:03:18+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 22:03:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 22:03:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 22:03:20 volumio volumio[27224]: info: Loading plugin "ytcr"... Feb 11 22:03:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 11 22:03:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:03:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:03:22 volumio go-librespot[27319]: go-librespot daemon starting... Feb 11 22:03:22 volumio go-librespot[27320]: time="2026-02-11T22:03:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 22:03:22 volumio go-librespot[27320]: time="2026-02-11T22:03:22+07:00" level=debug msg="app state loaded" Feb 11 22:03:22 volumio go-librespot[27320]: time="2026-02-11T22:03:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 22:03:22 volumio go-librespot[27320]: time="2026-02-11T22:03:22+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 11 22:03:22 volumio go-librespot[27320]: time="2026-02-11T22:03:22+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 11 22:03:22 volumio go-librespot[27320]: time="2026-02-11T22:03:22+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 11 22:03:22 volumio go-librespot[27320]: time="2026-02-11T22:03:22+07:00" level=info msg="zeroconf server listening on port 38041" Feb 11 22:03:22 volumio go-librespot[27320]: time="2026-02-11T22:03:22+07:00" level=debug msg="obtained new client token: AADp79vkWezglpGUjhmB7g/OPn87peqoDwI6NFEkhyhxVQ7pch+qt9vHhIs2vMRyycrV4t85dZdzoZbgPhMaAWroqmNzj13MUN3oo8hYA+NxiB1DmTt1jWxOF6k9hHye6NK8POvN15yT6QZXIBj3PUs6NEKbGwjP0KdEVxCIFs1elUz1KTzU1k05BM5aQQDqRoH5O9cU+/KXNipIeNcaMOMXJ4R1Ffagp3j264zH5VGLiwacSpB4zq+Xxw==" Feb 11 22:03:23 volumio go-librespot[27320]: time="2026-02-11T22:03:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 22:03:23 volumio go-librespot[27320]: time="2026-02-11T22:03:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 22:03:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 22:03:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 22:03:23 volumio volumio[27224]: info: Loading plugin "ytmusic"... Feb 11 22:03:23 volumio volumio-remote-updater[643]: [2026-02-11 22:03:23] [connect] Successful connection Feb 11 22:03:24 volumio volumio[27224]: info: Loading plugin "outputs"... Feb 11 22:03:24 volumio volumio[27224]: info: Loading plugin "albumart"... Feb 11 22:03:24 volumio volumio[27224]: info: Plugin example_plugin is not enabled Feb 11 22:03:24 volumio volumio[27224]: info: Loading plugin "inputs"... Feb 11 22:03:24 volumio volumio[27224]: info: Loading plugin "updater_comm"... Feb 11 22:03:24 volumio volumio[27224]: info: Plugin mpdemulation is not enabled Feb 11 22:03:24 volumio volumio[27224]: info: Loading plugin "rest_api"... Feb 11 22:03:24 volumio volumio[27224]: info: Loading plugin "websocket"... Feb 11 22:03:24 volumio volumio[27224]: info: Starting Socket.io Server version 1.7.4 Feb 11 22:03:24 volumio volumio[27224]: info: Loading plugin "RoonBridge"... Feb 11 22:03:25 volumio volumio[27224]: info: Applying required configuration parameters for plugin RoonBridge Feb 11 22:03:25 volumio volumio[27224]: info: Loading i18n strings for locale en Feb 11 22:03:25 volumio volumio[27224]: Updating browse sources language Feb 11 22:03:25 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 22:03:25 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 22:03:25 volumio volumio[27224]: info: CoreCommandRouter::initPlayerControls Feb 11 22:03:25 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:03:25 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:03:25 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:03:25 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:03:25 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:03:25 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:03:25 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:03:25 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:03:25 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 22:03:25 volumio volumio[27341]: Forking 3 albumart workers Feb 11 22:03:25 volumio volumio[27224]: Express server listening on port 3000 Feb 11 22:03:25 volumio volumio[27224]: [Metrics] WebUI: 16s 183.91ms Feb 11 22:03:25 volumio volumio[27224]: info: CoreStateMachine::resetVolumioState Feb 11 22:03:25 volumio volumio[27224]: info: CoreStateMachine::getcurrentVolume Feb 11 22:03:25 volumio volumio[27224]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 22:03:25 volumio sudo[27382]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 22:03:25 volumio volumio[27224]: info: Volumio Network Manager: Network status updated: 1 Feb 11 22:03:25 volumio sudo[27382]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:03:25 volumio sudo[27385]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 22:03:25 volumio sudo[27382]: pam_unix(sudo:session): session closed for user root Feb 11 22:03:25 volumio sudo[27385]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:03:25 volumio sudo[27385]: pam_unix(sudo:session): session closed for user root Feb 11 22:03:26 volumio volumio-remote-updater[643]: [2026-02-11 22:03:25] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770822203 101 Feb 11 22:03:26 volumio volumio[27224]: 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 11 22:03:26 volumio volumio[27224]: info: VolumeController:: Volume=100 Mute =false Feb 11 22:03:26 volumio volumio[27224]: info: CoreStateMachine::pushState Feb 11 22:03:26 volumio volumio[27224]: info: CorePlayQueue::getTrack 0 Feb 11 22:03:26 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 22:03:26 volumio volumio[27224]: info: CoreCommandRouter::volumioPushState Feb 11 22:03:26 volumio volumio[27224]: info: CoreStateMachine::updateTrackBlock Feb 11 22:03:26 volumio volumio[27224]: info: CorePlayQueue::getTrackBlock Feb 11 22:03:26 volumio volumio[27224]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 22:03:26 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 22:03:26 volumio volumio[27224]: info: Reloading queue from file Feb 11 22:03:26 volumio volumio[27224]: info: CoreStateMachine::setRepeat null single undefined Feb 11 22:03:26 volumio volumio[27224]: info: CoreStateMachine::pushState Feb 11 22:03:26 volumio volumio[27224]: info: CorePlayQueue::getTrack 0 Feb 11 22:03:26 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 22:03:26 volumio volumio[27224]: info: CoreCommandRouter::volumioPushState Feb 11 22:03:26 volumio volumio[27224]: info: CoreStateMachine::setRandom null Feb 11 22:03:26 volumio volumio[27224]: info: CoreStateMachine::pushState Feb 11 22:03:26 volumio volumio[27224]: info: CorePlayQueue::getTrack 0 Feb 11 22:03:26 volumio volumio[27224]: info: CoreCommandRouter::volumioPushState Feb 11 22:03:26 volumio volumio[27224]: info: Setting Device type: Raspberry PI Feb 11 22:03:26 volumio volumio[27224]: info: Completed loading Core Plugins Feb 11 22:03:26 volumio volumio[27224]: info: Preparing to generate the ALSA configuration file Feb 11 22:03:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 11 22:03:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:03:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:03:26 volumio go-librespot[27400]: go-librespot daemon starting... Feb 11 22:03:26 volumio volumio[27224]: info: VolumeController:: Volume=100 Mute =false Feb 11 22:03:26 volumio volumio[27224]: info: CoreStateMachine::pushState Feb 11 22:03:26 volumio volumio[27224]: info: CorePlayQueue::getTrack 0 Feb 11 22:03:26 volumio volumio[27224]: info: CoreCommandRouter::volumioPushState Feb 11 22:03:26 volumio volumio[27224]: info: Asound.conf file unchanged, so no further update is needed Feb 11 22:03:26 volumio volumio[27224]: info: Output device has changed, restarting MPD Feb 11 22:03:26 volumio go-librespot[27403]: time="2026-02-11T22:03:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 22:03:26 volumio go-librespot[27403]: time="2026-02-11T22:03:26+07:00" level=debug msg="app state loaded" Feb 11 22:03:26 volumio go-librespot[27403]: time="2026-02-11T22:03:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 22:03:26 volumio volumio[27224]: info: Output device has changed, restarting Shairport Sync Feb 11 22:03:26 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:03:26 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 22:03:26 volumio sudo[27405]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 11 22:03:26 volumio sudo[27405]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:03:26 volumio volumio[27224]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 22:03:26 volumio sudo[27412]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 22:03:26 volumio sudo[27412]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:03:26 volumio volumio[27224]: info: ___________ START PLUGINS ___________ Feb 11 22:03:26 volumio sudo[27414]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 22:03:26 volumio sudo[27414]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:03:26 volumio sudo[27412]: pam_unix(sudo:session): session closed for user root Feb 11 22:03:26 volumio volumio[27224]: info: ControllerMpd::onStart: Initializing MPD Feb 11 22:03:26 volumio volumio[27224]: info: Creating MPD Configuration file Feb 11 22:03:26 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 22:03:26 volumio volumio[27224]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 22:03:26 volumio sudo[27405]: pam_unix(sudo:session): session closed for user root Feb 11 22:03:26 volumio volumio[27224]: info: [1770822206766] CoreMusicLibrary::Adding element Media Servers Feb 11 22:03:26 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 22:03:26 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 11 22:03:26 volumio volumio[27224]: info: UPNP Browser: Client initialized successfully Feb 11 22:03:26 volumio sudo[27423]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 22:03:26 volumio sudo[27425]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 22:03:26 volumio sudo[27423]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:03:26 volumio sudo[27425]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:03:26 volumio sudo[27423]: pam_unix(sudo:session): session closed for user root Feb 11 22:03:26 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 11 22:03:26 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 11 22:03:26 volumio systemd[1]: mpd.service: Consumed 7.051s CPU time. Feb 11 22:03:26 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 11 22:03:26 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 11 22:03:26 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 11 22:03:26 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:03:26 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 22:03:27 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 11 22:03:27 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 11 22:03:27 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 11 22:03:27 volumio volumio[27224]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 22:03:27 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 11 22:03:27 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 11 22:03:27 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:03:27 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 11 22:03:27 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 11 22:03:27 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 22:03:27 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 11 22:03:27 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 11 22:03:27 volumio volumio[27224]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 22:03:27 volumio volumio[27224]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 22:03:27 volumio volumio[27224]: info: [1770822207229] CoreMusicLibrary::Adding element Last_100 Feb 11 22:03:27 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 22:03:27 volumio volumio[27224]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 22:03:27 volumio volumio[27224]: info: [1770822207251] CoreMusicLibrary::Adding element Webradio Feb 11 22:03:27 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 22:03:27 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 22:03:27 volumio go-librespot[27403]: time="2026-02-11T22:03:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 22:03:27 volumio go-librespot[27403]: time="2026-02-11T22:03:27+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 11 22:03:27 volumio go-librespot[27403]: time="2026-02-11T22:03:27+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 11 22:03:27 volumio volumio[27224]: info: Initializing BBC Radios Feb 11 22:03:27 volumio go-librespot[27403]: time="2026-02-11T22:03:27+07:00" level=info msg="zeroconf server listening on port 36873" Feb 11 22:03:27 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 22:03:27 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 22:03:27 volumio volumio[27224]: info: Creating Spotify config file Feb 11 22:03:27 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:03:27 volumio go-librespot[27403]: time="2026-02-11T22:03:27+07:00" level=debug msg="obtained new client token: AABEptdzlzxGtLSJojGMeFuYMFihuajOTnzsFFIcw0XnXzR3f7yGrEyLaoc7zeKnlXxzAeyJ/N0MmOdsL0xnriEegVjg2c8fnMm/p3Rhm+BaIYFZSzB8ICM1hUMiXuOs2f2WhCLecXQN42z1f5phgjwQgRZ+OvqxZC8jFBecBlzPdHImztj9K/HN0KopIXR1mJITZyCsWy75FJgC4VA3F1qOPhzcgVwgQOLIzpHbpkIIbDNgMcJ4Rgu0RA==" Feb 11 22:03:27 volumio sudo[27439]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 11 22:03:27 volumio sudo[27439]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 11 22:03:27 volumio sudo[27439]: pam_unix(sudo:session): session closed for user root Feb 11 22:03:27 volumio go-librespot[27403]: time="2026-02-11T22:03:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 22:03:27 volumio go-librespot[27403]: time="2026-02-11T22:03:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 22:03:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 22:03:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 22:03:28 volumio volumio[27224]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 22:03:28 volumio volumio[27224]: info: [1770822208794] CoreMusicLibrary::Adding element YouTube Music Feb 11 22:03:28 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 22:03:28 volumio volumio[27224]: Cannot find translation for source YouTube Music Feb 11 22:03:28 volumio volumio[27224]: info: Volumio Calling Home Feb 11 22:03:28 volumio volumio[27356]: Starting albumart workers Feb 11 22:03:28 volumio sudo[27459]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 11 22:03:28 volumio sudo[27459]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:03:29 volumio sudo[27459]: pam_unix(sudo:session): session closed for user root Feb 11 22:03:29 volumio volumio[27354]: Starting albumart workers Feb 11 22:03:29 volumio volumio[27351]: Starting albumart workers Feb 11 22:03:29 volumio volumio[27224]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 11 22:03:29 volumio volumio[27224]: info: Discovery: Found device Volumio Feb 11 22:03:29 volumio volumio[27224]: info: CoreCommandRouter::volumioGetState Feb 11 22:03:29 volumio volumio[27224]: info: CorePlayQueue::getTrack 0 Feb 11 22:03:29 volumio volumio[27224]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 11 22:03:29 volumio volumio[27224]: info: Discovery: Found device Volumio Feb 11 22:03:29 volumio volumio[27224]: info: CoreCommandRouter::volumioGetState Feb 11 22:03:29 volumio volumio[27224]: info: CorePlayQueue::getTrack 0 Feb 11 22:03:29 volumio volumio[27224]: info: MPD Permissions set Feb 11 22:03:29 volumio volumio[27224]: info: MPD Permissions set Feb 11 22:03:29 volumio volumio[27224]: info: Upmpdcli Daemon Started Feb 11 22:03:29 volumio volumio[27224]: info: Spotify config file written Feb 11 22:03:29 volumio volumio[27224]: 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 11 22:03:29 volumio volumio[27224]: info: Volumio called home Feb 11 22:03:29 volumio sudo[27465]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 11 22:03:29 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:03:29 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:03:29 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:03:29 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:03:29 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:03:29 volumio sudo[27465]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:03:29 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:03:29 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:03:29 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:03:30 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 22:03:30 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:03:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:03:30 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:03:30 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:03:30 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:03:30 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:03:30 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:03:30 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:03:30 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:03:30 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:03:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:03:30 volumio go-librespot[27472]: go-librespot daemon starting... Feb 11 22:03:30 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 22:03:30 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 22:03:30 volumio volumio[27224]: info: No need to fix Spotify hosts Feb 11 22:03:30 volumio go-librespot[27478]: time="2026-02-11T22:03:30+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 22:03:30 volumio go-librespot[27478]: time="2026-02-11T22:03:30+07:00" level=debug msg="app state loaded" Feb 11 22:03:30 volumio sudo[27465]: pam_unix(sudo:session): session closed for user root Feb 11 22:03:30 volumio go-librespot[27478]: time="2026-02-11T22:03:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 22:03:30 volumio go-librespot[27478]: time="2026-02-11T22:03: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 22:03:30 volumio go-librespot[27478]: time="2026-02-11T22:03:30+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 11 22:03:30 volumio go-librespot[27478]: time="2026-02-11T22:03:30+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 11 22:03:30 volumio go-librespot[27478]: time="2026-02-11T22:03:30+07:00" level=info msg="zeroconf server listening on port 40845" Feb 11 22:03:31 volumio go-librespot[27478]: time="2026-02-11T22:03:31+07:00" level=debug msg="obtained new client token: AADWN0cecxdjotWKdchq1/hXyJYudtN+RkII/553Eai5vZZ9rPKpi/zfP0R6MmMp9tslxhJES8d8vc1sqoun4Gg5ez21ujM5/6BX7bY4WO/rmixNB9CAxWKq8KyW0cpx2AOMaeULI6lnkbCr8O8fTwOSsz9K+B7Mgw0Rae1rL7quSvoYXhAU8wGO6kJ4MKtMijnbzxKqecn2lxo2ijvBTbo5dLLHZO0YWvkYVox6+kIiSfLR/cWhSng=" Feb 11 22:03:31 volumio go-librespot[27478]: time="2026-02-11T22:03:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 22:03:31 volumio go-librespot[27478]: time="2026-02-11T22:03:31+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 22:03:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 22:03:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 22:03:31 volumio volumio[27224]: info: Starting Shairport Sync Feb 11 22:03:31 volumio volumio[27224]: info: Starting Shairport Sync Feb 11 22:03:31 volumio volumio[27224]: info: Starting Shairport Sync Feb 11 22:03:31 volumio sudo[27504]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 22:03:31 volumio sudo[27504]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:03:31 volumio sudo[27509]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 22:03:31 volumio sudo[27509]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:03:31 volumio sudo[27506]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 22:03:31 volumio sudo[27506]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:03:31 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 11 22:03:31 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 11 22:03:31 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 22:03:31 volumio systemd[1]: shairport-sync.service: Consumed 2.553s CPU time. Feb 11 22:03:31 volumio volumio[27224]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 11 22:03:31 volumio volumio[27224]: SPOTIFY: BQD-Si3CzIw6Tf68uFgvRRZ7u8rP0BzQNmMC_0MpUB70hJ65sQOtcqjQQYSg1ZOl_txb9pIraZkVIXJqqxlAzOBQywJDqHXSC8mMGs0cTFvE77GqDXMqIo0cnPylIwf0KMWwA3frT9UAeel05MuRaJHezbvgOjmOT4gUUIB3pWScGcT1UvY0w9LFjMpNqRGQxfpgmzmVNEIP49hBEq9S7eh7ugJnzF1-IZfNX0oizJdVTrz7PlJk8QVsyM5BqQhEBHjjt3fg1E0fak_QYWV-1KahM6caoaivXVWkCH_GKwMfXTjdjq9FIQ03 Feb 11 22:03:31 volumio volumio[27224]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 11 22:03:31 volumio volumio[27224]: info: New Spotify access token = BQD-Si3CzIw6Tf68uFgvRRZ7u8rP0BzQNmMC_0MpUB70hJ65sQOtcqjQQYSg1ZOl_txb9pIraZkVIXJqqxlAzOBQywJDqHXSC8mMGs0cTFvE77GqDXMqIo0cnPylIwf0KMWwA3frT9UAeel05MuRaJHezbvgOjmOT4gUUIB3pWScGcT1UvY0w9LFjMpNqRGQxfpgmzmVNEIP49hBEq9S7eh7ugJnzF1-IZfNX0oizJdVTrz7PlJk8QVsyM5BqQhEBHjjt3fg1E0fak_QYWV-1KahM6caoaivXVWkCH_GKwMfXTjdjq9FIQ03 Feb 11 22:03:31 volumio volumio[27224]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 11 22:03:32 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 22:03:32 volumio sudo[27509]: pam_unix(sudo:session): session closed for user root Feb 11 22:03:32 volumio sudo[27504]: pam_unix(sudo:session): session closed for user root Feb 11 22:03:32 volumio sudo[27506]: pam_unix(sudo:session): session closed for user root Feb 11 22:03:32 volumio volumio[27224]: info: CoreCommandRouter::volumioGetState Feb 11 22:03:32 volumio volumio[27224]: info: CorePlayQueue::getTrack 0 Feb 11 22:03:32 volumio volumio[27224]: info: Shairport-Sync Started Feb 11 22:03:32 volumio volumio[27224]: Error adding Membership: Error: addMembership EINVAL Feb 11 22:03:32 volumio volumio[27224]: info: Shairport-Sync Started Feb 11 22:03:32 volumio volumio[27224]: info: Shairport-Sync Started Feb 11 22:03:32 volumio volumio[27224]: 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 11 22:03:32 volumio volumio[27224]: info: Spotify Successfully logged in Feb 11 22:03:32 volumio volumio[27224]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 22:03:32 volumio volumio[27224]: info: [1770822212638] CoreMusicLibrary::Adding element Spotify Feb 11 22:03:32 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 22:03:32 volumio volumio[27224]: Cannot find translation for source YouTube Music Feb 11 22:03:32 volumio volumio[27224]: Cannot find translation for source Spotify Feb 11 22:03:33 volumio volumio[27224]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 11 22:03:33 volumio volumio[27224]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 22:03:33 volumio volumio[27224]: info: VolumeController:: Volume=100 Mute =false Feb 11 22:03:33 volumio volumio[27224]: info: CoreCommandRouter::volumioGetState Feb 11 22:03:33 volumio volumio[27224]: info: CorePlayQueue::getTrack 0 Feb 11 22:03:33 volumio volumio[27224]: info: CoreStateMachine::pushState Feb 11 22:03:33 volumio volumio[27224]: info: CorePlayQueue::getTrack 0 Feb 11 22:03:33 volumio volumio[27224]: info: CoreCommandRouter::volumioPushState Feb 11 22:03:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 11 22:03:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:03:34 volumio volumio[27224]: info: go-librespot daemon successfully initialized Feb 11 22:03:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:03:34 volumio go-librespot[27544]: go-librespot daemon starting... Feb 11 22:03:34 volumio go-librespot[27545]: time="2026-02-11T22:03:34+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 22:03:34 volumio go-librespot[27545]: time="2026-02-11T22:03:34+07:00" level=debug msg="app state loaded" Feb 11 22:03:34 volumio mpd[27457]: 2026-02-11T22:03:34 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 11 22:03:34 volumio go-librespot[27545]: time="2026-02-11T22:03:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 22:03:34 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 11 22:03:34 volumio sudo[27414]: pam_unix(sudo:session): session closed for user root Feb 11 22:03:34 volumio sudo[27425]: pam_unix(sudo:session): session closed for user root Feb 11 22:03:34 volumio volumio[27224]: error: MPD error: The expression evaluated to a falsy value: Feb 11 22:03:34 volumio volumio[27224]: assert.ok(self.idling) Feb 11 22:03:34 volumio volumio[27224]: error: The expression evaluated to a falsy value: Feb 11 22:03:34 volumio volumio[27224]: assert.ok(self.idling) Feb 11 22:03:34 volumio volumio[27224]: error: updateQueue error: null Feb 11 22:03:35 volumio volumio[27224]: info: MPD running with PID27457 Feb 11 22:03:35 volumio volumio[27224]: ,establishing connection Feb 11 22:03:35 volumio volumio[27224]: info: Completed starting Core Plugins Feb 11 22:03:35 volumio volumio[27224]: info: ------------------------------------------- Feb 11 22:03:35 volumio volumio[27224]: info: ----- MyVolumio plugins startup ---- Feb 11 22:03:35 volumio volumio[27224]: info: ------------------------------------------- Feb 11 22:03:35 volumio volumio[27224]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 11 22:03:35 volumio volumio[27224]: error: updateQueue error: null Feb 11 22:03:35 volumio go-librespot[27545]: time="2026-02-11T22:03:35+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 11 22:03:35 volumio go-librespot[27545]: time="2026-02-11T22:03:35+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 11 22:03:35 volumio go-librespot[27545]: time="2026-02-11T22:03:35+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 11 22:03:35 volumio go-librespot[27545]: time="2026-02-11T22:03:35+07:00" level=info msg="zeroconf server listening on port 39239" Feb 11 22:03:35 volumio go-librespot[27545]: time="2026-02-11T22:03:35+07:00" level=debug msg="obtained new client token: AAC+IpYxOhFihGsr7uT2DowrKGfey0EeW/52s3l1tTRly5GyPm0948JwsZm3ynxyzlaEj9OZbEVq553QsFAINbMmbK5ZUtmAC3LNVtQhmhHSZkzBkkU55XmbURYk9Zy3ueaWAxFJfQh2ivz3b3qLdPWTnAmEV5AuVjtCU/9g4Jp+kWtXE5516qsg758jcBWmjjuuj+2LrawWhU4F0F3NESd4Ceh3x9d2pgvHMtzyHsM5ZiBkEBilL6grZA==" Feb 11 22:03:35 volumio go-librespot[27545]: time="2026-02-11T22:03:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 22:03:35 volumio go-librespot[27545]: time="2026-02-11T22:03:35+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 22:03:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 22:03:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 22:03:37 volumio volumio[27224]: info: Initializing connection to go-librespot Websocket Feb 11 22:03:37 volumio volumio[27224]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 22:03:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Feb 11 22:03:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:03:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:03:38 volumio go-librespot[27556]: go-librespot daemon starting... Feb 11 22:03:38 volumio go-librespot[27557]: time="2026-02-11T22:03:38+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 22:03:38 volumio go-librespot[27557]: time="2026-02-11T22:03:38+07:00" level=debug msg="app state loaded" Feb 11 22:03:38 volumio go-librespot[27557]: time="2026-02-11T22:03:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 22:03:39 volumio go-librespot[27557]: time="2026-02-11T22:03:39+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 22:03:39 volumio go-librespot[27557]: time="2026-02-11T22:03:39+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 11 22:03:39 volumio go-librespot[27557]: time="2026-02-11T22:03:39+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 11 22:03:39 volumio go-librespot[27557]: time="2026-02-11T22:03:39+07:00" level=info msg="zeroconf server listening on port 42259" Feb 11 22:03:39 volumio go-librespot[27557]: time="2026-02-11T22:03:39+07:00" level=debug msg="obtained new client token: AADvBiK5crJoW5iKRELBU5Wk5vXNXM+f3qbL9fWPiX/6hnWiNjTxePMhkvp5eLtWAa4n7B5JtRJCFzG7QICxGenFUNMif1bjAvkE3WhiGETti3hxeD5v8ITVeVMYafXw0BOY6ZY7ssRkZwtGK/6uFGBjxOLzWv1SqAVCRbkrAb9D/7NgG5Gb1HudG3xLqPmFisjbI+Ju7+O/dM0DbeGvsVGNqjkZ4wpsBHdxJsuT+nFGLnHFsPv4etRkAw==" Feb 11 22:03:39 volumio go-librespot[27557]: time="2026-02-11T22:03:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 22:03:39 volumio go-librespot[27557]: time="2026-02-11T22:03:39+07:00" level=debug msg="completed keyexchange" Feb 11 22:03:39 volumio go-librespot[27557]: time="2026-02-11T22:03:39+07:00" level=debug msg="completed challenge" Feb 11 22:03:39 volumio volumio[27224]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 11 22:03:39 volumio go-librespot[27557]: time="2026-02-11T22:03: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 11 22:03:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 22:03:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 22:03:40 volumio volumio[27224]: info: Initializing connection to go-librespot Websocket Feb 11 22:03:40 volumio volumio[27224]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 22:03:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Feb 11 22:03:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:03:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:03:43 volumio go-librespot[27564]: go-librespot daemon starting... Feb 11 22:03:43 volumio go-librespot[27565]: time="2026-02-11T22:03:43+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 22:03:43 volumio go-librespot[27565]: time="2026-02-11T22:03:43+07:00" level=debug msg="app state loaded" Feb 11 22:03:43 volumio go-librespot[27565]: time="2026-02-11T22:03:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 22:03:43 volumio go-librespot[27565]: time="2026-02-11T22:03:43+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 22:03:43 volumio go-librespot[27565]: time="2026-02-11T22:03:43+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 11 22:03:43 volumio go-librespot[27565]: time="2026-02-11T22:03:43+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 11 22:03:43 volumio go-librespot[27565]: time="2026-02-11T22:03:43+07:00" level=info msg="zeroconf server listening on port 34091" Feb 11 22:03:43 volumio volumio[27224]: info: Initializing connection to go-librespot Websocket Feb 11 22:03:43 volumio go-librespot[27565]: time="2026-02-11T22:03:43+07:00" level=debug msg="new websocket client" Feb 11 22:03:43 volumio volumio[27224]: info: Connection to go-librespot Websocket established Feb 11 22:03:43 volumio volumio[27224]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 11 22:03:43 volumio volumio[27224]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 11 22:03:43 volumio volumio[27224]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 11 22:03:43 volumio volumio[27224]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 11 22:03:43 volumio volumio[27224]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 11 22:03:43 volumio volumio[27224]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 11 22:03:43 volumio volumio[27224]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 11 22:03:43 volumio volumio[27224]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 11 22:03:43 volumio volumio[27224]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 11 22:03:43 volumio volumio[27224]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 11 22:03:43 volumio volumio[27224]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 11 22:03:43 volumio volumio[27224]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 11 22:03:43 volumio volumio[27224]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 11 22:03:43 volumio volumio[27224]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 11 22:03:43 volumio volumio[27224]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 11 22:03:43 volumio volumio[27224]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 11 22:03:43 volumio volumio[27224]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 11 22:03:43 volumio volumio[27224]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 11 22:03:43 volumio volumio[27224]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 11 22:03:43 volumio volumio[27224]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 11 22:03:43 volumio volumio[27224]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 11 22:03:43 volumio volumio[27224]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 11 22:03:43 volumio volumio[27224]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 11 22:03:43 volumio volumio[27224]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 11 22:03:43 volumio volumio[27224]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 11 22:03:43 volumio volumio[27224]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 11 22:03:43 volumio volumio[27224]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 11 22:03:43 volumio volumio[27224]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 11 22:03:43 volumio volumio[27224]: info: Adding plugin bluetooth to MyMusic Plugins Feb 11 22:03:43 volumio volumio[27224]: info: Adding plugin multiroom to MyMusic Plugins Feb 11 22:03:43 volumio volumio[27224]: info: Adding plugin metavolumio to MyMusic Plugins Feb 11 22:03:43 volumio volumio[27224]: info: Adding plugin cd_controller to MyMusic Plugins Feb 11 22:03:43 volumio volumio[27224]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 11 22:03:43 volumio volumio[27224]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 11 22:03:43 volumio volumio[27224]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 11 22:03:43 volumio volumio[27224]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 11 22:03:43 volumio go-librespot[27565]: time="2026-02-11T22:03:43+07:00" level=debug msg="obtained new client token: AAAZn7ZtVDr0pmpbshTszy3rwOTKcIS8jV6btu2Wpucesd0UU+2nYjeRWCTLmyiHYtWuluF2Yw5BmapMknYlmSbzGEoe+C8UYlmMCRUn+vFS+BLkg1YUQvsvu97y5h8gWgIpN9fB2hSQFKjwcjHuaPzGQJdW9sZno058FUkWKGzl/TgjWF926Z9TNn2M4ceQAdTrI2Xvjopskr5cFUDlXkah9LU7KDNGWOlV/y0AhrA+vz6DNw59Jpf48Q==" Feb 11 22:03:43 volumio go-librespot[27565]: time="2026-02-11T22:03:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 22:03:44 volumio go-librespot[27565]: time="2026-02-11T22:03:44+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 22:03:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 22:03:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 22:03:45 volumio volumio[27224]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 11 22:03:45 volumio volumio[27224]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 11 22:03:45 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 22:03:45 volumio volumio[27224]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 22:03:45 volumio volumio[27224]: info: Starting MyVolumio Remote Streaming Endpoints Feb 11 22:03:45 volumio volumio[27224]: info: MyVolumio login type: Token Feb 11 22:03:45 volumio volumio[27224]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 11 22:03:45 volumio volumio[27224]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 11 22:03:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Feb 11 22:03:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:03:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 22:03:47 volumio go-librespot[27589]: go-librespot daemon starting... Feb 11 22:03:47 volumio go-librespot[27590]: time="2026-02-11T22:03:47+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 22:03:47 volumio go-librespot[27590]: time="2026-02-11T22:03:47+07:00" level=debug msg="app state loaded" Feb 11 22:03:47 volumio go-librespot[27590]: time="2026-02-11T22:03:47+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 22:03:47 volumio volumio[27224]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 11 22:03:47 volumio volumio[27224]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 11 22:03:47 volumio volumio[27224]: info: Streaming services startup Feb 11 22:03:47 volumio volumio[27224]: info: Starting Streaming Daemon Feb 11 22:03:47 volumio sudo[27598]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 11 22:03:47 volumio sudo[27598]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 22:03:47 volumio volumio[27224]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 11 22:03:47 volumio sudo[27598]: pam_unix(sudo:session): session closed for user root Feb 11 22:03:47 volumio go-librespot[27590]: time="2026-02-11T22:03:47+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 22:03:47 volumio go-librespot[27590]: time="2026-02-11T22:03:47+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 22:03:47 volumio go-librespot[27590]: time="2026-02-11T22:03:47+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 22:03:47 volumio go-librespot[27590]: time="2026-02-11T22:03:47+07:00" level=info msg="zeroconf server listening on port 34099" Feb 11 22:03:47 volumio volumio[27224]: info: Getting Spotify volume Feb 11 22:03:47 volumio volumio[27224]: info: Connection to go-librespot Websocket closed Feb 11 22:03:47 volumio volumio[27224]: error: Cannot start Volumio Streaming Daemon Feb 11 22:03:47 volumio volumio[27224]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 11 22:03:47 volumio volumio[27224]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 11 22:03:47 volumio volumio[27224]: 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 11 22:03:47 volumio go-librespot[27590]: time="2026-02-11T22:03:47+07:00" level=debug msg="obtained new client token: AAAWjwnB7I0DPKWQNr6fzj5nLdk/GfGU2EEOmIs05OLWAqtLOD8ueCgzBqD2RjVVFo012EhbXlq7PptYuCvldVBuEBhOA7XS5yFFoj8rrUg3E5+GkmJGnuuBjB1UL80sFtonIhD0s0iL00D+9tBJ3NZ6kiYGqmyEBCcBjJPtt3stOuHPzPbhb03JJpstBKz0V2edR+6392DhwIPhEawi49f1cCbswzn7sEGatT25bKobsBbKEJVLXcBqYA==" Feb 11 22:03:48 volumio volumio[27224]: info: CoreCommandRouter::volumioGetState Feb 11 22:03:48 volumio volumio[27224]: info: CorePlayQueue::getTrack 0 Feb 11 22:03:48 volumio go-librespot[27590]: time="2026-02-11T22:03:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 22:03:48 volumio volumio[27224]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 11 22:03:48 volumio volumio[27224]: SPOTIFY: SPOTIFY VOLUME undefined Feb 11 22:03:48 volumio volumio[27224]: SPOTIFY: VOLUMIO VOLUME 100 Feb 11 22:03:48 volumio volumio[27224]: info: Aligning Spotify Volume to Volumio Volume Feb 11 22:03:48 volumio volumio[27224]: info: CoreCommandRouter::volumioGetState Feb 11 22:03:48 volumio volumio[27224]: info: CorePlayQueue::getTrack 0 Feb 11 22:03:48 volumio volumio[27224]: info: Setting Spotify Volume from Volumio: 100 Feb 11 22:03:48 volumio go-librespot[27590]: time="2026-02-11T22:03:48+07:00" level=debug msg="completed keyexchange" Feb 11 22:03:48 volumio go-librespot[27590]: time="2026-02-11T22:03:48+07:00" level=debug msg="completed challenge" Feb 11 22:03:48 volumio go-librespot[27590]: time="2026-02-11T22:03:48+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 22:03:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 22:03:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 22:03:48 volumio volumio[27224]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 22:03:48 volumio volumio[27224]: Error: socket hang up Feb 11 22:03:48 volumio volumio[27224]: at connResetException (node:internal/errors:720:14) Feb 11 22:03:48 volumio volumio[27224]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 11 22:03:48 volumio volumio[27224]: at Socket.emit (node:events:526:35) Feb 11 22:03:48 volumio volumio[27224]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 11 22:03:48 volumio volumio[27224]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 11 22:03:48 volumio volumio[27224]: code: 'ECONNRESET', Feb 11 22:03:48 volumio volumio[27224]: response: undefined Feb 11 22:03:48 volumio volumio[27224]: } Feb 11 22:03:48 volumio volumio[27224]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 22:03:49 volumio sudo[27619]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-11 22:02' Feb 11 22:03:49 volumio sudo[27619]: 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"