Feb 12 21:26:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Feb 12 21:26:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:26:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:26:01 volumio go-librespot[22712]: go-librespot daemon starting... Feb 12 21:26:01 volumio go-librespot[22713]: time="2026-02-12T21:26:01+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 21:26:01 volumio go-librespot[22713]: time="2026-02-12T21:26:01+07:00" level=debug msg="app state loaded" Feb 12 21:26:01 volumio go-librespot[22713]: time="2026-02-12T21:26:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 21:26:02 volumio go-librespot[22713]: time="2026-02-12T21:26:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 21:26:02 volumio go-librespot[22713]: time="2026-02-12T21:26:02+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 12 21:26:02 volumio go-librespot[22713]: time="2026-02-12T21:26:02+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 12 21:26:02 volumio go-librespot[22713]: time="2026-02-12T21:26:02+07:00" level=info msg="zeroconf server listening on port 36533" Feb 12 21:26:02 volumio go-librespot[22713]: time="2026-02-12T21:26:02+07:00" level=debug msg="obtained new client token: AAD+HheED+GGysnZP5PKBmCcjcsfORdESxPq+gAI0ARkdLI43gB5dmwFk+seFAQL0X8o+5PDmZAZ1iH2Bel+G8xZR1i/hZzhe/wicj/araDdAhcBg5k07kuoScOCKQZHDNUv7jLeQsGtIxrYZQMtSZr+StovcAJ6yFpXR/W84mEUieU4grwjsU5DxZwlDLPfP5HhB4chTzL2J/QU94q56n+lLzbyGEwq5wTlUAvMY37+Xh00fgeNi4bRkQ==" Feb 12 21:26:02 volumio volumio[22696]: info: ------------------------------------------- Feb 12 21:26:02 volumio volumio[22696]: info: ----- Volumio3 ---- Feb 12 21:26:02 volumio volumio[22696]: info: ------------------------------------------- Feb 12 21:26:02 volumio volumio[22696]: info: ----- System startup ---- Feb 12 21:26:02 volumio volumio[22696]: info: ------------------------------------------- Feb 12 21:26:02 volumio go-librespot[22713]: time="2026-02-12T21:26:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 21:26:03 volumio go-librespot[22713]: time="2026-02-12T21:26:03+07:00" level=debug msg="completed keyexchange" Feb 12 21:26:03 volumio go-librespot[22713]: time="2026-02-12T21:26:03+07:00" level=debug msg="completed challenge" Feb 12 21:26:03 volumio go-librespot[22713]: time="2026-02-12T21:26:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 21:26:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 21:26:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 21:26:04 volumio volumio-remote-updater[643]: [2026-02-12 21:26:04] [connect] Successful connection Feb 12 21:26:04 volumio volumio[22696]: info: MYVOLUMIO Environment detected Feb 12 21:26:04 volumio volumio[22696]: info: Plugin folders cleanup Feb 12 21:26:04 volumio volumio[22696]: info: Scanning into folder /volumio/app/plugins/ Feb 12 21:26:04 volumio volumio[22696]: info: Scanning category audio_interface Feb 12 21:26:04 volumio volumio[22696]: info: Scanning category miscellanea Feb 12 21:26:04 volumio volumio[22696]: info: Scanning category music_service Feb 12 21:26:04 volumio volumio[22696]: info: Scanning category plugins.json Feb 12 21:26:04 volumio volumio[22696]: info: Scanning category system_controller Feb 12 21:26:04 volumio volumio[22696]: info: Scanning category user_interface Feb 12 21:26:04 volumio volumio[22696]: info: Scanning into folder /data/plugins/ Feb 12 21:26:04 volumio volumio[22696]: info: Scanning category music_service Feb 12 21:26:04 volumio volumio[22696]: info: Plugin folders cleanup completed Feb 12 21:26:04 volumio volumio[22696]: info: ------------------------------------------- Feb 12 21:26:04 volumio volumio[22696]: info: ----- Core plugins startup ---- Feb 12 21:26:04 volumio volumio[22696]: info: ------------------------------------------- Feb 12 21:26:04 volumio volumio[22696]: info: Loading plugins from folder /volumio/app/plugins/ Feb 12 21:26:04 volumio volumio[22696]: info: Adding plugin upnp to MyMusic Plugins Feb 12 21:26:04 volumio volumio[22696]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 12 21:26:04 volumio volumio[22696]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 12 21:26:04 volumio volumio[22696]: info: Loading plugins from folder /data/plugins/ Feb 12 21:26:04 volumio volumio[22696]: info: Loading plugin "system"... Feb 12 21:26:04 volumio volumio[22696]: info: Loading plugin "appearance"... Feb 12 21:26:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Feb 12 21:26:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:26:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:26:06 volumio go-librespot[22732]: go-librespot daemon starting... Feb 12 21:26:06 volumio volumio[22696]: info: Loading plugin "network"... Feb 12 21:26:06 volumio volumio[22696]: info: Refreshing Cached IP Addresses Feb 12 21:26:06 volumio go-librespot[22733]: time="2026-02-12T21:26:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 21:26:06 volumio go-librespot[22733]: time="2026-02-12T21:26:06+07:00" level=debug msg="app state loaded" Feb 12 21:26:06 volumio go-librespot[22733]: time="2026-02-12T21:26:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 21:26:06 volumio sudo[22740]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 21:26:06 volumio sudo[22740]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:26:06 volumio sudo[22742]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 21:26:06 volumio sudo[22742]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:26:06 volumio volumio[22696]: info: Loading plugin "services"... Feb 12 21:26:06 volumio sudo[22740]: pam_unix(sudo:session): session closed for user root Feb 12 21:26:06 volumio volumio[22696]: info: Loading plugin "alsa_controller"... Feb 12 21:26:06 volumio sudo[22742]: pam_unix(sudo:session): session closed for user root Feb 12 21:26:06 volumio sudo[22749]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 12 21:26:06 volumio sudo[22749]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:26:06 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 21:26:06 volumio volumio[22696]: info: Loading plugin "wizard"... Feb 12 21:26:06 volumio volumio[22696]: info: Loading plugin "networkfs"... Feb 12 21:26:06 volumio volumio[22696]: info: Starting Udev Watcher for removable devices Feb 12 21:26:06 volumio volumio[22696]: info: Ignoring mount for partition: boot Feb 12 21:26:06 volumio volumio[22696]: info: Ignoring mount for partition: volumio Feb 12 21:26:06 volumio volumio[22696]: info: Ignoring mount for partition: volumio_data Feb 12 21:26:06 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 21:26:06 volumio volumio[22696]: info: Loading plugin "volumio_command_line_client"... Feb 12 21:26:06 volumio volumio[22696]: info: Loading plugin "upnp"... Feb 12 21:26:06 volumio volumio[22696]: info: [1770906366856] Starting Upmpd Daemon Feb 12 21:26:06 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 21:26:06 volumio volumio[22696]: info: Loading plugin "my_music"... Feb 12 21:26:06 volumio volumio[22696]: info: Loading plugin "mpd"... Feb 12 21:26:06 volumio go-librespot[22733]: time="2026-02-12T21:26:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 21:26:06 volumio go-librespot[22733]: time="2026-02-12T21:26:06+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 12 21:26:06 volumio go-librespot[22733]: time="2026-02-12T21:26:06+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 12 21:26:06 volumio go-librespot[22733]: time="2026-02-12T21:26:06+07:00" level=info msg="zeroconf server listening on port 40723" Feb 12 21:26:07 volumio go-librespot[22733]: time="2026-02-12T21:26:07+07:00" level=debug msg="obtained new client token: AACOPQ4l6AaJ6a7VDsbTMZXIWse7RqqznRWoxQ5qa1j3UC8Rs9RTe2VEcujmTA3vrjsv5Rn8ilxJmjZY65pVz7vCB/mPpyA1AK0wJurH88PoCjEAWfn8XjwcovVt51BjYhzEQYJx5ZaL8iLxpcaMstMiaDUtZXRTIqzsfyduyNjtzn0HcqfPo65hLU15Y+1wZoSjafvmWngp4hmmNk8ZuDmbT9s8SWQrcKIsLHO5v2mpT3FCpOtQsjw=" Feb 12 21:26:07 volumio go-librespot[22733]: time="2026-02-12T21:26:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 21:26:07 volumio go-librespot[22733]: time="2026-02-12T21:26:07+07:00" level=debug msg="completed keyexchange" Feb 12 21:26:07 volumio go-librespot[22733]: time="2026-02-12T21:26:07+07:00" level=debug msg="completed challenge" Feb 12 21:26:07 volumio go-librespot[22733]: time="2026-02-12T21:26:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 21:26:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 21:26:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 21:26:07 volumio volumio[22696]: info: Loading plugin "upnp_browser"... Feb 12 21:26:09 volumio sudo[22749]: pam_unix(sudo:session): session closed for user root Feb 12 21:26:10 volumio volumio[22696]: info: Starting UPNP Browser Feb 12 21:26:10 volumio volumio[22696]: info: Loading plugin "alarm-clock"... Feb 12 21:26:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Feb 12 21:26:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:26:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:26:10 volumio go-librespot[22774]: go-librespot daemon starting... Feb 12 21:26:10 volumio go-librespot[22775]: time="2026-02-12T21:26:10+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 21:26:10 volumio go-librespot[22775]: time="2026-02-12T21:26:10+07:00" level=debug msg="app state loaded" Feb 12 21:26:10 volumio go-librespot[22775]: time="2026-02-12T21:26:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 21:26:10 volumio volumio[22696]: info: Loading plugin "airplay_emulation"... Feb 12 21:26:10 volumio volumio[22696]: info: Starting Shairport Sync Feb 12 21:26:10 volumio volumio[22696]: info: Loading plugin "last_100"... Feb 12 21:26:10 volumio volumio[22696]: info: Loading plugin "webradio"... Feb 12 21:26:11 volumio volumio[22696]: info: Loading plugin "i2s_dacs"... Feb 12 21:26:11 volumio volumio[22696]: info: Loading plugin "volumiodiscovery"... Feb 12 21:26:11 volumio volumio[22696]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 12 21:26:11 volumio volumio[22696]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 21:26:11 volumio volumio[22696]: *** WARNING *** For more information see Feb 12 21:26:11 volumio volumio[22696]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 12 21:26:11 volumio volumio[22696]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 21:26:11 volumio volumio[22696]: *** WARNING *** For more information see Feb 12 21:26:11 volumio node[22696]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 12 21:26:11 volumio node[22696]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 21:26:11 volumio node[22696]: *** WARNING *** For more information see Feb 12 21:26:11 volumio node[22696]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 12 21:26:11 volumio node[22696]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 21:26:11 volumio node[22696]: *** WARNING *** For more information see Feb 12 21:26:11 volumio volumio[22696]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 12 21:26:11 volumio volumio[22696]: info: Discovery: Started advertising with name: Volumio Feb 12 21:26:11 volumio go-librespot[22775]: time="2026-02-12T21:26:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 21:26:11 volumio go-librespot[22775]: time="2026-02-12T21:26:11+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 21:26:11 volumio go-librespot[22775]: time="2026-02-12T21:26:11+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 21:26:11 volumio go-librespot[22775]: time="2026-02-12T21:26:11+07:00" level=info msg="zeroconf server listening on port 42707" Feb 12 21:26:11 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 21:26:11 volumio volumio[22696]: info: Loading plugin "spop"... Feb 12 21:26:11 volumio go-librespot[22775]: time="2026-02-12T21:26:11+07:00" level=debug msg="obtained new client token: AADy3L9d75F+iI2+cWeoPlAMaXklzJ4si3Z09sIVIkWK2eiY0lXgCAhaL4KWEPFYz4aIxWNExUygnZvvIGInWsbC2x60n/EpYo8U6TDBJrqfDg0G1EuTLjMx0U9EJsClf9yjQF192f3uMw3LGI7YP+NQ0VXIY5QSR38QIC9vQq+yO15C+XsuEIRT0aAnVt7nzMGhRytV+vDC2mr00ZRSFKQ0HjjxQSEuIw0A9+zKH0K4oyln++c2vwosHQ==" Feb 12 21:26:11 volumio go-librespot[22775]: time="2026-02-12T21:26:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 21:26:11 volumio go-librespot[22775]: time="2026-02-12T21:26:11+07:00" level=debug msg="completed keyexchange" Feb 12 21:26:11 volumio go-librespot[22775]: time="2026-02-12T21:26:11+07:00" level=debug msg="completed challenge" Feb 12 21:26:11 volumio go-librespot[22775]: time="2026-02-12T21:26:11+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 21:26:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 21:26:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 21:26:13 volumio volumio[22696]: info: Loading plugin "ytcr"... Feb 12 21:26:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Feb 12 21:26:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:26:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:26:14 volumio go-librespot[22789]: go-librespot daemon starting... Feb 12 21:26:14 volumio go-librespot[22790]: time="2026-02-12T21:26:14+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 21:26:14 volumio go-librespot[22790]: time="2026-02-12T21:26:14+07:00" level=debug msg="app state loaded" Feb 12 21:26:14 volumio go-librespot[22790]: time="2026-02-12T21:26:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 21:26:15 volumio go-librespot[22790]: time="2026-02-12T21:26:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 12 21:26:15 volumio go-librespot[22790]: time="2026-02-12T21:26:15+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 12 21:26:15 volumio go-librespot[22790]: time="2026-02-12T21:26:15+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 12 21:26:15 volumio go-librespot[22790]: time="2026-02-12T21:26:15+07:00" level=info msg="zeroconf server listening on port 46855" Feb 12 21:26:15 volumio go-librespot[22790]: time="2026-02-12T21:26:15+07:00" level=debug msg="obtained new client token: AACYfN/fDlf7+6QD76qAoPvTva5tn9ocJpY6rOuPUDBrQnvitOe0p+cwOHRI/gsjSFTbjRe5Km4NKFpGKSPzYYTRJ86I45sjIApZSuxMSiMy00LY+z3R8x2pngSfuD5zaPis0Pem50XM2jiJDZzJy8RZu+tC83fQ5FhXMymH7Qx1l+SQjm9TFkf4vKZaN0Cj85Y5HQeDo+ip9Up5OXSoZpvymLZLmOM84DCseLklZ4XXG5gQxJcgUylG4g==" Feb 12 21:26:15 volumio go-librespot[22790]: time="2026-02-12T21:26:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 21:26:15 volumio volumio[22696]: info: Loading plugin "ytmusic"... Feb 12 21:26:15 volumio go-librespot[22790]: time="2026-02-12T21:26:15+07:00" level=debug msg="completed keyexchange" Feb 12 21:26:15 volumio go-librespot[22790]: time="2026-02-12T21:26:15+07:00" level=debug msg="completed challenge" Feb 12 21:26:15 volumio go-librespot[22790]: time="2026-02-12T21:26:15+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 21:26:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 21:26:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 21:26:16 volumio volumio-remote-updater[643]: [2026-02-12 21:26:16] [connect] Successful connection Feb 12 21:26:16 volumio volumio[22696]: info: Loading plugin "outputs"... Feb 12 21:26:16 volumio volumio[22696]: info: Loading plugin "albumart"... Feb 12 21:26:16 volumio volumio[22696]: info: Plugin example_plugin is not enabled Feb 12 21:26:16 volumio volumio[22696]: info: Loading plugin "inputs"... Feb 12 21:26:17 volumio volumio[22696]: info: Loading plugin "updater_comm"... Feb 12 21:26:17 volumio volumio[22696]: info: Plugin mpdemulation is not enabled Feb 12 21:26:17 volumio volumio[22696]: info: Loading plugin "rest_api"... Feb 12 21:26:17 volumio volumio[22696]: info: Loading plugin "websocket"... Feb 12 21:26:17 volumio volumio[22696]: info: Starting Socket.io Server version 1.7.4 Feb 12 21:26:17 volumio volumio[22696]: info: Loading plugin "RoonBridge"... Feb 12 21:26:17 volumio volumio[22696]: info: Applying required configuration parameters for plugin RoonBridge Feb 12 21:26:17 volumio volumio[22696]: info: Loading i18n strings for locale en Feb 12 21:26:17 volumio volumio[22696]: Updating browse sources language Feb 12 21:26:17 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 21:26:18 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 21:26:18 volumio volumio[22696]: info: CoreCommandRouter::initPlayerControls Feb 12 21:26:18 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:26:18 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:26:18 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:26:18 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:26:18 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:26:18 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:26:18 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:26:18 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:26:18 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 21:26:18 volumio volumio[22696]: Express server listening on port 3000 Feb 12 21:26:18 volumio volumio[22696]: [Metrics] WebUI: 16s 232.26ms Feb 12 21:26:18 volumio volumio[22811]: Forking 3 albumart workers Feb 12 21:26:18 volumio volumio[22696]: info: CoreStateMachine::resetVolumioState Feb 12 21:26:18 volumio volumio[22696]: info: CoreStateMachine::getcurrentVolume Feb 12 21:26:18 volumio volumio[22696]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 21:26:18 volumio sudo[22838]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 21:26:18 volumio sudo[22838]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:26:18 volumio sudo[22838]: pam_unix(sudo:session): session closed for user root Feb 12 21:26:18 volumio sudo[22847]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 21:26:18 volumio sudo[22847]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:26:18 volumio sudo[22847]: pam_unix(sudo:session): session closed for user root Feb 12 21:26:18 volumio volumio[22696]: info: Volumio Network Manager: Network status updated: 1 Feb 12 21:26:18 volumio volumio[22696]: info: VolumeController:: Volume=100 Mute =false Feb 12 21:26:18 volumio volumio[22696]: info: CoreStateMachine::pushState Feb 12 21:26:18 volumio volumio[22696]: info: CorePlayQueue::getTrack 0 Feb 12 21:26:18 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 21:26:18 volumio volumio[22696]: info: CoreCommandRouter::volumioPushState Feb 12 21:26:18 volumio volumio[22696]: info: CoreStateMachine::updateTrackBlock Feb 12 21:26:18 volumio volumio[22696]: info: CorePlayQueue::getTrackBlock Feb 12 21:26:18 volumio volumio[22696]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 21:26:18 volumio volumio-remote-updater[643]: [2026-02-12 21:26:18] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770906376 101 Feb 12 21:26:18 volumio volumio[22696]: 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 12 21:26:18 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:26:18 volumio volumio[22696]: info: Reloading queue from file Feb 12 21:26:18 volumio volumio[22696]: info: CoreStateMachine::setRepeat null single undefined Feb 12 21:26:18 volumio volumio[22696]: info: CoreStateMachine::pushState Feb 12 21:26:18 volumio volumio[22696]: info: CorePlayQueue::getTrack 0 Feb 12 21:26:18 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 21:26:18 volumio volumio[22696]: info: CoreCommandRouter::volumioPushState Feb 12 21:26:18 volumio volumio[22696]: info: CoreStateMachine::setRandom null Feb 12 21:26:18 volumio volumio[22696]: info: CoreStateMachine::pushState Feb 12 21:26:18 volumio volumio[22696]: info: CorePlayQueue::getTrack 0 Feb 12 21:26:18 volumio volumio[22696]: info: CoreCommandRouter::volumioPushState Feb 12 21:26:18 volumio volumio[22696]: info: Setting Device type: Raspberry PI Feb 12 21:26:19 volumio volumio[22696]: info: Completed loading Core Plugins Feb 12 21:26:19 volumio volumio[22696]: info: Preparing to generate the ALSA configuration file Feb 12 21:26:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Feb 12 21:26:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:26:19 volumio volumio[22696]: info: VolumeController:: Volume=100 Mute =false Feb 12 21:26:19 volumio volumio[22696]: info: CoreStateMachine::pushState Feb 12 21:26:19 volumio volumio[22696]: info: CorePlayQueue::getTrack 0 Feb 12 21:26:19 volumio volumio[22696]: info: CoreCommandRouter::volumioPushState Feb 12 21:26:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:26:19 volumio go-librespot[22870]: go-librespot daemon starting... Feb 12 21:26:19 volumio volumio[22696]: info: Asound.conf file unchanged, so no further update is needed Feb 12 21:26:19 volumio volumio[22696]: info: Output device has changed, restarting MPD Feb 12 21:26:19 volumio go-librespot[22873]: time="2026-02-12T21:26:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 21:26:19 volumio go-librespot[22873]: time="2026-02-12T21:26:19+07:00" level=debug msg="app state loaded" Feb 12 21:26:19 volumio go-librespot[22873]: time="2026-02-12T21:26:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 21:26:19 volumio sudo[22874]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 12 21:26:19 volumio volumio[22696]: info: Output device has changed, restarting Shairport Sync Feb 12 21:26:19 volumio sudo[22874]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:26:19 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:26:19 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:26:19 volumio sudo[22881]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 21:26:19 volumio sudo[22881]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:26:19 volumio sudo[22883]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 21:26:19 volumio volumio[22696]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 21:26:19 volumio volumio[22696]: info: ___________ START PLUGINS ___________ Feb 12 21:26:19 volumio sudo[22883]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:26:19 volumio sudo[22881]: pam_unix(sudo:session): session closed for user root Feb 12 21:26:19 volumio sudo[22874]: pam_unix(sudo:session): session closed for user root Feb 12 21:26:19 volumio volumio[22696]: info: ControllerMpd::onStart: Initializing MPD Feb 12 21:26:19 volumio volumio[22696]: info: Creating MPD Configuration file Feb 12 21:26:19 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 21:26:19 volumio volumio[22696]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 21:26:19 volumio volumio[22696]: info: [1770906379546] CoreMusicLibrary::Adding element Media Servers Feb 12 21:26:19 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 21:26:19 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 12 21:26:19 volumio sudo[22894]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 21:26:19 volumio sudo[22894]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:26:19 volumio sudo[22892]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 21:26:19 volumio sudo[22892]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:26:19 volumio volumio[22696]: info: UPNP Browser: Client initialized successfully Feb 12 21:26:19 volumio sudo[22892]: pam_unix(sudo:session): session closed for user root Feb 12 21:26:19 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 12 21:26:19 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 12 21:26:19 volumio systemd[1]: mpd.service: Consumed 7.201s CPU time. Feb 12 21:26:19 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 12 21:26:19 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 12 21:26:19 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 12 21:26:19 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:26:19 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:26:19 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 12 21:26:19 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 12 21:26:19 volumio volumio[22696]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 21:26:19 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:26:19 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:26:19 volumio go-librespot[22873]: time="2026-02-12T21:26:19+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 12 21:26:19 volumio go-librespot[22873]: time="2026-02-12T21:26:19+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 12 21:26:19 volumio go-librespot[22873]: time="2026-02-12T21:26:19+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 12 21:26:19 volumio go-librespot[22873]: time="2026-02-12T21:26:19+07:00" level=info msg="zeroconf server listening on port 38255" Feb 12 21:26:20 volumio volumio[22696]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 21:26:20 volumio volumio[22696]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 21:26:20 volumio volumio[22696]: info: [1770906380104] CoreMusicLibrary::Adding element Last_100 Feb 12 21:26:20 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 21:26:20 volumio volumio[22696]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 21:26:20 volumio volumio[22696]: info: [1770906380117] CoreMusicLibrary::Adding element Webradio Feb 12 21:26:20 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 21:26:20 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 21:26:20 volumio volumio[22696]: info: Initializing BBC Radios Feb 12 21:26:20 volumio go-librespot[22873]: time="2026-02-12T21:26:20+07:00" level=debug msg="obtained new client token: AAA+cbjI++eRM+5p1m0GO7+aWFJE4TeuZMHBQ2xro+ShkMJF/+pUwHJHO9fKIYu8UsZmD7LKUb0w+mqfvAgFC/08FFcrjlqRMDfphSnI7UplbKfZ3cGLGADEh6IWubSgA+rqlcbHzmDLxj+ABk46UKqUQQN+MpE4TRDZ98gcp8mQASkm2Q8ePZLkgSM0uFRm3LvGwffRHRWFLxh7olaf1vkEQnC235EqMrESVwAd5j9G/CgJAjA/iaE=" Feb 12 21:26:20 volumio go-librespot[22873]: time="2026-02-12T21:26:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 21:26:20 volumio sudo[22904]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 12 21:26:20 volumio sudo[22904]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 12 21:26:20 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 21:26:20 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:26:20 volumio sudo[22904]: pam_unix(sudo:session): session closed for user root Feb 12 21:26:20 volumio go-librespot[22873]: time="2026-02-12T21:26:20+07:00" level=debug msg="completed keyexchange" Feb 12 21:26:20 volumio go-librespot[22873]: time="2026-02-12T21:26:20+07:00" level=debug msg="completed challenge" Feb 12 21:26:20 volumio volumio[22696]: info: Creating Spotify config file Feb 12 21:26:20 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:26:20 volumio go-librespot[22873]: time="2026-02-12T21:26:20+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 12 21:26:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 21:26:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 21:26:21 volumio volumio[22825]: Starting albumart workers Feb 12 21:26:21 volumio volumio[22824]: Starting albumart workers Feb 12 21:26:21 volumio volumio[22826]: Starting albumart workers Feb 12 21:26:21 volumio volumio[22696]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 21:26:21 volumio volumio[22696]: info: [1770906381712] CoreMusicLibrary::Adding element YouTube Music Feb 12 21:26:21 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 21:26:21 volumio volumio[22696]: Cannot find translation for source YouTube Music Feb 12 21:26:21 volumio volumio[22696]: info: Volumio Calling Home Feb 12 21:26:21 volumio sudo[22925]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 12 21:26:21 volumio sudo[22925]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:26:21 volumio sudo[22925]: pam_unix(sudo:session): session closed for user root Feb 12 21:26:22 volumio volumio[22696]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 12 21:26:22 volumio volumio[22696]: info: Discovery: Found device Volumio Feb 12 21:26:22 volumio volumio[22696]: info: CoreCommandRouter::volumioGetState Feb 12 21:26:22 volumio volumio[22696]: info: CorePlayQueue::getTrack 0 Feb 12 21:26:22 volumio volumio[22696]: info: MPD Permissions set Feb 12 21:26:22 volumio volumio[22696]: info: MPD Permissions set Feb 12 21:26:22 volumio volumio[22696]: info: Upmpdcli Daemon Started Feb 12 21:26:22 volumio volumio[22696]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 12 21:26:22 volumio volumio[22696]: info: Discovery: Found device Volumio Feb 12 21:26:22 volumio volumio[22696]: info: CoreCommandRouter::volumioGetState Feb 12 21:26:22 volumio volumio[22696]: info: CorePlayQueue::getTrack 0 Feb 12 21:26:22 volumio volumio[22696]: info: Spotify config file written Feb 12 21:26:22 volumio sudo[22932]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 12 21:26:22 volumio sudo[22932]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:26:22 volumio volumio[22696]: 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 12 21:26:22 volumio volumio[22696]: info: Volumio called home Feb 12 21:26:22 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:26:22 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:26:22 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:26:22 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:26:22 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:26:22 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:26:22 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:26:22 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:26:23 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:26:23 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:26:23 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:26:23 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:26:23 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:26:23 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:26:23 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:26:23 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:26:23 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:26:23 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:26:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:26:23 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:26:23 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:26:23 volumio volumio[22696]: info: No need to fix Spotify hosts Feb 12 21:26:23 volumio go-librespot[22941]: go-librespot daemon starting... Feb 12 21:26:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:26:23 volumio sudo[22932]: pam_unix(sudo:session): session closed for user root Feb 12 21:26:23 volumio go-librespot[22945]: time="2026-02-12T21:26:23+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 21:26:23 volumio go-librespot[22945]: time="2026-02-12T21:26:23+07:00" level=debug msg="app state loaded" Feb 12 21:26:23 volumio go-librespot[22945]: time="2026-02-12T21:26:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 21:26:23 volumio go-librespot[22945]: time="2026-02-12T21:26:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 12 21:26:23 volumio go-librespot[22945]: time="2026-02-12T21:26:23+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 12 21:26:23 volumio go-librespot[22945]: time="2026-02-12T21:26:23+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 12 21:26:23 volumio go-librespot[22945]: time="2026-02-12T21:26:23+07:00" level=info msg="zeroconf server listening on port 37729" Feb 12 21:26:24 volumio go-librespot[22945]: time="2026-02-12T21:26:24+07:00" level=debug msg="obtained new client token: AABqOs5/cj2GkH2rOnLjMALTvpkIUzBGUW3UM7LX3jgkYgskfVZGWV7CNeoiiyfPTTUeByMYLgwV2aN1K260tAvRFvqD2afRhrx3LCfkTumZgVSHN8144PscMOnKt1JJJmiWX1vYNVHvFUd8WfBQHIp9X+9pELobWpfith/dIeOL6ecYTG6g9hFqrNhMyVN8EslOSwUEarBqEADpQvzzz928CzUJ4gne1JB9jtuhzoF76EQAcPdn+8o=" Feb 12 21:26:24 volumio volumio[22696]: info: Starting Shairport Sync Feb 12 21:26:24 volumio go-librespot[22945]: time="2026-02-12T21:26:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 21:26:24 volumio volumio[22696]: info: Starting Shairport Sync Feb 12 21:26:24 volumio volumio[22696]: info: Starting Shairport Sync Feb 12 21:26:24 volumio sudo[22973]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 21:26:24 volumio sudo[22973]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:26:24 volumio go-librespot[22945]: time="2026-02-12T21:26:24+07:00" level=debug msg="completed keyexchange" Feb 12 21:26:24 volumio go-librespot[22945]: time="2026-02-12T21:26:24+07:00" level=debug msg="completed challenge" Feb 12 21:26:24 volumio sudo[22975]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 21:26:24 volumio sudo[22975]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:26:24 volumio sudo[22978]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 21:26:24 volumio sudo[22978]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:26:24 volumio go-librespot[22945]: time="2026-02-12T21:26:24+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 12 21:26:24 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 21:26:24 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 21:26:24 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 21:26:24 volumio systemd[1]: shairport-sync.service: Consumed 2.404s CPU time. Feb 12 21:26:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 21:26:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 21:26:24 volumio volumio[22696]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 21:26:24 volumio volumio[22696]: SPOTIFY: BQD8-vvTSyzoHYbWTQY1YxbQwSVuuB_gDvGY0V3YpDHf3sarajenhi2nNrks6U1s8_gLBeqI3mUVfnZs9ky5QzxWoJYMSVYVcElXy-MVZexog1sjxnQ4szmkK7NDxwiIHmN5vDFkz-mkvUFUnWFuhY17_HxPN3L32yZTbWgH3iUNDShHLXqzlXffElxi8nClB66dK--lH4oywv2AWR4rtaKY6ImZz9hOX5gJkszMjtsQm0HDPe5qILthRYm0VMWS8E9yoXw3K2InHUSrDBvQXTZ-5L2TPubXNFrKKIWtDrnSgBEUFq3MkRKW Feb 12 21:26:24 volumio volumio[22696]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 21:26:24 volumio volumio[22696]: info: New Spotify access token = BQD8-vvTSyzoHYbWTQY1YxbQwSVuuB_gDvGY0V3YpDHf3sarajenhi2nNrks6U1s8_gLBeqI3mUVfnZs9ky5QzxWoJYMSVYVcElXy-MVZexog1sjxnQ4szmkK7NDxwiIHmN5vDFkz-mkvUFUnWFuhY17_HxPN3L32yZTbWgH3iUNDShHLXqzlXffElxi8nClB66dK--lH4oywv2AWR4rtaKY6ImZz9hOX5gJkszMjtsQm0HDPe5qILthRYm0VMWS8E9yoXw3K2InHUSrDBvQXTZ-5L2TPubXNFrKKIWtDrnSgBEUFq3MkRKW Feb 12 21:26:24 volumio volumio[22696]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 12 21:26:24 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 21:26:24 volumio sudo[22973]: pam_unix(sudo:session): session closed for user root Feb 12 21:26:24 volumio sudo[22975]: pam_unix(sudo:session): session closed for user root Feb 12 21:26:24 volumio volumio[22696]: info: CoreCommandRouter::volumioGetState Feb 12 21:26:24 volumio volumio[22696]: info: CorePlayQueue::getTrack 0 Feb 12 21:26:24 volumio sudo[22978]: pam_unix(sudo:session): session closed for user root Feb 12 21:26:24 volumio volumio[22696]: info: Shairport-Sync Started Feb 12 21:26:24 volumio volumio[22696]: Error adding Membership: Error: addMembership EINVAL Feb 12 21:26:24 volumio volumio[22696]: info: Shairport-Sync Started Feb 12 21:26:24 volumio volumio[22696]: info: Shairport-Sync Started Feb 12 21:26:25 volumio volumio[22696]: 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 12 21:26:25 volumio volumio[22696]: info: Spotify Successfully logged in Feb 12 21:26:25 volumio volumio[22696]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 21:26:25 volumio volumio[22696]: info: [1770906385280] CoreMusicLibrary::Adding element Spotify Feb 12 21:26:25 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 21:26:25 volumio volumio[22696]: Cannot find translation for source YouTube Music Feb 12 21:26:25 volumio volumio[22696]: Cannot find translation for source Spotify Feb 12 21:26:25 volumio volumio[22696]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 12 21:26:25 volumio volumio[22696]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 21:26:26 volumio volumio[22696]: info: VolumeController:: Volume=100 Mute =false Feb 12 21:26:26 volumio volumio[22696]: info: CoreCommandRouter::volumioGetState Feb 12 21:26:26 volumio volumio[22696]: info: CorePlayQueue::getTrack 0 Feb 12 21:26:26 volumio volumio[22696]: info: CoreStateMachine::pushState Feb 12 21:26:26 volumio volumio[22696]: info: CorePlayQueue::getTrack 0 Feb 12 21:26:26 volumio volumio[22696]: info: CoreCommandRouter::volumioPushState Feb 12 21:26:27 volumio volumio[22696]: info: go-librespot daemon successfully initialized Feb 12 21:26:27 volumio mpd[22923]: 2026-02-12T21:26:27 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 12 21:26:27 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 12 21:26:27 volumio sudo[22883]: pam_unix(sudo:session): session closed for user root Feb 12 21:26:27 volumio sudo[22894]: pam_unix(sudo:session): session closed for user root Feb 12 21:26:27 volumio volumio[22696]: error: MPD error: The expression evaluated to a falsy value: Feb 12 21:26:27 volumio volumio[22696]: assert.ok(self.idling) Feb 12 21:26:27 volumio volumio[22696]: error: The expression evaluated to a falsy value: Feb 12 21:26:27 volumio volumio[22696]: assert.ok(self.idling) Feb 12 21:26:27 volumio volumio[22696]: error: updateQueue error: null Feb 12 21:26:27 volumio volumio[22696]: info: MPD running with PID22923 Feb 12 21:26:27 volumio volumio[22696]: ,establishing connection Feb 12 21:26:27 volumio volumio[22696]: info: Completed starting Core Plugins Feb 12 21:26:27 volumio volumio[22696]: info: ------------------------------------------- Feb 12 21:26:27 volumio volumio[22696]: info: ----- MyVolumio plugins startup ---- Feb 12 21:26:27 volumio volumio[22696]: info: ------------------------------------------- Feb 12 21:26:27 volumio volumio[22696]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 12 21:26:27 volumio volumio[22696]: error: updateQueue error: null Feb 12 21:26:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Feb 12 21:26:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:26:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:26:27 volumio go-librespot[23016]: go-librespot daemon starting... Feb 12 21:26:27 volumio go-librespot[23017]: time="2026-02-12T21:26:27+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 21:26:27 volumio go-librespot[23017]: time="2026-02-12T21:26:27+07:00" level=debug msg="app state loaded" Feb 12 21:26:27 volumio go-librespot[23017]: time="2026-02-12T21:26:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 21:26:28 volumio go-librespot[23017]: time="2026-02-12T21:26:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 21:26:28 volumio go-librespot[23017]: time="2026-02-12T21:26:28+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 21:26:28 volumio go-librespot[23017]: time="2026-02-12T21:26:28+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 21:26:28 volumio go-librespot[23017]: time="2026-02-12T21:26:28+07:00" level=info msg="zeroconf server listening on port 37005" Feb 12 21:26:28 volumio go-librespot[23017]: time="2026-02-12T21:26:28+07:00" level=debug msg="obtained new client token: AAAmVvQ/UL25Cf0Y0bKRVtewvZaTKcZSOTPawk4Q/7rxCrO16eFlPWaW85iQBr7HB8HPHE6Qhy0HdK9eRo3gYTe0lbDfWDHqdm/9UfF1UbWPQMQczEbbRFIfc+Z4RlV3IPR2ypKz1x9oW6rAn4xooQlMVv/AZmOVQK5GCKy0m5C7EgThP9/68lqntfO5KONBuYegHnqh7kHvkmL8l/Ax00kjG2yR8kvvgRTgvmCW3vQBYky23igpMZQcKw==" Feb 12 21:26:28 volumio go-librespot[23017]: time="2026-02-12T21:26:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 21:26:28 volumio go-librespot[23017]: time="2026-02-12T21:26:28+07:00" level=debug msg="completed keyexchange" Feb 12 21:26:28 volumio go-librespot[23017]: time="2026-02-12T21:26:28+07:00" level=debug msg="completed challenge" Feb 12 21:26:28 volumio go-librespot[23017]: time="2026-02-12T21:26:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 21:26:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 21:26:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 21:26:30 volumio volumio[22696]: info: Initializing connection to go-librespot Websocket Feb 12 21:26:30 volumio volumio[22696]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 21:26:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Feb 12 21:26:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:26:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:26:32 volumio go-librespot[23025]: go-librespot daemon starting... Feb 12 21:26:32 volumio go-librespot[23026]: time="2026-02-12T21:26:32+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 21:26:32 volumio go-librespot[23026]: time="2026-02-12T21:26:32+07:00" level=debug msg="app state loaded" Feb 12 21:26:32 volumio go-librespot[23026]: time="2026-02-12T21:26:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 21:26:32 volumio volumio[22696]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 12 21:26:32 volumio go-librespot[23026]: time="2026-02-12T21:26:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 21:26:32 volumio go-librespot[23026]: time="2026-02-12T21:26:32+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 21:26:32 volumio go-librespot[23026]: time="2026-02-12T21:26:32+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 21:26:32 volumio go-librespot[23026]: time="2026-02-12T21:26:32+07:00" level=info msg="zeroconf server listening on port 33111" Feb 12 21:26:32 volumio go-librespot[23026]: time="2026-02-12T21:26:32+07:00" level=debug msg="obtained new client token: AABopgtLF1i+aFnuN62z6sG+SN5GNaHm34y28iD7GPU2hK6Q1E+9EGdmjr+G14zNiq58kqy8/eImM4zdqqVHJ8BsZ/vsTv8+Yrkl/q885S6LKL7iiSl27r5j1qp7csfnqYuMq5DDp1FBiFFy0iH8mX6yaclwtKB6Wu/0YYwB8T9V/zKgSYof2RZmh/Ts2Z6H4x5ff/WuuyRNKv4mYxD2n4QoifQchc1G+PyS7elf9nYu2G3qULW5D4cvLA==" Feb 12 21:26:33 volumio go-librespot[23026]: time="2026-02-12T21:26:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 21:26:33 volumio go-librespot[23026]: time="2026-02-12T21:26:33+07:00" level=debug msg="completed keyexchange" Feb 12 21:26:33 volumio go-librespot[23026]: time="2026-02-12T21:26:33+07:00" level=debug msg="completed challenge" Feb 12 21:26:33 volumio go-librespot[23026]: time="2026-02-12T21:26:33+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 21:26:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 21:26:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 21:26:33 volumio volumio[22696]: info: Initializing connection to go-librespot Websocket Feb 12 21:26:33 volumio volumio[22696]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 21:26:36 volumio volumio[22696]: info: Initializing connection to go-librespot Websocket Feb 12 21:26:36 volumio volumio[22696]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 21:26:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Feb 12 21:26:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:26:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:26:36 volumio go-librespot[23035]: go-librespot daemon starting... Feb 12 21:26:36 volumio go-librespot[23036]: time="2026-02-12T21:26:36+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 21:26:36 volumio go-librespot[23036]: time="2026-02-12T21:26:36+07:00" level=debug msg="app state loaded" Feb 12 21:26:36 volumio go-librespot[23036]: time="2026-02-12T21:26:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 21:26:36 volumio volumio[22696]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 12 21:26:36 volumio volumio[22696]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 12 21:26:36 volumio volumio[22696]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 12 21:26:36 volumio volumio[22696]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 12 21:26:36 volumio volumio[22696]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 12 21:26:36 volumio volumio[22696]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 12 21:26:36 volumio volumio[22696]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 12 21:26:36 volumio volumio[22696]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 12 21:26:36 volumio volumio[22696]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 12 21:26:36 volumio volumio[22696]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 12 21:26:36 volumio volumio[22696]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 12 21:26:36 volumio volumio[22696]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 12 21:26:36 volumio volumio[22696]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 12 21:26:36 volumio volumio[22696]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 12 21:26:36 volumio volumio[22696]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 12 21:26:36 volumio volumio[22696]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 12 21:26:36 volumio volumio[22696]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 12 21:26:36 volumio volumio[22696]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 12 21:26:36 volumio volumio[22696]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 12 21:26:36 volumio volumio[22696]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 12 21:26:36 volumio volumio[22696]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 12 21:26:36 volumio volumio[22696]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 12 21:26:36 volumio volumio[22696]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 12 21:26:36 volumio volumio[22696]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 12 21:26:36 volumio volumio[22696]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 12 21:26:36 volumio volumio[22696]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 12 21:26:36 volumio volumio[22696]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 12 21:26:36 volumio volumio[22696]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 12 21:26:36 volumio volumio[22696]: info: Adding plugin bluetooth to MyMusic Plugins Feb 12 21:26:36 volumio volumio[22696]: info: Adding plugin multiroom to MyMusic Plugins Feb 12 21:26:36 volumio volumio[22696]: info: Adding plugin metavolumio to MyMusic Plugins Feb 12 21:26:36 volumio volumio[22696]: info: Adding plugin cd_controller to MyMusic Plugins Feb 12 21:26:36 volumio volumio[22696]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 12 21:26:36 volumio volumio[22696]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 12 21:26:36 volumio volumio[22696]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 12 21:26:36 volumio volumio[22696]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 12 21:26:36 volumio go-librespot[23036]: time="2026-02-12T21:26:36+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 12 21:26:36 volumio go-librespot[23036]: time="2026-02-12T21:26:36+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 12 21:26:36 volumio go-librespot[23036]: time="2026-02-12T21:26:36+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 12 21:26:36 volumio go-librespot[23036]: time="2026-02-12T21:26:36+07:00" level=info msg="zeroconf server listening on port 35871" Feb 12 21:26:37 volumio go-librespot[23036]: time="2026-02-12T21:26:37+07:00" level=debug msg="obtained new client token: AADj4jsVsTbm97T73Cl5Tmrvc9lr/8lRPHlsoUZW+rFWsIKSA6YBEpkcQzoNEOI/2btUjiUcDb3MJWrq8Sr6Ins5xrKK6y1ObuEh/rn/8gbXCCEgqreRaOr6ticNXg00PERFSf1IHkFGJNplCVNzFAS8Tiwfm4gtDRXseaS7q6Vrqq/ejeYlomffGUR5A6vBiv4SiJci41yxnStZ+T1WiicN0ZOcotf7YI6KqI0RvbK3piVJ+TsFrak=" Feb 12 21:26:37 volumio go-librespot[23036]: time="2026-02-12T21:26:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 21:26:37 volumio go-librespot[23036]: time="2026-02-12T21:26:37+07:00" level=debug msg="completed keyexchange" Feb 12 21:26:37 volumio go-librespot[23036]: time="2026-02-12T21:26:37+07:00" level=debug msg="completed challenge" Feb 12 21:26:37 volumio go-librespot[23036]: time="2026-02-12T21:26:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 21:26:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 21:26:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 21:26:38 volumio volumio[22696]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 12 21:26:38 volumio volumio[22696]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 12 21:26:38 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:26:38 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:26:38 volumio volumio[22696]: info: Starting MyVolumio Remote Streaming Endpoints Feb 12 21:26:38 volumio volumio[22696]: info: MyVolumio login type: Token Feb 12 21:26:38 volumio volumio[22696]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 12 21:26:38 volumio volumio[22696]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 12 21:26:40 volumio volumio[22696]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 12 21:26:40 volumio volumio[22696]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 12 21:26:40 volumio volumio[22696]: info: Streaming services startup Feb 12 21:26:40 volumio volumio[22696]: info: Starting Streaming Daemon Feb 12 21:26:40 volumio sudo[23059]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 12 21:26:40 volumio sudo[23059]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:26:40 volumio volumio[22696]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 12 21:26:40 volumio sudo[23059]: pam_unix(sudo:session): session closed for user root Feb 12 21:26:40 volumio volumio[22696]: info: Initializing connection to go-librespot Websocket Feb 12 21:26:40 volumio volumio[22696]: error: Cannot start Volumio Streaming Daemon Feb 12 21:26:40 volumio volumio[22696]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 12 21:26:40 volumio volumio[22696]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 12 21:26:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Feb 12 21:26:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:26:40 volumio volumio[22696]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 21:26:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:26:40 volumio go-librespot[23066]: go-librespot daemon starting... Feb 12 21:26:40 volumio go-librespot[23067]: time="2026-02-12T21:26:40+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 21:26:40 volumio go-librespot[23067]: time="2026-02-12T21:26:40+07:00" level=debug msg="app state loaded" Feb 12 21:26:40 volumio go-librespot[23067]: time="2026-02-12T21:26:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 21:26:41 volumio go-librespot[23067]: time="2026-02-12T21:26:41+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 12 21:26:41 volumio go-librespot[23067]: time="2026-02-12T21:26:41+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 12 21:26:41 volumio go-librespot[23067]: time="2026-02-12T21:26:41+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 12 21:26:41 volumio go-librespot[23067]: time="2026-02-12T21:26:41+07:00" level=info msg="zeroconf server listening on port 41479" Feb 12 21:26:41 volumio go-librespot[23067]: time="2026-02-12T21:26:41+07:00" level=debug msg="obtained new client token: AACvQT2+hYH7pFF13222Ir+ynZOZ3ykgXghjvVM1l6JiMNDaEGw3wZ+cZd3OxZSdgqTbIXkdBT84D/DM6yynUGWhcIDx8offklMtJhxEBaOC0i0hNDbLap2+1ToVM2z7tQrzzEj5jOI7ukIkcOiNsFCwb2RTsX6kT+LP56lgDljxhy434UxTc7Z4SXKTqNSUPCJma7BeYx13k0lj/M9NxjMAGp9UM4gtvH74Hk0GA28wRXIA6Eg3GID4wQ==" Feb 12 21:26:41 volumio go-librespot[23067]: time="2026-02-12T21:26:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 21:26:41 volumio go-librespot[23067]: time="2026-02-12T21:26:41+07:00" level=debug msg="completed keyexchange" Feb 12 21:26:41 volumio go-librespot[23067]: time="2026-02-12T21:26:41+07:00" level=debug msg="completed challenge" Feb 12 21:26:41 volumio volumio[22696]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 12 21:26:41 volumio go-librespot[23067]: time="2026-02-12T21:26:41+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 21:26:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 21:26:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 21:26:42 volumio volumio[22696]: info: MyVolumio token set successfully Feb 12 21:26:42 volumio volumio[22696]: info: MYVOLUMIO: Adding device Feb 12 21:26:42 volumio volumio[22696]: info: MYVOLUMIO: Evaluating Server Feb 12 21:26:43 volumio volumio[22696]: info: MyVolumio status changed Feb 12 21:26:43 volumio volumio[22696]: info: Streaming services startup Feb 12 21:26:43 volumio volumio[22696]: info: Starting Streaming Daemon Feb 12 21:26:43 volumio volumio[22696]: info: Removing browser output: myVolumio user plan is not superstar Feb 12 21:26:43 volumio volumio[22696]: info: Removing audio output: Feb 12 21:26:43 volumio volumio[22696]: info: Stoppping Tunnel 1 Feb 12 21:26:43 volumio sudo[23095]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 12 21:26:43 volumio sudo[23095]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:26:43 volumio volumio[22696]: info: Initializing connection to go-librespot Websocket Feb 12 21:26:43 volumio sudo[23098]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 12 21:26:43 volumio sudo[23098]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:26:43 volumio sudo[23095]: pam_unix(sudo:session): session closed for user root Feb 12 21:26:43 volumio volumio[22696]: error: Cannot start Volumio Streaming Daemon Feb 12 21:26:43 volumio volumio[22696]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 12 21:26:43 volumio volumio[22696]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 12 21:26:43 volumio volumio[22696]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 21:26:43 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 12 21:26:43 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 12 21:26:43 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 12 21:26:43 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 12 21:26:43 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 12 21:26:43 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 12 21:26:43 volumio volumio[22696]: info: Setting Geolocation for MyVolumio to as1 Feb 12 21:26:43 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:26:43 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:26:43 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:26:43 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 12 21:26:43 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 12 21:26:43 volumio sudo[23098]: pam_unix(sudo:session): session closed for user root Feb 12 21:26:43 volumio volumio[22696]: info: Remote SSH Stopped Feb 12 21:26:44 volumio volumio[22696]: info: Updating MyVolumio device info Feb 12 21:26:44 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:26:44 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:26:44 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:26:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Feb 12 21:26:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:26:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:26:44 volumio go-librespot[23100]: go-librespot daemon starting... Feb 12 21:26:44 volumio go-librespot[23101]: time="2026-02-12T21:26:44+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 21:26:44 volumio go-librespot[23101]: time="2026-02-12T21:26:44+07:00" level=debug msg="app state loaded" Feb 12 21:26:44 volumio go-librespot[23101]: time="2026-02-12T21:26:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 21:26:44 volumio volumio[22696]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 12 21:26:45 volumio volumio[22696]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 12 21:26:45 volumio go-librespot[23101]: time="2026-02-12T21:26:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 21:26:45 volumio go-librespot[23101]: time="2026-02-12T21:26:45+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 21:26:45 volumio go-librespot[23101]: time="2026-02-12T21:26:45+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 21:26:45 volumio go-librespot[23101]: time="2026-02-12T21:26:45+07:00" level=info msg="zeroconf server listening on port 46419" Feb 12 21:26:45 volumio go-librespot[23101]: time="2026-02-12T21:26:45+07:00" level=debug msg="obtained new client token: AAAaXHjYCxMM/fDHz6KVEo3UnJYujkRLMxGqEm1z3pfAZ4NvYLnAoHj2U27JrFWZ38mMcX+un+xk1nZloiuPFJqx4KeTY5pG9kzpcUADiQJFEOeZTTQazU2kbVz1xeRX4L9zy4DWraU/vLJXyI/smJH5pok+fB2xXH9RfNdS+TdGnrbMCyQ8DjY/uusCFOrhkIyY0tw157ekt9S5fWj3q35EXOyM/zBmjATWiOnwrbmfADMfFX0lwZzOug==" Feb 12 21:26:45 volumio go-librespot[23101]: time="2026-02-12T21:26:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 21:26:45 volumio go-librespot[23101]: time="2026-02-12T21:26:45+07:00" level=debug msg="completed keyexchange" Feb 12 21:26:45 volumio go-librespot[23101]: time="2026-02-12T21:26:45+07:00" level=debug msg="completed challenge" Feb 12 21:26:45 volumio go-librespot[23101]: time="2026-02-12T21:26:45+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 21:26:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 21:26:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 21:26:46 volumio volumio[22696]: info: Initializing connection to go-librespot Websocket Feb 12 21:26:46 volumio volumio[22696]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 21:26:48 volumio volumio[22696]: info: MYVOLUMIO: Adding device Feb 12 21:26:48 volumio volumio[22696]: info: MYVOLUMIO: Evaluating Server Feb 12 21:26:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Feb 12 21:26:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:26:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:26:49 volumio go-librespot[23122]: go-librespot daemon starting... Feb 12 21:26:49 volumio go-librespot[23123]: time="2026-02-12T21:26:49+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 21:26:49 volumio go-librespot[23123]: time="2026-02-12T21:26:49+07:00" level=debug msg="app state loaded" Feb 12 21:26:49 volumio go-librespot[23123]: time="2026-02-12T21:26:49+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 21:26:49 volumio volumio[22696]: info: Initializing connection to go-librespot Websocket Feb 12 21:26:49 volumio go-librespot[23123]: time="2026-02-12T21:26:49+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 12 21:26:49 volumio go-librespot[23123]: time="2026-02-12T21:26:49+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 12 21:26:49 volumio go-librespot[23123]: time="2026-02-12T21:26:49+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 12 21:26:49 volumio go-librespot[23123]: time="2026-02-12T21:26:49+07:00" level=debug msg="new websocket client" Feb 12 21:26:49 volumio volumio[22696]: info: Connection to go-librespot Websocket established Feb 12 21:26:49 volumio go-librespot[23123]: time="2026-02-12T21:26:49+07:00" level=info msg="zeroconf server listening on port 40567" Feb 12 21:26:49 volumio volumio[22696]: info: Setting Geolocation for MyVolumio to as1 Feb 12 21:26:49 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:26:49 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:26:49 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:26:49 volumio go-librespot[23123]: time="2026-02-12T21:26:49+07:00" level=debug msg="obtained new client token: AAAwaKR0VBI9vf2pXZKWUY/80RIXzV5ksL0O5tYsVRevYxpeu7153LFgf/gvPKLcPheIxJgBt+SqxRJyeY9eowSOiSRa58AOXYuJfjsJzTPF5eCul1226hfDn4cphrEwM8Fd2xSc7EqQYuCl5H9h+5PsDx/GqSL+uni38mckvi1j0rl0i32igRRIcgqTySaV6XxXOScnkfAyTijWtMbGSTs3yAsYDO5owFMzEw6TJYUzCniLH5F7Eotjeg==" Feb 12 21:26:49 volumio go-librespot[23123]: time="2026-02-12T21:26:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 21:26:50 volumio go-librespot[23123]: time="2026-02-12T21:26:50+07:00" level=debug msg="completed keyexchange" Feb 12 21:26:50 volumio go-librespot[23123]: time="2026-02-12T21:26:50+07:00" level=debug msg="completed challenge" Feb 12 21:26:50 volumio volumio[22696]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 12 21:26:50 volumio go-librespot[23123]: time="2026-02-12T21:26:50+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 21:26:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 21:26:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 21:26:50 volumio volumio[22696]: info: Connection to go-librespot Websocket closed Feb 12 21:26:50 volumio volumio[22696]: info: Updating MyVolumio device info Feb 12 21:26:50 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:26:50 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:26:50 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:26:51 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 21:26:51 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:26:51 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 12 21:26:51 volumio volumio[22696]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 12 21:26:52 volumio volumio-remote-updater[643]: Test mode disabled Feb 12 21:26:52 volumio volumio-remote-updater[643]: Alpha mode disabled Feb 12 21:26:52 volumio volumio-remote-updater[643]: Alpha legacy test mode disabled Feb 12 21:26:52 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Feb 12 21:26:52 volumio volumio[22696]: 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 12 21:26:52 volumio volumio[22696]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 12 21:26:52 volumio volumio[22696]: info: Getting Spotify volume Feb 12 21:26:52 volumio volumio[22696]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 21:26:52 volumio volumio[22696]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 21:26:52 volumio volumio[22696]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 12 21:26:52 volumio volumio[22696]: errno: -111, Feb 12 21:26:52 volumio volumio[22696]: code: 'ECONNREFUSED', Feb 12 21:26:52 volumio volumio[22696]: syscall: 'connect', Feb 12 21:26:52 volumio volumio[22696]: address: '127.0.0.1', Feb 12 21:26:52 volumio volumio[22696]: port: 9879, Feb 12 21:26:52 volumio volumio[22696]: response: undefined Feb 12 21:26:52 volumio volumio[22696]: } Feb 12 21:26:52 volumio volumio[22696]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 21:26:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Feb 12 21:26:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:26:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:26:53 volumio go-librespot[23165]: go-librespot daemon starting... Feb 12 21:26:53 volumio go-librespot[23166]: time="2026-02-12T21:26:53+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 21:26:53 volumio go-librespot[23166]: time="2026-02-12T21:26:53+07:00" level=debug msg="app state loaded" Feb 12 21:26:53 volumio go-librespot[23166]: time="2026-02-12T21:26:53+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 21:26:53 volumio go-librespot[23166]: time="2026-02-12T21:26: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 21:26:53 volumio go-librespot[23166]: time="2026-02-12T21:26:53+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 12 21:26:53 volumio go-librespot[23166]: time="2026-02-12T21:26:53+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 12 21:26:53 volumio go-librespot[23166]: time="2026-02-12T21:26:53+07:00" level=info msg="zeroconf server listening on port 39867" Feb 12 21:26:54 volumio go-librespot[23166]: time="2026-02-12T21:26:54+07:00" level=debug msg="obtained new client token: AAB/pUaWcEnL4NPdOCR0jXWpgDOP8oOeU9VU4VgEdjNm3BANfi+3b8lUwRkqaEM3qQDrIFQIoKh/kq/jzAWOllSnE/+85b/zKbFuP93NKt0AhvfbEIC4s9jnRgBIv43pzhTLDzM90BuEb1ASEQZWT3+ccpr0QbQT+DlH9+y6ekA+yvdhXnawXzv2SOBkOfGQAe4JpK2YoLUp+Us/ixz/5hNohBYqA/Uif3+hhLnLX2wLHUQ63JSW0lA=" Feb 12 21:26:54 volumio sudo[23175]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 21:25' Feb 12 21:26:54 volumio sudo[23175]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:26:54 volumio go-librespot[23166]: time="2026-02-12T21:26:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 21:26:54 volumio sudo[23175]: pam_unix(sudo:session): session closed for user root Feb 12 21:26:54 volumio volumio-remote-updater[643]: [2026-02-12 21:26:54] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 12 21:26:54 volumio volumio-remote-updater[643]: [2026-02-12 21:26:54] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 12 21:26:54 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 12 21:26:54 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 12 21:26:54 volumio systemd[1]: volumio.service: Consumed 58.322s CPU time. Feb 12 21:26:54 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 12 21:26:54 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 12 21:26:54 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 13783. Feb 12 21:26:54 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 12 21:26:54 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 12 21:26:54 volumio systemd[1]: volumio.service: Consumed 58.322s CPU time. Feb 12 21:26:54 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 12 21:26:54 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 12 21:26:55 volumio go-librespot[23166]: time="2026-02-12T21:26:55+07:00" level=debug msg="completed keyexchange" Feb 12 21:26:55 volumio go-librespot[23166]: time="2026-02-12T21:26:55+07:00" level=debug msg="completed challenge" Feb 12 21:26:55 volumio go-librespot[23166]: time="2026-02-12T21:26:55+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 12 21:26:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 21:26:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 21:26:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Feb 12 21:26:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:26:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:26:58 volumio go-librespot[23206]: go-librespot daemon starting... Feb 12 21:26:58 volumio go-librespot[23210]: time="2026-02-12T21:26:58+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 21:26:58 volumio go-librespot[23210]: time="2026-02-12T21:26:58+07:00" level=debug msg="app state loaded" Feb 12 21:26:58 volumio go-librespot[23210]: time="2026-02-12T21:26:58+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 21:26:58 volumio volumio[23188]: info: ------------------------------------------- Feb 12 21:26:58 volumio volumio[23188]: info: ----- Volumio3 ---- Feb 12 21:26:58 volumio volumio[23188]: info: ------------------------------------------- Feb 12 21:26:58 volumio volumio[23188]: info: ----- System startup ---- Feb 12 21:26:58 volumio volumio[23188]: info: ------------------------------------------- Feb 12 21:26:58 volumio go-librespot[23210]: time="2026-02-12T21:26:58+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 12 21:26:58 volumio go-librespot[23210]: time="2026-02-12T21:26:58+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 12 21:26:58 volumio go-librespot[23210]: time="2026-02-12T21:26:58+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 12 21:26:58 volumio go-librespot[23210]: time="2026-02-12T21:26:58+07:00" level=info msg="zeroconf server listening on port 42941" Feb 12 21:26:59 volumio go-librespot[23210]: time="2026-02-12T21:26:59+07:00" level=debug msg="obtained new client token: AADa95N6l1AqXCj38FzF6f1HKnQjArR6OgzuP7K8gzSG7wSxpJLDyR8pZTFrVcb+K6bsWE9uLX1zM7RJ5RwJ1mRexaR78uqF6v0CeM8A64uCLwN1RPF+MLHgwuTpYMHT29GiBJeASjdBoHFMH8CINjCjHghIltuzjUJEHOKUpbtq7pfGoQPGWFCKdwbB2Ebqw1Y5Ttt5hX7poIeBwFUyL9hytlrq+Yv2862jlOG/nFlIWDoLuIO5T8Y=" Feb 12 21:26:59 volumio go-librespot[23210]: time="2026-02-12T21:26:59+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 12 21:26:59 volumio go-librespot[23210]: time="2026-02-12T21:26:59+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Feb 12 21:26:59 volumio go-librespot[23210]: time="2026-02-12T21:26:59+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 12 21:26:59 volumio go-librespot[23210]: time="2026-02-12T21:26:59+07:00" level=debug msg="completed keyexchange" Feb 12 21:26:59 volumio go-librespot[23210]: time="2026-02-12T21:26:59+07:00" level=debug msg="completed challenge" Feb 12 21:26:59 volumio go-librespot[23210]: time="2026-02-12T21:26:59+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 12 21:26:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 21:26:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 21:26:59 volumio volumio-remote-updater[643]: [2026-02-12 21:26:59] [connect] Successful connection Feb 12 21:26:59 volumio volumio[23188]: info: MYVOLUMIO Environment detected Feb 12 21:27:00 volumio volumio[23188]: info: Plugin folders cleanup Feb 12 21:27:00 volumio volumio[23188]: info: Scanning into folder /volumio/app/plugins/ Feb 12 21:27:00 volumio volumio[23188]: info: Scanning category audio_interface Feb 12 21:27:00 volumio volumio[23188]: info: Scanning category miscellanea Feb 12 21:27:00 volumio volumio[23188]: info: Scanning category music_service Feb 12 21:27:00 volumio volumio[23188]: info: Scanning category plugins.json Feb 12 21:27:00 volumio volumio[23188]: info: Scanning category system_controller Feb 12 21:27:00 volumio volumio[23188]: info: Scanning category user_interface Feb 12 21:27:00 volumio volumio[23188]: info: Scanning into folder /data/plugins/ Feb 12 21:27:00 volumio volumio[23188]: info: Scanning category music_service Feb 12 21:27:00 volumio volumio[23188]: info: Plugin folders cleanup completed Feb 12 21:27:00 volumio volumio[23188]: info: ------------------------------------------- Feb 12 21:27:00 volumio volumio[23188]: info: ----- Core plugins startup ---- Feb 12 21:27:00 volumio volumio[23188]: info: ------------------------------------------- Feb 12 21:27:00 volumio volumio[23188]: info: Loading plugins from folder /volumio/app/plugins/ Feb 12 21:27:00 volumio volumio[23188]: info: Adding plugin upnp to MyMusic Plugins Feb 12 21:27:00 volumio volumio[23188]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 12 21:27:00 volumio volumio[23188]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 12 21:27:00 volumio volumio[23188]: info: Loading plugins from folder /data/plugins/ Feb 12 21:27:00 volumio volumio[23188]: info: Loading plugin "system"... Feb 12 21:27:00 volumio volumio[23188]: info: Loading plugin "appearance"... Feb 12 21:27:02 volumio volumio[23188]: info: Loading plugin "network"... Feb 12 21:27:02 volumio volumio[23188]: info: Refreshing Cached IP Addresses Feb 12 21:27:02 volumio sudo[23225]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 21:27:02 volumio sudo[23227]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 21:27:02 volumio sudo[23227]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:27:02 volumio sudo[23225]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:27:02 volumio sudo[23227]: pam_unix(sudo:session): session closed for user root Feb 12 21:27:02 volumio volumio[23188]: info: Loading plugin "services"... Feb 12 21:27:02 volumio sudo[23225]: pam_unix(sudo:session): session closed for user root Feb 12 21:27:02 volumio volumio[23188]: info: Loading plugin "alsa_controller"... Feb 12 21:27:02 volumio sudo[23234]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 12 21:27:02 volumio sudo[23234]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:27:02 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 21:27:02 volumio volumio[23188]: info: Loading plugin "wizard"... Feb 12 21:27:02 volumio volumio[23188]: info: Loading plugin "networkfs"... Feb 12 21:27:02 volumio volumio[23188]: info: Starting Udev Watcher for removable devices Feb 12 21:27:02 volumio volumio[23188]: info: Ignoring mount for partition: boot Feb 12 21:27:02 volumio volumio[23188]: info: Ignoring mount for partition: volumio Feb 12 21:27:02 volumio volumio[23188]: info: Ignoring mount for partition: volumio_data Feb 12 21:27:02 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 21:27:02 volumio volumio[23188]: info: Loading plugin "volumio_command_line_client"... Feb 12 21:27:02 volumio volumio[23188]: info: Loading plugin "upnp"... Feb 12 21:27:02 volumio volumio[23188]: info: [1770906422465] Starting Upmpd Daemon Feb 12 21:27:02 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 21:27:02 volumio volumio[23188]: info: Loading plugin "my_music"... Feb 12 21:27:02 volumio volumio[23188]: info: Loading plugin "mpd"... Feb 12 21:27:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Feb 12 21:27:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:27:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:27:02 volumio go-librespot[23258]: go-librespot daemon starting... Feb 12 21:27:02 volumio go-librespot[23259]: time="2026-02-12T21:27:02+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 21:27:02 volumio go-librespot[23259]: time="2026-02-12T21:27:02+07:00" level=debug msg="app state loaded" Feb 12 21:27:02 volumio go-librespot[23259]: time="2026-02-12T21:27:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 21:27:03 volumio volumio[23188]: info: Loading plugin "upnp_browser"... Feb 12 21:27:03 volumio go-librespot[23259]: time="2026-02-12T21:27:03+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 12 21:27:03 volumio go-librespot[23259]: time="2026-02-12T21:27:03+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 12 21:27:03 volumio go-librespot[23259]: time="2026-02-12T21:27:03+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 12 21:27:03 volumio go-librespot[23259]: time="2026-02-12T21:27:03+07:00" level=info msg="zeroconf server listening on port 35813" Feb 12 21:27:03 volumio go-librespot[23259]: time="2026-02-12T21:27:03+07:00" level=debug msg="obtained new client token: AACEuB2p6fkMtEUkbugulhGyb/DHOWWxF9KZneWB4BWpw5d93Hg24sWHQ0RVjZ35+MFl5WQZnK5oypbozV9Q06BCKOGOvrE1Oyp/ltxB0nzNsnFdaeX4wBbUsKdYKIHlkReJ86XRm2TV+v8tfURe3r0Fa3yG4+QMQ1kcQZbLbEwPvAFnW79s3/8NfY/wtEs7VnPOmLAzzIQxmeRDA5HObFR+ObRYbjnIUeStM9+g6itlAxLZAODGG/vGfQ==" Feb 12 21:27:03 volumio go-librespot[23259]: time="2026-02-12T21:27:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 21:27:03 volumio go-librespot[23259]: time="2026-02-12T21:27:03+07:00" level=debug msg="completed keyexchange" Feb 12 21:27:03 volumio go-librespot[23259]: time="2026-02-12T21:27:03+07:00" level=debug msg="completed challenge" Feb 12 21:27:03 volumio go-librespot[23259]: time="2026-02-12T21:27:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 21:27:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 21:27:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 21:27:04 volumio sudo[23234]: pam_unix(sudo:session): session closed for user root Feb 12 21:27:06 volumio volumio[23188]: info: Starting UPNP Browser Feb 12 21:27:06 volumio volumio[23188]: info: Loading plugin "alarm-clock"... Feb 12 21:27:06 volumio volumio[23188]: info: Loading plugin "airplay_emulation"... Feb 12 21:27:06 volumio volumio[23188]: info: Starting Shairport Sync Feb 12 21:27:06 volumio volumio[23188]: info: Loading plugin "last_100"... Feb 12 21:27:06 volumio volumio[23188]: info: Loading plugin "webradio"... Feb 12 21:27:06 volumio volumio[23188]: info: Loading plugin "i2s_dacs"... Feb 12 21:27:06 volumio volumio[23188]: info: Loading plugin "volumiodiscovery"... Feb 12 21:27:06 volumio volumio[23188]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 12 21:27:06 volumio volumio[23188]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 21:27:06 volumio node[23188]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 12 21:27:06 volumio volumio[23188]: *** WARNING *** For more information see Feb 12 21:27:06 volumio volumio[23188]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 12 21:27:06 volumio volumio[23188]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 21:27:06 volumio volumio[23188]: *** WARNING *** For more information see Feb 12 21:27:06 volumio node[23188]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 21:27:06 volumio node[23188]: *** WARNING *** For more information see Feb 12 21:27:06 volumio node[23188]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 12 21:27:06 volumio node[23188]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 21:27:06 volumio node[23188]: *** WARNING *** For more information see Feb 12 21:27:06 volumio volumio[23188]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 12 21:27:06 volumio volumio[23188]: info: Discovery: Started advertising with name: Volumio Feb 12 21:27:06 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 21:27:06 volumio volumio[23188]: info: Loading plugin "spop"... Feb 12 21:27:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33. Feb 12 21:27:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:27:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:27:07 volumio go-librespot[23268]: go-librespot daemon starting... Feb 12 21:27:07 volumio go-librespot[23269]: time="2026-02-12T21:27:07+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 21:27:07 volumio go-librespot[23269]: time="2026-02-12T21:27:07+07:00" level=debug msg="app state loaded" Feb 12 21:27:07 volumio go-librespot[23269]: time="2026-02-12T21:27:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 21:27:07 volumio go-librespot[23269]: time="2026-02-12T21:27:07+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 21:27:07 volumio go-librespot[23269]: time="2026-02-12T21:27:07+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 12 21:27:07 volumio go-librespot[23269]: time="2026-02-12T21:27:07+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 12 21:27:07 volumio go-librespot[23269]: time="2026-02-12T21:27:07+07:00" level=info msg="zeroconf server listening on port 34853" Feb 12 21:27:07 volumio go-librespot[23269]: time="2026-02-12T21:27:07+07:00" level=debug msg="obtained new client token: AACbL0rDbgWH2Q6FOkf6jaxHHsDCJISajm+RsxiD13pn+AtuHXb7cxoRBVNpaLiTAgIzu+p/DhoYZHmrMjuDbJcAizqwfLMWx/uFGA8sM3Q6XRIbBxt/HIzT90xudpLtDKDHQL3cJ0iJMA62Y3IYmde3KAG7dUlKVDbMaomckHmzBLK6lyf20LWeNhWvYs4oB4opwaukJarqkkFpWHnOPAZEIWlA/Tk51Tp9tFrRhfkxTKUKhjzLf++ghg==" Feb 12 21:27:07 volumio go-librespot[23269]: time="2026-02-12T21:27:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 21:27:08 volumio go-librespot[23269]: time="2026-02-12T21:27:08+07:00" level=debug msg="completed keyexchange" Feb 12 21:27:08 volumio go-librespot[23269]: time="2026-02-12T21:27:08+07:00" level=debug msg="completed challenge" Feb 12 21:27:08 volumio go-librespot[23269]: time="2026-02-12T21:27:08+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 12 21:27:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 21:27:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 21:27:08 volumio volumio[23188]: info: Loading plugin "ytcr"... Feb 12 21:27:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34. Feb 12 21:27:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:27:11 volumio volumio[23188]: info: Loading plugin "ytmusic"... Feb 12 21:27:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:27:11 volumio go-librespot[23278]: go-librespot daemon starting... Feb 12 21:27:11 volumio go-librespot[23279]: time="2026-02-12T21:27:11+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 21:27:11 volumio go-librespot[23279]: time="2026-02-12T21:27:11+07:00" level=debug msg="app state loaded" Feb 12 21:27:11 volumio go-librespot[23279]: time="2026-02-12T21:27:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 21:27:11 volumio go-librespot[23279]: time="2026-02-12T21:27:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 21:27:11 volumio go-librespot[23279]: time="2026-02-12T21:27:11+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 12 21:27:11 volumio go-librespot[23279]: time="2026-02-12T21:27:11+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 12 21:27:11 volumio go-librespot[23279]: time="2026-02-12T21:27:11+07:00" level=info msg="zeroconf server listening on port 32779" Feb 12 21:27:12 volumio go-librespot[23279]: time="2026-02-12T21:27:12+07:00" level=debug msg="obtained new client token: AACO38jyP2MV+yuiu4YZp0MkEdv7iBsGkMd2VzjrHjkcEoO+adKkkndwA759PkYwQQ2veZrZ4xyPQHKknoNxa3LaTK13lJgsGXLXugWWNe+0719T5zKj5SvV14rPNwwF+0lpxzBvxI6+2HgHOz74zNs4c+KfCJpYOHxPWGCpOm/o+6leGYkbmhip8fEWWu1hs01aEB8I5uEhQEcix7pKc0iR4RmDliJX5qFGQhjUOaRPPMVRMSJlOso=" Feb 12 21:27:12 volumio volumio-remote-updater[643]: [2026-02-12 21:27:12] [connect] Successful connection Feb 12 21:27:12 volumio go-librespot[23279]: time="2026-02-12T21:27:12+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 12 21:27:12 volumio go-librespot[23279]: time="2026-02-12T21:27:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 12 21:27:12 volumio volumio[23188]: info: Loading plugin "outputs"... Feb 12 21:27:12 volumio volumio[23188]: info: Loading plugin "albumart"... Feb 12 21:27:12 volumio volumio[23188]: info: Plugin example_plugin is not enabled Feb 12 21:27:12 volumio volumio[23188]: info: Loading plugin "inputs"... Feb 12 21:27:12 volumio volumio[23188]: info: Loading plugin "updater_comm"... Feb 12 21:27:12 volumio volumio[23188]: info: Plugin mpdemulation is not enabled Feb 12 21:27:12 volumio volumio[23188]: info: Loading plugin "rest_api"... Feb 12 21:27:12 volumio volumio[23188]: info: Loading plugin "websocket"... Feb 12 21:27:12 volumio volumio[23188]: info: Starting Socket.io Server version 1.7.4 Feb 12 21:27:12 volumio volumio[23188]: info: Loading plugin "RoonBridge"... Feb 12 21:27:12 volumio go-librespot[23279]: time="2026-02-12T21:27:12+07:00" level=debug msg="completed keyexchange" Feb 12 21:27:12 volumio go-librespot[23279]: time="2026-02-12T21:27:12+07:00" level=debug msg="completed challenge" Feb 12 21:27:12 volumio go-librespot[23279]: time="2026-02-12T21:27:12+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 12 21:27:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 21:27:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 21:27:13 volumio volumio[23188]: info: Applying required configuration parameters for plugin RoonBridge Feb 12 21:27:13 volumio volumio[23188]: info: Loading i18n strings for locale en Feb 12 21:27:13 volumio volumio[23188]: Updating browse sources language Feb 12 21:27:13 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 21:27:13 volumio volumio[23300]: Forking 3 albumart workers Feb 12 21:27:13 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 21:27:13 volumio volumio[23188]: info: CoreCommandRouter::initPlayerControls Feb 12 21:27:13 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:27:13 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:27:13 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:27:13 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:27:13 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:27:13 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:27:13 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:27:13 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:27:13 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 21:27:13 volumio volumio[23188]: Express server listening on port 3000 Feb 12 21:27:13 volumio volumio[23188]: [Metrics] WebUI: 16s 34.11ms Feb 12 21:27:13 volumio volumio[23188]: info: CoreStateMachine::resetVolumioState Feb 12 21:27:13 volumio volumio[23188]: info: CoreStateMachine::getcurrentVolume Feb 12 21:27:13 volumio volumio[23188]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 21:27:13 volumio sudo[23345]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 21:27:13 volumio sudo[23345]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:27:13 volumio sudo[23348]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 21:27:13 volumio volumio[23188]: info: Volumio Network Manager: Network status updated: 1 Feb 12 21:27:13 volumio sudo[23348]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:27:13 volumio sudo[23345]: pam_unix(sudo:session): session closed for user root Feb 12 21:27:13 volumio sudo[23348]: pam_unix(sudo:session): session closed for user root Feb 12 21:27:14 volumio volumio[23188]: info: VolumeController:: Volume=100 Mute =false Feb 12 21:27:14 volumio volumio[23188]: info: CoreStateMachine::pushState Feb 12 21:27:14 volumio volumio[23188]: info: CorePlayQueue::getTrack 0 Feb 12 21:27:14 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 21:27:14 volumio volumio[23188]: info: CoreCommandRouter::volumioPushState Feb 12 21:27:14 volumio volumio[23188]: info: CoreStateMachine::updateTrackBlock Feb 12 21:27:14 volumio volumio[23188]: info: CorePlayQueue::getTrackBlock Feb 12 21:27:14 volumio volumio[23188]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 21:27:14 volumio volumio-remote-updater[643]: [2026-02-12 21:27:14] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770906432 101 Feb 12 21:27:14 volumio volumio[23188]: 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 12 21:27:14 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:27:14 volumio volumio[23188]: info: Reloading queue from file Feb 12 21:27:14 volumio volumio[23188]: info: CoreStateMachine::setRepeat null single undefined Feb 12 21:27:14 volumio volumio[23188]: info: CoreStateMachine::pushState Feb 12 21:27:14 volumio volumio[23188]: info: CorePlayQueue::getTrack 0 Feb 12 21:27:14 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 21:27:14 volumio volumio[23188]: info: CoreCommandRouter::volumioPushState Feb 12 21:27:14 volumio volumio[23188]: info: CoreStateMachine::setRandom null Feb 12 21:27:14 volumio volumio[23188]: info: CoreStateMachine::pushState Feb 12 21:27:14 volumio volumio[23188]: info: CorePlayQueue::getTrack 0 Feb 12 21:27:14 volumio volumio[23188]: info: CoreCommandRouter::volumioPushState Feb 12 21:27:14 volumio volumio[23188]: info: Setting Device type: Raspberry PI Feb 12 21:27:14 volumio volumio[23188]: info: Completed loading Core Plugins Feb 12 21:27:14 volumio volumio[23188]: info: Preparing to generate the ALSA configuration file Feb 12 21:27:14 volumio volumio[23188]: info: VolumeController:: Volume=100 Mute =false Feb 12 21:27:14 volumio volumio[23188]: info: CoreStateMachine::pushState Feb 12 21:27:14 volumio volumio[23188]: info: CorePlayQueue::getTrack 0 Feb 12 21:27:14 volumio volumio[23188]: info: CoreCommandRouter::volumioPushState Feb 12 21:27:14 volumio volumio[23188]: info: Asound.conf file unchanged, so no further update is needed Feb 12 21:27:14 volumio volumio[23188]: info: Output device has changed, restarting MPD Feb 12 21:27:14 volumio volumio[23188]: info: Output device has changed, restarting Shairport Sync Feb 12 21:27:14 volumio sudo[23364]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 12 21:27:14 volumio sudo[23364]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:27:14 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:27:14 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:27:14 volumio volumio[23188]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 21:27:14 volumio sudo[23366]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 21:27:14 volumio volumio[23188]: info: ___________ START PLUGINS ___________ Feb 12 21:27:14 volumio sudo[23366]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:27:14 volumio sudo[23366]: pam_unix(sudo:session): session closed for user root Feb 12 21:27:14 volumio volumio[23188]: info: ControllerMpd::onStart: Initializing MPD Feb 12 21:27:14 volumio volumio[23188]: info: Creating MPD Configuration file Feb 12 21:27:14 volumio sudo[23369]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 21:27:14 volumio sudo[23369]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:27:14 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 21:27:14 volumio volumio[23188]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 21:27:14 volumio volumio[23188]: info: [1770906434913] CoreMusicLibrary::Adding element Media Servers Feb 12 21:27:14 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 21:27:14 volumio sudo[23364]: pam_unix(sudo:session): session closed for user root Feb 12 21:27:14 volumio volumio[23188]: info: UPNP Browser: Client initialized successfully Feb 12 21:27:14 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:27:14 volumio sudo[23377]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 21:27:14 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:27:14 volumio sudo[23377]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:27:15 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 12 21:27:15 volumio sudo[23377]: pam_unix(sudo:session): session closed for user root Feb 12 21:27:15 volumio volumio[23188]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 21:27:15 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:27:15 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:27:15 volumio sudo[23379]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 21:27:15 volumio sudo[23379]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:27:15 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 12 21:27:15 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 12 21:27:15 volumio systemd[1]: mpd.service: Consumed 7.146s CPU time. Feb 12 21:27:15 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 12 21:27:15 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 12 21:27:15 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 12 21:27:15 volumio volumio[23188]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 21:27:15 volumio volumio[23188]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 21:27:15 volumio volumio[23188]: info: [1770906435203] CoreMusicLibrary::Adding element Last_100 Feb 12 21:27:15 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 21:27:15 volumio volumio[23188]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 21:27:15 volumio volumio[23188]: info: [1770906435222] CoreMusicLibrary::Adding element Webradio Feb 12 21:27:15 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 21:27:15 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 12 21:27:15 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 21:27:15 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 12 21:27:15 volumio volumio[23188]: info: Initializing BBC Radios Feb 12 21:27:15 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 12 21:27:15 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 12 21:27:15 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 12 21:27:15 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 12 21:27:15 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 12 21:27:15 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 12 21:27:15 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 12 21:27:15 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 21:27:15 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:27:15 volumio volumio[23188]: info: Creating Spotify config file Feb 12 21:27:15 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:27:15 volumio sudo[23401]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 12 21:27:15 volumio sudo[23401]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 12 21:27:15 volumio sudo[23401]: pam_unix(sudo:session): session closed for user root Feb 12 21:27:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35. Feb 12 21:27:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:27:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:27:16 volumio go-librespot[23409]: go-librespot daemon starting... Feb 12 21:27:16 volumio go-librespot[23410]: time="2026-02-12T21:27:16+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 21:27:16 volumio volumio[23314]: Starting albumart workers Feb 12 21:27:16 volumio volumio[23188]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 21:27:16 volumio volumio[23188]: info: [1770906436836] CoreMusicLibrary::Adding element YouTube Music Feb 12 21:27:16 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 21:27:16 volumio volumio[23188]: Cannot find translation for source YouTube Music Feb 12 21:27:16 volumio go-librespot[23410]: time="2026-02-12T21:27:16+07:00" level=info msg="zeroconf server listening on port 43143" Feb 12 21:27:16 volumio volumio[23188]: info: Volumio Calling Home Feb 12 21:27:17 volumio sudo[23419]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 12 21:27:17 volumio sudo[23419]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:27:17 volumio sudo[23419]: pam_unix(sudo:session): session closed for user root Feb 12 21:27:17 volumio volumio[23313]: Starting albumart workers Feb 12 21:27:17 volumio volumio[23188]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 12 21:27:17 volumio volumio[23188]: info: Discovery: Found device Volumio Feb 12 21:27:17 volumio volumio[23188]: info: CoreCommandRouter::volumioGetState Feb 12 21:27:17 volumio volumio[23188]: info: CorePlayQueue::getTrack 0 Feb 12 21:27:17 volumio volumio[23188]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 12 21:27:17 volumio volumio[23188]: info: Discovery: Found device Volumio Feb 12 21:27:17 volumio volumio[23188]: info: CoreCommandRouter::volumioGetState Feb 12 21:27:17 volumio volumio[23188]: info: CorePlayQueue::getTrack 0 Feb 12 21:27:17 volumio volumio[23315]: Starting albumart workers Feb 12 21:27:17 volumio volumio[23188]: info: MPD Permissions set Feb 12 21:27:17 volumio volumio[23188]: info: MPD Permissions set Feb 12 21:27:17 volumio volumio[23188]: info: Upmpdcli Daemon Started Feb 12 21:27:17 volumio volumio[23188]: info: Volumio called home Feb 12 21:27:17 volumio volumio[23188]: info: Spotify config file written Feb 12 21:27:17 volumio volumio[23188]: 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 12 21:27:17 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:27:17 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:27:17 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:27:17 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:27:17 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:27:17 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:27:17 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:27:17 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:27:17 volumio sudo[23425]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 12 21:27:17 volumio sudo[23425]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:27:17 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:27:17 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:27:17 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:27:17 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:27:17 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:27:17 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:27:17 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:27:17 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:27:17 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:27:17 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:27:17 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 12 21:27:17 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 12 21:27:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:27:18 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:27:18 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:27:18 volumio volumio[23188]: info: No need to fix Spotify hosts Feb 12 21:27:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:27:18 volumio go-librespot[23437]: go-librespot daemon starting... Feb 12 21:27:18 volumio sudo[23425]: pam_unix(sudo:session): session closed for user root Feb 12 21:27:18 volumio go-librespot[23438]: time="2026-02-12T21:27:18+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 21:27:18 volumio go-librespot[23438]: time="2026-02-12T21:27:18+07:00" level=debug msg="app state loaded" Feb 12 21:27:18 volumio go-librespot[23438]: time="2026-02-12T21:27:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 21:27:18 volumio go-librespot[23438]: time="2026-02-12T21:27: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 12 21:27:18 volumio go-librespot[23438]: time="2026-02-12T21:27: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 12 21:27:18 volumio go-librespot[23438]: time="2026-02-12T21:27: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 12 21:27:18 volumio go-librespot[23438]: time="2026-02-12T21:27:18+07:00" level=info msg="zeroconf server listening on port 38631" Feb 12 21:27:19 volumio go-librespot[23438]: time="2026-02-12T21:27:19+07:00" level=debug msg="obtained new client token: AACaKGuAVzfWobEFIEw3TSKSZ4parAPmnIdSFPMALDyXLYzkuKa8RlzJvLnODo/3E1jDUsZI6i9OV2exsCJ9vAsI4czDKXg6DnWpN65wPrd7BIm/CE5R2AVbAdWlsjw8b5iV+N9D7tYpeBoJDlh/zNPC2fJHQwWnXWJD5zvo+scOKG7LSCSEENLTWpBwQZNbG05czGLRkosKRJAHD0hShLbSFgyWdfk5gwc47MqQV2xuhSe0z3DjIIo=" Feb 12 21:27:19 volumio go-librespot[23438]: time="2026-02-12T21:27:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 21:27:19 volumio go-librespot[23438]: time="2026-02-12T21:27:19+07:00" level=debug msg="completed keyexchange" Feb 12 21:27:19 volumio go-librespot[23438]: time="2026-02-12T21:27:19+07:00" level=debug msg="completed challenge" Feb 12 21:27:19 volumio volumio[23188]: info: Starting Shairport Sync Feb 12 21:27:19 volumio volumio[23188]: info: Starting Shairport Sync Feb 12 21:27:19 volumio volumio[23188]: info: Starting Shairport Sync Feb 12 21:27:19 volumio go-librespot[23438]: time="2026-02-12T21:27:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 21:27:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 21:27:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 21:27:19 volumio sudo[23459]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 21:27:19 volumio sudo[23457]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 21:27:19 volumio sudo[23459]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:27:19 volumio sudo[23457]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:27:19 volumio sudo[23453]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 21:27:19 volumio sudo[23453]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:27:19 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 21:27:19 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 21:27:19 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 21:27:19 volumio systemd[1]: shairport-sync.service: Consumed 2.407s CPU time. Feb 12 21:27:20 volumio volumio[23188]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 21:27:20 volumio volumio[23188]: SPOTIFY: BQAtAukOZdUHnbO5XNJ0puQMYOVWCfNx8-ABkplhfDwVqdGhGrv1Sz6sV6-xwA3VhOj8YLsori7ttJM9ufuo62aevwk9Yv5bNylmBe7ruAbXOpaTlkxZpBB5ajAgghvGbD1YGfl_ucO57DbfXd1IHfEFPGxcD43MCT7_pvXiJ8Z1da8VdZj0-iubXsWtQsb8la64Vc9cQuP3kbwZ6eNvP7CoP5l7PyuInNgQHiGkJ1LncfcX-n63CQb0n6MXgHEHYQOwdRuAiSYUhpyrC5TJ2IFQ-JPjtzwnXuPl94K6QtHGh9d5ynffcqeP Feb 12 21:27:20 volumio volumio[23188]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 21:27:20 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 21:27:20 volumio volumio[23188]: info: New Spotify access token = BQAtAukOZdUHnbO5XNJ0puQMYOVWCfNx8-ABkplhfDwVqdGhGrv1Sz6sV6-xwA3VhOj8YLsori7ttJM9ufuo62aevwk9Yv5bNylmBe7ruAbXOpaTlkxZpBB5ajAgghvGbD1YGfl_ucO57DbfXd1IHfEFPGxcD43MCT7_pvXiJ8Z1da8VdZj0-iubXsWtQsb8la64Vc9cQuP3kbwZ6eNvP7CoP5l7PyuInNgQHiGkJ1LncfcX-n63CQb0n6MXgHEHYQOwdRuAiSYUhpyrC5TJ2IFQ-JPjtzwnXuPl94K6QtHGh9d5ynffcqeP Feb 12 21:27:20 volumio volumio[23188]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 12 21:27:20 volumio sudo[23453]: pam_unix(sudo:session): session closed for user root Feb 12 21:27:20 volumio sudo[23459]: pam_unix(sudo:session): session closed for user root Feb 12 21:27:20 volumio sudo[23457]: pam_unix(sudo:session): session closed for user root Feb 12 21:27:20 volumio volumio[23188]: info: Shairport-Sync Started Feb 12 21:27:20 volumio volumio[23188]: Error adding Membership: Error: addMembership EINVAL Feb 12 21:27:20 volumio volumio[23188]: info: Shairport-Sync Started Feb 12 21:27:20 volumio volumio[23188]: info: Shairport-Sync Started Feb 12 21:27:20 volumio volumio[23188]: info: CoreCommandRouter::volumioGetState Feb 12 21:27:20 volumio volumio[23188]: info: CorePlayQueue::getTrack 0 Feb 12 21:27:20 volumio volumio[23188]: 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 12 21:27:20 volumio volumio[23188]: info: Spotify Successfully logged in Feb 12 21:27:20 volumio volumio[23188]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 21:27:20 volumio volumio[23188]: info: [1770906440594] CoreMusicLibrary::Adding element Spotify Feb 12 21:27:20 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 21:27:20 volumio volumio[23188]: Cannot find translation for source YouTube Music Feb 12 21:27:20 volumio volumio[23188]: Cannot find translation for source Spotify Feb 12 21:27:21 volumio volumio[23188]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 12 21:27:21 volumio volumio[23188]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 21:27:21 volumio volumio[23188]: info: VolumeController:: Volume=100 Mute =false Feb 12 21:27:21 volumio volumio[23188]: info: CoreCommandRouter::volumioGetState Feb 12 21:27:21 volumio volumio[23188]: info: CorePlayQueue::getTrack 0 Feb 12 21:27:21 volumio volumio[23188]: info: CoreStateMachine::pushState Feb 12 21:27:21 volumio volumio[23188]: info: CorePlayQueue::getTrack 0 Feb 12 21:27:21 volumio volumio[23188]: info: CoreCommandRouter::volumioPushState Feb 12 21:27:22 volumio volumio[23188]: info: go-librespot daemon successfully initialized Feb 12 21:27:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 12 21:27:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:27:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:27:22 volumio go-librespot[23504]: go-librespot daemon starting... Feb 12 21:27:22 volumio go-librespot[23505]: time="2026-02-12T21:27:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 21:27:22 volumio go-librespot[23505]: time="2026-02-12T21:27:22+07:00" level=debug msg="app state loaded" Feb 12 21:27:22 volumio go-librespot[23505]: time="2026-02-12T21:27:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 21:27:22 volumio mpd[23408]: 2026-02-12T21:27:22 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 12 21:27:22 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 12 21:27:22 volumio sudo[23369]: pam_unix(sudo:session): session closed for user root Feb 12 21:27:22 volumio sudo[23379]: pam_unix(sudo:session): session closed for user root Feb 12 21:27:23 volumio volumio[23188]: error: MPD error: The expression evaluated to a falsy value: Feb 12 21:27:23 volumio volumio[23188]: assert.ok(self.idling) Feb 12 21:27:23 volumio volumio[23188]: error: The expression evaluated to a falsy value: Feb 12 21:27:23 volumio volumio[23188]: assert.ok(self.idling) Feb 12 21:27:23 volumio volumio[23188]: info: MPD running with PID23408 Feb 12 21:27:23 volumio volumio[23188]: ,establishing connection Feb 12 21:27:23 volumio volumio[23188]: error: updateQueue error: null Feb 12 21:27:23 volumio volumio[23188]: info: Completed starting Core Plugins Feb 12 21:27:23 volumio volumio[23188]: info: ------------------------------------------- Feb 12 21:27:23 volumio volumio[23188]: info: ----- MyVolumio plugins startup ---- Feb 12 21:27:23 volumio volumio[23188]: info: ------------------------------------------- Feb 12 21:27:23 volumio volumio[23188]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 12 21:27:23 volumio volumio[23188]: error: updateQueue error: null Feb 12 21:27:23 volumio go-librespot[23505]: time="2026-02-12T21:27:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 21:27:23 volumio go-librespot[23505]: time="2026-02-12T21:27:23+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 12 21:27:23 volumio go-librespot[23505]: time="2026-02-12T21:27:23+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 12 21:27:23 volumio go-librespot[23505]: time="2026-02-12T21:27:23+07:00" level=info msg="zeroconf server listening on port 37673" Feb 12 21:27:23 volumio go-librespot[23505]: time="2026-02-12T21:27:23+07:00" level=debug msg="obtained new client token: AADx77ZKxgZA80N8PnidHSENwGYIJjlGRh/TKCfk3Ym1ZmNXZVg3gc3SCwNeSUMLAa9S2zFSeUgbyKLywkzhMIjDujm9a1BypG9FugvHqF1hyt67/VaEzui6yQHJgEXb+60lWkc+eFi6wJROzK3kXBwaqvMC9xs31nfkJVF53MGE5wQVhTCjCraxft9O8M8Zd1Yxh/WyyDNp5TahRkUQX5BNWozB1RYaWecnFC5zGnuq6Z4vCelBA8nEbQ==" Feb 12 21:27:23 volumio go-librespot[23505]: time="2026-02-12T21:27:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 21:27:23 volumio go-librespot[23505]: time="2026-02-12T21:27:23+07:00" level=debug msg="completed keyexchange" Feb 12 21:27:23 volumio go-librespot[23505]: time="2026-02-12T21:27:23+07:00" level=debug msg="completed challenge" Feb 12 21:27:24 volumio go-librespot[23505]: time="2026-02-12T21:27:24+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 12 21:27:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 21:27:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 21:27:25 volumio volumio[23188]: info: Initializing connection to go-librespot Websocket Feb 12 21:27:25 volumio volumio[23188]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 21:27:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 12 21:27:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:27:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:27:27 volumio go-librespot[23517]: go-librespot daemon starting... Feb 12 21:27:27 volumio go-librespot[23518]: time="2026-02-12T21:27:27+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 21:27:27 volumio go-librespot[23518]: time="2026-02-12T21:27:27+07:00" level=debug msg="app state loaded" Feb 12 21:27:27 volumio go-librespot[23518]: time="2026-02-12T21:27:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 21:27:27 volumio go-librespot[23518]: time="2026-02-12T21:27:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 21:27:27 volumio go-librespot[23518]: time="2026-02-12T21:27:27+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 21:27:27 volumio go-librespot[23518]: time="2026-02-12T21:27:27+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 21:27:27 volumio go-librespot[23518]: time="2026-02-12T21:27:27+07:00" level=info msg="zeroconf server listening on port 39705" Feb 12 21:27:27 volumio go-librespot[23518]: time="2026-02-12T21:27:27+07:00" level=debug msg="obtained new client token: AAAksn4juMroplyFwJpfgAH6HsOCpRShiRK1dxRH78e5CkNEOtt/7559wghnwgdkJuhv3vCptATrH8QHR+iU7jSrtQkItVankxFTr6PfZA+iqyBr68dx4wRj131mxLEklhJ7bzdNuZc9uUdi8ah6qRRtQXete2J7D/3PsWA5YJRdRe0u5s0/+HBFFxRrtTa8G1e37bAPSy9runMilyfDKFU8T1de/4n8hDEB9ApS65FdIPUyOM0Ki3pFVg==" Feb 12 21:27:27 volumio go-librespot[23518]: time="2026-02-12T21:27:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 21:27:27 volumio go-librespot[23518]: time="2026-02-12T21:27: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 12 21:27:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 21:27:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 21:27:28 volumio volumio[23188]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 12 21:27:28 volumio volumio[23188]: info: Initializing connection to go-librespot Websocket Feb 12 21:27:28 volumio volumio[23188]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 21:27:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 12 21:27:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:27:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:27:31 volumio go-librespot[23525]: go-librespot daemon starting... Feb 12 21:27:31 volumio go-librespot[23526]: time="2026-02-12T21:27:31+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 21:27:31 volumio go-librespot[23526]: time="2026-02-12T21:27:31+07:00" level=debug msg="app state loaded" Feb 12 21:27:31 volumio go-librespot[23526]: time="2026-02-12T21:27:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 21:27:31 volumio volumio[23188]: info: Initializing connection to go-librespot Websocket Feb 12 21:27:31 volumio go-librespot[23526]: time="2026-02-12T21:27:31+07:00" level=debug msg="new websocket client" Feb 12 21:27:31 volumio volumio[23188]: info: Connection to go-librespot Websocket established Feb 12 21:27:31 volumio go-librespot[23526]: time="2026-02-12T21:27:31+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 12 21:27:31 volumio go-librespot[23526]: time="2026-02-12T21:27:31+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 12 21:27:31 volumio go-librespot[23526]: time="2026-02-12T21:27:31+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 12 21:27:31 volumio go-librespot[23526]: time="2026-02-12T21:27:31+07:00" level=info msg="zeroconf server listening on port 35761" Feb 12 21:27:31 volumio go-librespot[23526]: time="2026-02-12T21:27:31+07:00" level=debug msg="obtained new client token: AADhH1fJbDGeK7CfJNVPBR8B1YOpamdx4qh97/tMiaCMJTUINqHVafLTJgNSGinskBO16+82Hykb4gewXF0VfBARZjWKOxy/dlNV0BeYD1hriAhRDPce5uLTNi8Dkn09yyUdt+lzJEIm56M5uasDIcqwuCK4tKQT/veZEOps5o0eYLTZwyJCevZ6T8kIqKIy0MmoRRgBLsUWG279j4CpJcr8XVtEuAaFM4DhjlFY7cWjAieXFmB7ma2U5A==" Feb 12 21:27:32 volumio go-librespot[23526]: time="2026-02-12T21:27:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 21:27:32 volumio volumio[23188]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 12 21:27:32 volumio volumio[23188]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 12 21:27:32 volumio volumio[23188]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 12 21:27:32 volumio volumio[23188]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 12 21:27:32 volumio volumio[23188]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 12 21:27:32 volumio volumio[23188]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 12 21:27:32 volumio volumio[23188]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 12 21:27:32 volumio volumio[23188]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 12 21:27:32 volumio volumio[23188]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 12 21:27:32 volumio volumio[23188]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 12 21:27:32 volumio volumio[23188]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 12 21:27:32 volumio volumio[23188]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 12 21:27:32 volumio volumio[23188]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 12 21:27:32 volumio volumio[23188]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 12 21:27:32 volumio volumio[23188]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 12 21:27:32 volumio volumio[23188]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 12 21:27:32 volumio volumio[23188]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 12 21:27:32 volumio volumio[23188]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 12 21:27:32 volumio volumio[23188]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 12 21:27:32 volumio volumio[23188]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 12 21:27:32 volumio volumio[23188]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 12 21:27:32 volumio volumio[23188]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 12 21:27:32 volumio volumio[23188]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 12 21:27:32 volumio volumio[23188]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 12 21:27:32 volumio volumio[23188]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 12 21:27:32 volumio volumio[23188]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 12 21:27:32 volumio volumio[23188]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 12 21:27:32 volumio volumio[23188]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 12 21:27:32 volumio volumio[23188]: info: Adding plugin bluetooth to MyMusic Plugins Feb 12 21:27:32 volumio volumio[23188]: info: Adding plugin multiroom to MyMusic Plugins Feb 12 21:27:32 volumio volumio[23188]: info: Adding plugin metavolumio to MyMusic Plugins Feb 12 21:27:32 volumio volumio[23188]: info: Adding plugin cd_controller to MyMusic Plugins Feb 12 21:27:32 volumio volumio[23188]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 12 21:27:32 volumio volumio[23188]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 12 21:27:32 volumio volumio[23188]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 12 21:27:32 volumio volumio[23188]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 12 21:27:32 volumio go-librespot[23526]: time="2026-02-12T21:27:32+07:00" level=debug msg="completed keyexchange" Feb 12 21:27:32 volumio go-librespot[23526]: time="2026-02-12T21:27:32+07:00" level=debug msg="completed challenge" Feb 12 21:27:32 volumio go-librespot[23526]: time="2026-02-12T21:27:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 21:27:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 21:27:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 21:27:33 volumio volumio[23188]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 12 21:27:33 volumio volumio[23188]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 12 21:27:33 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:27:33 volumio volumio[23188]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:27:33 volumio volumio[23188]: info: Starting MyVolumio Remote Streaming Endpoints Feb 12 21:27:33 volumio volumio[23188]: info: MyVolumio login type: Token Feb 12 21:27:34 volumio volumio[23188]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 12 21:27:34 volumio volumio[23188]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 12 21:27:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 12 21:27:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:27:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 21:27:35 volumio go-librespot[23549]: go-librespot daemon starting... Feb 12 21:27:35 volumio go-librespot[23550]: time="2026-02-12T21:27:35+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 21:27:35 volumio go-librespot[23550]: time="2026-02-12T21:27:35+07:00" level=debug msg="app state loaded" Feb 12 21:27:35 volumio go-librespot[23550]: time="2026-02-12T21:27:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 21:27:35 volumio volumio[23188]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 12 21:27:35 volumio volumio[23188]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 12 21:27:35 volumio volumio[23188]: info: Streaming services startup Feb 12 21:27:35 volumio volumio[23188]: info: Starting Streaming Daemon Feb 12 21:27:35 volumio sudo[23559]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 12 21:27:35 volumio sudo[23559]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 21:27:35 volumio volumio[23188]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 12 21:27:35 volumio sudo[23559]: pam_unix(sudo:session): session closed for user root Feb 12 21:27:35 volumio go-librespot[23550]: time="2026-02-12T21:27: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 21:27:35 volumio go-librespot[23550]: time="2026-02-12T21:27:35+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 12 21:27:35 volumio go-librespot[23550]: time="2026-02-12T21:27:35+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 12 21:27:35 volumio go-librespot[23550]: time="2026-02-12T21:27:35+07:00" level=info msg="zeroconf server listening on port 34729" Feb 12 21:27:36 volumio volumio[23188]: info: Getting Spotify volume Feb 12 21:27:36 volumio volumio[23188]: info: Connection to go-librespot Websocket closed Feb 12 21:27:36 volumio volumio[23188]: error: Cannot start Volumio Streaming Daemon Feb 12 21:27:36 volumio volumio[23188]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 12 21:27:36 volumio volumio[23188]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 12 21:27:36 volumio volumio[23188]: 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 12 21:27:36 volumio go-librespot[23550]: time="2026-02-12T21:27:36+07:00" level=debug msg="obtained new client token: AACNqSf8GOc/O/Z9fg9qzhn5jG3lQg4OuomgJ2NCud2SUUEv4jYU0l61wgTAkzJtpsqM1NKU6o9tkRc8pUL6nmBKtJkKEwxCDfTNhQTKcdgV5u1ogF3XIwE1Fs/upTzU5pDr/vF9bTX8LYLHVWw+H1i07TzSrhmSIFQ79+dyK05Uj/CO32y/FV0RU7EBulQMM6fzN+/1qDSjDIoQqdtpYzJb03Pz5awOwd21ey2qsi4126sf5/b4YuU=" Feb 12 21:27:36 volumio volumio[23188]: info: CoreCommandRouter::volumioGetState Feb 12 21:27:36 volumio volumio[23188]: info: CorePlayQueue::getTrack 0 Feb 12 21:27:36 volumio volumio[23188]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 12 21:27:36 volumio volumio[23188]: SPOTIFY: SPOTIFY VOLUME undefined Feb 12 21:27:36 volumio volumio[23188]: SPOTIFY: VOLUMIO VOLUME 100 Feb 12 21:27:36 volumio volumio[23188]: info: Aligning Spotify Volume to Volumio Volume Feb 12 21:27:36 volumio volumio[23188]: info: CoreCommandRouter::volumioGetState Feb 12 21:27:36 volumio volumio[23188]: info: CorePlayQueue::getTrack 0 Feb 12 21:27:36 volumio volumio[23188]: info: Setting Spotify Volume from Volumio: 100 Feb 12 21:27:36 volumio go-librespot[23550]: time="2026-02-12T21:27:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 21:27:36 volumio go-librespot[23550]: time="2026-02-12T21:27:36+07:00" level=debug msg="completed keyexchange" Feb 12 21:27:36 volumio go-librespot[23550]: time="2026-02-12T21:27:36+07:00" level=debug msg="completed challenge" Feb 12 21:27:36 volumio go-librespot[23550]: time="2026-02-12T21:27:36+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 12 21:27:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 21:27:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 21:27:36 volumio volumio[23188]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 21:27:36 volumio volumio[23188]: Error: socket hang up Feb 12 21:27:36 volumio volumio[23188]: at connResetException (node:internal/errors:720:14) Feb 12 21:27:36 volumio volumio[23188]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 12 21:27:36 volumio volumio[23188]: at Socket.emit (node:events:526:35) Feb 12 21:27:36 volumio volumio[23188]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 12 21:27:36 volumio volumio[23188]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 12 21:27:36 volumio volumio[23188]: code: 'ECONNRESET', Feb 12 21:27:36 volumio volumio[23188]: response: undefined Feb 12 21:27:36 volumio volumio[23188]: } Feb 12 21:27:36 volumio volumio[23188]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 21:27:38 volumio sudo[23579]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 21:26' Feb 12 21:27:38 volumio sudo[23579]: 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"