Feb 18 15:22:01 volumio volumio[27128]: info: ------------------------------------------- Feb 18 15:22:01 volumio volumio[27128]: info: ----- Volumio3 ---- Feb 18 15:22:01 volumio volumio[27128]: info: ------------------------------------------- Feb 18 15:22:01 volumio volumio[27128]: info: ----- System startup ---- Feb 18 15:22:01 volumio volumio[27128]: info: ------------------------------------------- Feb 18 15:22:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33. Feb 18 15:22:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:22:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:22:02 volumio go-librespot[27152]: go-librespot daemon starting... Feb 18 15:22:02 volumio go-librespot[27153]: time="2026-02-18T15:22:02+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:22:02 volumio go-librespot[27153]: time="2026-02-18T15:22:02+07:00" level=debug msg="app state loaded" Feb 18 15:22:02 volumio go-librespot[27153]: time="2026-02-18T15:22:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:22:02 volumio volumio-remote-updater[25144]: [2026-02-18 15:22:02] [connect] Successful connection Feb 18 15:22:02 volumio go-librespot[27153]: time="2026-02-18T15:22:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:22:02 volumio go-librespot[27153]: time="2026-02-18T15:22:02+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 15:22:02 volumio go-librespot[27153]: time="2026-02-18T15:22:02+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 15:22:02 volumio go-librespot[27153]: time="2026-02-18T15:22:02+07:00" level=info msg="zeroconf server listening on port 37985" Feb 18 15:22:02 volumio volumio[27128]: info: MYVOLUMIO Environment detected Feb 18 15:22:02 volumio go-librespot[27153]: time="2026-02-18T15:22:02+07:00" level=debug msg="obtained new client token: AABMCPO+fHIQmpQIpQudqbaJB+TaptG17m2C3U8TE3h+SFFyaci1hQoEiqXWKR/AfzrclcUl9fXWnxxBV99K6jgT/qGj/54Jh3a3Y7ZSxbnrmjgK4VRgJK7nuWCfjphFYQFG2KEjEOvHNOfXRyCb7mwgygIAnyImiUDpcTrbVCQfCrRfRPB1Lc6NOtMds68j9ycK9Bhpxq56CSBUaZFvLZcCMKZzGxUOtPPqafZ9yMHlQ2AaJoBGuj4hbw==" Feb 18 15:22:03 volumio volumio[27128]: info: Plugin folders cleanup Feb 18 15:22:03 volumio volumio[27128]: info: Scanning into folder /volumio/app/plugins/ Feb 18 15:22:03 volumio volumio[27128]: info: Scanning category audio_interface Feb 18 15:22:03 volumio volumio[27128]: info: Scanning category miscellanea Feb 18 15:22:03 volumio volumio[27128]: info: Scanning category music_service Feb 18 15:22:03 volumio volumio[27128]: info: Scanning category plugins.json Feb 18 15:22:03 volumio volumio[27128]: info: Scanning category system_controller Feb 18 15:22:03 volumio volumio[27128]: info: Scanning category user_interface Feb 18 15:22:03 volumio volumio[27128]: info: Scanning into folder /data/plugins/ Feb 18 15:22:03 volumio volumio[27128]: info: Scanning category music_service Feb 18 15:22:03 volumio volumio[27128]: info: Plugin folders cleanup completed Feb 18 15:22:03 volumio volumio[27128]: info: ------------------------------------------- Feb 18 15:22:03 volumio volumio[27128]: info: ----- Core plugins startup ---- Feb 18 15:22:03 volumio volumio[27128]: info: ------------------------------------------- Feb 18 15:22:03 volumio volumio[27128]: info: Loading plugins from folder /volumio/app/plugins/ Feb 18 15:22:03 volumio volumio[27128]: info: Adding plugin upnp to MyMusic Plugins Feb 18 15:22:03 volumio volumio[27128]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 18 15:22:03 volumio volumio[27128]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 18 15:22:03 volumio volumio[27128]: info: Loading plugins from folder /data/plugins/ Feb 18 15:22:03 volumio go-librespot[27153]: time="2026-02-18T15:22:03+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 18 15:22:03 volumio volumio[27128]: info: Loading plugin "system"... Feb 18 15:22:03 volumio go-librespot[27153]: time="2026-02-18T15:22:03+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 18 15:22:03 volumio volumio[27128]: info: Loading plugin "appearance"... Feb 18 15:22:03 volumio go-librespot[27153]: time="2026-02-18T15:22:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 18 15:22:03 volumio go-librespot[27153]: time="2026-02-18T15:22:03+07:00" level=debug msg="completed keyexchange" Feb 18 15:22:03 volumio go-librespot[27153]: time="2026-02-18T15:22:03+07:00" level=debug msg="completed challenge" Feb 18 15:22:03 volumio go-librespot[27153]: time="2026-02-18T15:22:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 15:22:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:22:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:22:05 volumio volumio[27128]: info: Loading plugin "network"... Feb 18 15:22:05 volumio volumio[27128]: info: Refreshing Cached IP Addresses Feb 18 15:22:05 volumio sudo[27168]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 15:22:05 volumio sudo[27168]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:22:05 volumio sudo[27170]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 15:22:05 volumio volumio[27128]: info: Loading plugin "services"... Feb 18 15:22:05 volumio sudo[27170]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:22:05 volumio sudo[27168]: pam_unix(sudo:session): session closed for user root Feb 18 15:22:05 volumio volumio[27128]: info: Loading plugin "alsa_controller"... Feb 18 15:22:05 volumio sudo[27170]: pam_unix(sudo:session): session closed for user root Feb 18 15:22:05 volumio sudo[27182]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 18 15:22:05 volumio sudo[27182]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:22:05 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 15:22:05 volumio volumio[27128]: info: Loading plugin "wizard"... Feb 18 15:22:05 volumio volumio[27128]: info: Loading plugin "networkfs"... Feb 18 15:22:05 volumio volumio[27128]: info: Starting Udev Watcher for removable devices Feb 18 15:22:05 volumio volumio[27128]: info: Ignoring mount for partition: boot Feb 18 15:22:05 volumio volumio[27128]: info: Ignoring mount for partition: volumio Feb 18 15:22:05 volumio volumio[27128]: info: Ignoring mount for partition: volumio_data Feb 18 15:22:05 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 15:22:05 volumio volumio[27128]: info: Loading plugin "volumio_command_line_client"... Feb 18 15:22:05 volumio volumio[27128]: info: Loading plugin "upnp"... Feb 18 15:22:05 volumio volumio[27128]: info: [1771402925448] Starting Upmpd Daemon Feb 18 15:22:05 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 15:22:05 volumio volumio[27128]: info: Loading plugin "my_music"... Feb 18 15:22:05 volumio volumio[27128]: info: Loading plugin "mpd"... Feb 18 15:22:06 volumio volumio[27128]: info: Loading plugin "upnp_browser"... Feb 18 15:22:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34. Feb 18 15:22:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:22:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:22:06 volumio go-librespot[27201]: go-librespot daemon starting... Feb 18 15:22:06 volumio go-librespot[27202]: time="2026-02-18T15:22:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:22:06 volumio go-librespot[27202]: time="2026-02-18T15:22:06+07:00" level=debug msg="app state loaded" Feb 18 15:22:06 volumio go-librespot[27202]: time="2026-02-18T15:22:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:22:07 volumio go-librespot[27202]: time="2026-02-18T15:22: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:22:07 volumio go-librespot[27202]: time="2026-02-18T15:22:07+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 15:22:07 volumio go-librespot[27202]: time="2026-02-18T15:22:07+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 15:22:07 volumio go-librespot[27202]: time="2026-02-18T15:22:07+07:00" level=info msg="zeroconf server listening on port 35503" Feb 18 15:22:07 volumio go-librespot[27202]: time="2026-02-18T15:22:07+07:00" level=debug msg="obtained new client token: AAD3WUd1a5n9rmEOcSNuFJppdZsnkRVxk+y9fnik2tInX7Q1jXCtq5Ag24xoOVrPh40AHM1jdC3vsbqnerDkeiesp+G1d1ZdZIM/zBBpHhc8SZgi25Ers7SZL1Cvs27a+VH3yVsMZ76o57a/hguFXf247zO9rcR3Xg4UUXPeELedVZD4qtbw3o3t6FKiueZLaiu1D3koL4gg7mGrTF+DxJx30jp81OQ75FqOd7yc32QNE7FOcWxbshBGnw==" Feb 18 15:22:07 volumio go-librespot[27202]: time="2026-02-18T15:22:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:22:07 volumio go-librespot[27202]: time="2026-02-18T15:22:07+07:00" level=debug msg="completed keyexchange" Feb 18 15:22:07 volumio go-librespot[27202]: time="2026-02-18T15:22:07+07:00" level=debug msg="completed challenge" Feb 18 15:22:07 volumio go-librespot[27202]: time="2026-02-18T15:22:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 15:22:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:22:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:22:07 volumio sudo[27182]: pam_unix(sudo:session): session closed for user root Feb 18 15:22:09 volumio volumio[27128]: info: Starting UPNP Browser Feb 18 15:22:09 volumio volumio[27128]: info: Loading plugin "alarm-clock"... Feb 18 15:22:09 volumio volumio[27128]: info: Loading plugin "airplay_emulation"... Feb 18 15:22:09 volumio volumio[27128]: info: Starting Shairport Sync Feb 18 15:22:09 volumio volumio[27128]: info: Loading plugin "last_100"... Feb 18 15:22:09 volumio volumio[27128]: info: Loading plugin "webradio"... Feb 18 15:22:09 volumio volumio[27128]: info: Loading plugin "i2s_dacs"... Feb 18 15:22:09 volumio volumio[27128]: info: Loading plugin "volumiodiscovery"... Feb 18 15:22:09 volumio volumio[27128]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 15:22:09 volumio volumio[27128]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 15:22:09 volumio volumio[27128]: *** WARNING *** For more information see Feb 18 15:22:09 volumio volumio[27128]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 15:22:09 volumio volumio[27128]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 15:22:09 volumio volumio[27128]: *** WARNING *** For more information see Feb 18 15:22:09 volumio node[27128]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 15:22:09 volumio node[27128]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 15:22:09 volumio node[27128]: *** WARNING *** For more information see Feb 18 15:22:09 volumio node[27128]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 15:22:09 volumio node[27128]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 15:22:09 volumio node[27128]: *** WARNING *** For more information see Feb 18 15:22:09 volumio volumio[27128]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 18 15:22:09 volumio volumio[27128]: info: Discovery: Started advertising with name: Volumio Feb 18 15:22:09 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 15:22:09 volumio volumio[27128]: info: Loading plugin "spop"... Feb 18 15:22:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35. Feb 18 15:22:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:22:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:22:10 volumio go-librespot[27211]: go-librespot daemon starting... Feb 18 15:22:10 volumio go-librespot[27212]: time="2026-02-18T15:22:10+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:22:10 volumio go-librespot[27212]: time="2026-02-18T15:22:10+07:00" level=debug msg="app state loaded" Feb 18 15:22:10 volumio go-librespot[27212]: time="2026-02-18T15:22:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:22:11 volumio go-librespot[27212]: time="2026-02-18T15:22:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:22:11 volumio go-librespot[27212]: time="2026-02-18T15:22:11+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 15:22:11 volumio go-librespot[27212]: time="2026-02-18T15:22:11+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 15:22:11 volumio go-librespot[27212]: time="2026-02-18T15:22:11+07:00" level=info msg="zeroconf server listening on port 42751" Feb 18 15:22:11 volumio volumio[27128]: info: Loading plugin "ytcr"... Feb 18 15:22:11 volumio go-librespot[27212]: time="2026-02-18T15:22:11+07:00" level=debug msg="obtained new client token: AABxeZm5uRYfHyvg36rowEAtZjMFsl/xlHdHdZIQ5F0hpRCsbb5BtN8lcU/AR/f9CwTFURcNBl90kfnjlHxw5Xv9TDYcf1yu+yT60DnOuMj41wOgxqS2gullDsUhn1v9kgPl1WHyXK60rXtZ6NCsATKxoFi/myS0CAKWodqXJGnUXTjItGE8Qlp/pUHSzpiAMRREHcvnfRfc3MVdMT7nhRNX3JQC+2cvUzZ78EAJzU/YO36f9bUDDVpYtw==" Feb 18 15:22:11 volumio go-librespot[27212]: time="2026-02-18T15:22:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:22:12 volumio go-librespot[27212]: time="2026-02-18T15:22:12+07:00" level=debug msg="completed keyexchange" Feb 18 15:22:12 volumio go-librespot[27212]: time="2026-02-18T15:22:12+07:00" level=debug msg="completed challenge" Feb 18 15:22:12 volumio go-librespot[27212]: time="2026-02-18T15:22: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 18 15:22:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:22:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:22:14 volumio volumio[27128]: info: Loading plugin "ytmusic"... Feb 18 15:22:15 volumio volumio-remote-updater[25144]: [2026-02-18 15:22:15] [connect] Successful connection Feb 18 15:22:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 36. Feb 18 15:22:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:22:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:22:15 volumio go-librespot[27235]: go-librespot daemon starting... Feb 18 15:22:15 volumio volumio[27128]: info: Loading plugin "outputs"... Feb 18 15:22:15 volumio volumio[27128]: info: Loading plugin "albumart"... Feb 18 15:22:15 volumio go-librespot[27236]: time="2026-02-18T15:22:15+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:22:15 volumio go-librespot[27236]: time="2026-02-18T15:22:15+07:00" level=debug msg="app state loaded" Feb 18 15:22:15 volumio go-librespot[27236]: time="2026-02-18T15:22:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:22:15 volumio volumio[27128]: info: Plugin example_plugin is not enabled Feb 18 15:22:15 volumio volumio[27128]: info: Loading plugin "inputs"... Feb 18 15:22:15 volumio volumio[27128]: info: Loading plugin "updater_comm"... Feb 18 15:22:15 volumio volumio[27128]: info: Plugin mpdemulation is not enabled Feb 18 15:22:15 volumio volumio[27128]: info: Loading plugin "rest_api"... Feb 18 15:22:15 volumio volumio[27128]: info: Loading plugin "websocket"... Feb 18 15:22:15 volumio volumio[27128]: info: Starting Socket.io Server version 1.7.4 Feb 18 15:22:15 volumio volumio[27128]: info: Loading plugin "RoonBridge"... Feb 18 15:22:15 volumio go-librespot[27236]: time="2026-02-18T15:22: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-gew4.spotify.com:80]" Feb 18 15:22:15 volumio go-librespot[27236]: time="2026-02-18T15:22:15+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 15:22:15 volumio go-librespot[27236]: time="2026-02-18T15:22:15+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 15:22:15 volumio go-librespot[27236]: time="2026-02-18T15:22:15+07:00" level=info msg="zeroconf server listening on port 46425" Feb 18 15:22:16 volumio go-librespot[27236]: time="2026-02-18T15:22:16+07:00" level=debug msg="obtained new client token: AABwP5kDWmJi7XWusdiuBSo3Uitbcu+LD9amTOcxX3qnzYE9ogBgTdABpwvBRjM6dFruaK64KZ6zsbCZq2NbcB8RMjU57tpKEaLBGizxrCtA+TvRvbvTblq4HqoD80ITkXDTQU41z2WQY/r+QenVRTgRbdRcXNeTwCq5lTKD9YfUn41XdRV40mftCVciJCbXmg8UqKEp0RxieFxbpi8KbROhsIjvxURURWf4vgEHOz4s8Uk3tzopfUQ=" Feb 18 15:22:16 volumio go-librespot[27236]: time="2026-02-18T15:22:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:22:16 volumio volumio[27128]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 15:22:16 volumio go-librespot[27236]: time="2026-02-18T15:22:16+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 15:22:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:22:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:22:16 volumio volumio[27128]: info: Loading i18n strings for locale en Feb 18 15:22:16 volumio volumio[27128]: Updating browse sources language Feb 18 15:22:16 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:22:16 volumio volumio[27242]: Forking 3 albumart workers Feb 18 15:22:16 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 15:22:16 volumio volumio[27128]: info: CoreCommandRouter::initPlayerControls Feb 18 15:22:16 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:22:16 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:22:16 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:22:16 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:22:16 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:22:16 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:22:16 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:22:16 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:22:16 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 15:22:16 volumio volumio[27128]: Express server listening on port 3000 Feb 18 15:22:16 volumio volumio[27128]: [Metrics] WebUI: 16s 169.87ms Feb 18 15:22:16 volumio volumio[27128]: info: CoreStateMachine::resetVolumioState Feb 18 15:22:16 volumio volumio[27128]: info: CoreStateMachine::getcurrentVolume Feb 18 15:22:16 volumio volumio[27128]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 15:22:16 volumio sudo[27286]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 15:22:16 volumio sudo[27286]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:22:16 volumio sudo[27286]: pam_unix(sudo:session): session closed for user root Feb 18 15:22:16 volumio sudo[27289]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 15:22:17 volumio sudo[27289]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:22:17 volumio sudo[27289]: pam_unix(sudo:session): session closed for user root Feb 18 15:22:17 volumio volumio[27128]: info: Volumio Network Manager: Network status updated: 1 Feb 18 15:22:17 volumio volumio[27128]: info: VolumeController:: Volume=100 Mute =false Feb 18 15:22:17 volumio volumio[27128]: info: CoreStateMachine::pushState Feb 18 15:22:17 volumio volumio[27128]: info: CorePlayQueue::getTrack 0 Feb 18 15:22:17 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 15:22:17 volumio volumio[27128]: info: CoreCommandRouter::volumioPushState Feb 18 15:22:17 volumio volumio[27128]: info: CoreStateMachine::updateTrackBlock Feb 18 15:22:17 volumio volumio[27128]: info: CorePlayQueue::getTrackBlock Feb 18 15:22:17 volumio volumio[27128]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 15:22:17 volumio volumio-remote-updater[25144]: [2026-02-18 15:22:17] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771402935 101 Feb 18 15:22:17 volumio volumio[27128]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 18 15:22:17 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:22:17 volumio volumio[27128]: info: Reloading queue from file Feb 18 15:22:17 volumio volumio[27128]: info: CoreStateMachine::setRepeat null single undefined Feb 18 15:22:17 volumio volumio[27128]: info: CoreStateMachine::pushState Feb 18 15:22:17 volumio volumio[27128]: info: CorePlayQueue::getTrack 0 Feb 18 15:22:17 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 15:22:17 volumio volumio[27128]: info: CoreCommandRouter::volumioPushState Feb 18 15:22:17 volumio volumio[27128]: info: CoreStateMachine::setRandom null Feb 18 15:22:17 volumio volumio[27128]: info: CoreStateMachine::pushState Feb 18 15:22:17 volumio volumio[27128]: info: CorePlayQueue::getTrack 0 Feb 18 15:22:17 volumio volumio[27128]: info: CoreCommandRouter::volumioPushState Feb 18 15:22:17 volumio volumio[27128]: info: Setting Device type: Raspberry PI Feb 18 15:22:17 volumio volumio[27128]: info: Completed loading Core Plugins Feb 18 15:22:17 volumio volumio[27128]: info: Preparing to generate the ALSA configuration file Feb 18 15:22:17 volumio volumio[27128]: info: VolumeController:: Volume=100 Mute =false Feb 18 15:22:17 volumio volumio[27128]: info: CoreStateMachine::pushState Feb 18 15:22:17 volumio volumio[27128]: info: CorePlayQueue::getTrack 0 Feb 18 15:22:17 volumio volumio[27128]: info: CoreCommandRouter::volumioPushState Feb 18 15:22:17 volumio volumio[27128]: info: Asound.conf file unchanged, so no further update is needed Feb 18 15:22:17 volumio volumio[27128]: info: Output device has changed, restarting MPD Feb 18 15:22:17 volumio volumio[27128]: info: Output device has changed, restarting Shairport Sync Feb 18 15:22:17 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:22:17 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:22:18 volumio sudo[27305]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 15:22:18 volumio sudo[27305]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:22:18 volumio sudo[27307]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 15:22:18 volumio sudo[27307]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:22:18 volumio sudo[27307]: pam_unix(sudo:session): session closed for user root Feb 18 15:22:18 volumio sudo[27309]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 15:22:18 volumio volumio[27128]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 15:22:18 volumio sudo[27309]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:22:18 volumio volumio[27128]: info: ___________ START PLUGINS ___________ Feb 18 15:22:18 volumio volumio[27128]: info: ControllerMpd::onStart: Initializing MPD Feb 18 15:22:18 volumio volumio[27128]: info: Creating MPD Configuration file Feb 18 15:22:18 volumio sudo[27305]: pam_unix(sudo:session): session closed for user root Feb 18 15:22:18 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 15:22:18 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 15:22:18 volumio volumio[27128]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:22:18 volumio volumio[27128]: info: [1771402938237] CoreMusicLibrary::Adding element Media Servers Feb 18 15:22:18 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:22:18 volumio sudo[27320]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 15:22:18 volumio sudo[27318]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 15:22:18 volumio sudo[27320]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:22:18 volumio sudo[27318]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:22:18 volumio volumio[27128]: info: UPNP Browser: Client initialized successfully Feb 18 15:22:18 volumio sudo[27318]: pam_unix(sudo:session): session closed for user root Feb 18 15:22:18 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 15:22:18 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 15:22:18 volumio systemd[1]: mpd.service: Consumed 7.090s CPU time. Feb 18 15:22:18 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 15:22:18 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 15:22:18 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 15:22:18 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:22:18 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:22:18 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 15:22:18 volumio volumio[27128]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 15:22:18 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 15:22:18 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:22:18 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:22:18 volumio volumio[27128]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 15:22:18 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 15:22:18 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 15:22:18 volumio volumio[27128]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:22:18 volumio volumio[27128]: info: [1771402938581] CoreMusicLibrary::Adding element Last_100 Feb 18 15:22:18 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:22:18 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 15:22:18 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 15:22:18 volumio volumio[27128]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:22:18 volumio volumio[27128]: info: [1771402938595] CoreMusicLibrary::Adding element Webradio Feb 18 15:22:18 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:22:18 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 15:22:18 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 15:22:18 volumio volumio[27128]: info: Initializing BBC Radios Feb 18 15:22:18 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 15:22:18 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 15:22:18 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 15:22:18 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:22:18 volumio volumio[27128]: info: Creating Spotify config file Feb 18 15:22:18 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:22:19 volumio sudo[27347]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 15:22:19 volumio sudo[27347]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 15:22:19 volumio sudo[27347]: pam_unix(sudo:session): session closed for user root Feb 18 15:22:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 37. Feb 18 15:22:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:22:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:22:19 volumio go-librespot[27350]: go-librespot daemon starting... Feb 18 15:22:19 volumio volumio[27254]: Starting albumart workers Feb 18 15:22:19 volumio go-librespot[27351]: time="2026-02-18T15:22:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:22:19 volumio volumio[27255]: Starting albumart workers Feb 18 15:22:20 volumio volumio[27128]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:22:20 volumio volumio[27128]: info: [1771402940010] CoreMusicLibrary::Adding element YouTube Music Feb 18 15:22:20 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:22:20 volumio volumio[27128]: Cannot find translation for source YouTube Music Feb 18 15:22:20 volumio volumio[27128]: info: Volumio Calling Home Feb 18 15:22:20 volumio sudo[27358]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 15:22:20 volumio sudo[27358]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:22:20 volumio volumio[27256]: Starting albumart workers Feb 18 15:22:20 volumio sudo[27358]: pam_unix(sudo:session): session closed for user root Feb 18 15:22:20 volumio go-librespot[27351]: time="2026-02-18T15:22:20+07:00" level=info msg="zeroconf server listening on port 46821" Feb 18 15:22:21 volumio volumio[27128]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 15:22:21 volumio volumio[27128]: info: Discovery: Found device Volumio Feb 18 15:22:21 volumio volumio[27128]: info: CoreCommandRouter::volumioGetState Feb 18 15:22:21 volumio volumio[27128]: info: CorePlayQueue::getTrack 0 Feb 18 15:22:21 volumio volumio[27128]: info: MPD Permissions set Feb 18 15:22:21 volumio volumio[27128]: info: MPD Permissions set Feb 18 15:22:21 volumio volumio[27128]: info: Upmpdcli Daemon Started Feb 18 15:22:21 volumio volumio[27128]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 15:22:21 volumio volumio[27128]: info: Discovery: Found device Volumio Feb 18 15:22:21 volumio volumio[27128]: info: CoreCommandRouter::volumioGetState Feb 18 15:22:21 volumio volumio[27128]: info: CorePlayQueue::getTrack 0 Feb 18 15:22:21 volumio volumio[27128]: info: Volumio called home Feb 18 15:22:21 volumio volumio[27128]: info: Spotify config file written Feb 18 15:22:21 volumio volumio[27128]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 18 15:22:21 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:22:21 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:22:21 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:22:21 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:22:21 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:22:21 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:22:21 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:22:21 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:22:21 volumio sudo[27366]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 15:22:21 volumio sudo[27366]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:22:21 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:22:21 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:22:21 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:22:21 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:22:21 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:22:21 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:22:21 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:22:21 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:22:21 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:22:21 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:22:21 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:22:21 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 18 15:22:21 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 18 15:22:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:22:21 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:22:21 volumio volumio[27128]: info: No need to fix Spotify hosts Feb 18 15:22:21 volumio go-librespot[27378]: go-librespot daemon starting... Feb 18 15:22:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:22:21 volumio sudo[27366]: pam_unix(sudo:session): session closed for user root Feb 18 15:22:21 volumio go-librespot[27380]: time="2026-02-18T15:22:21+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:22:21 volumio go-librespot[27380]: time="2026-02-18T15:22:21+07:00" level=debug msg="app state loaded" Feb 18 15:22:21 volumio go-librespot[27380]: time="2026-02-18T15:22:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:22:22 volumio go-librespot[27380]: time="2026-02-18T15:22:22+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:22:22 volumio go-librespot[27380]: time="2026-02-18T15:22:22+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 15:22:22 volumio go-librespot[27380]: time="2026-02-18T15:22:22+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 15:22:22 volumio go-librespot[27380]: time="2026-02-18T15:22:22+07:00" level=info msg="zeroconf server listening on port 33483" Feb 18 15:22:22 volumio go-librespot[27380]: time="2026-02-18T15:22:22+07:00" level=debug msg="obtained new client token: AACZGb73Kt/5Gp5pOrmg8KViGDRaCIRFG3lUHLrpPYvbEipmFsEbTU93BZW+gnRU32JEv1A9SOedSPygODsS/dIP4/xpTm1H0nKfwx5K+XO3IYwN4+TuNIcOwz1UO/I+EYDD6smiaz2FYQkfrUHg9dsYX9gMVQ9XFl1RpM40t+XGipGplm2j+2CGVPc2p8kPGEpK6kpUegd+1s4BqieOcT82lX/c5iDE5ADSTZ/NIPecB5FJ5SE5CwATLQ==" Feb 18 15:22:22 volumio volumio[27128]: info: Starting Shairport Sync Feb 18 15:22:22 volumio go-librespot[27380]: time="2026-02-18T15:22:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:22:22 volumio volumio[27128]: info: Starting Shairport Sync Feb 18 15:22:22 volumio volumio[27128]: info: Starting Shairport Sync Feb 18 15:22:22 volumio go-librespot[27380]: time="2026-02-18T15:22:22+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 15:22:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:22:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:22:22 volumio sudo[27406]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 15:22:22 volumio sudo[27406]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:22:22 volumio sudo[27408]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 15:22:22 volumio sudo[27408]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:22:23 volumio sudo[27410]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 15:22:23 volumio sudo[27410]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:22:23 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 15:22:23 volumio volumio[27128]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 15:22:23 volumio volumio[27128]: SPOTIFY: BQD_DjGGlSAfAvwyBF_LOm93k_0DG3HqdObHYfKHKuw32UWafu-13zzkFJRRRhgzMzlujig3p7uxQEHiH4iuLuxzZlPhEmwtwzd8YKTxnp07lYW-CPR2GUqcGMFRagRZlniJWxQy5qWBckcnrHh9CycR1FVtnKf9d6lTkIq7L5obErgJXVS2eUnGyIYbIKkFL0Hb2-KtyDLcqEXwyoPkGo37ta48_jh-hs-Pb-KLgQHQLQ13chnTTda1kTqRbp7KTCxseyo8QfZixrZyVpSNSoPlk9eo9lAWjlGtKlYEowc_pQbL4o7NY3CC Feb 18 15:22:23 volumio volumio[27128]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 15:22:23 volumio volumio[27128]: info: New Spotify access token = BQD_DjGGlSAfAvwyBF_LOm93k_0DG3HqdObHYfKHKuw32UWafu-13zzkFJRRRhgzMzlujig3p7uxQEHiH4iuLuxzZlPhEmwtwzd8YKTxnp07lYW-CPR2GUqcGMFRagRZlniJWxQy5qWBckcnrHh9CycR1FVtnKf9d6lTkIq7L5obErgJXVS2eUnGyIYbIKkFL0Hb2-KtyDLcqEXwyoPkGo37ta48_jh-hs-Pb-KLgQHQLQ13chnTTda1kTqRbp7KTCxseyo8QfZixrZyVpSNSoPlk9eo9lAWjlGtKlYEowc_pQbL4o7NY3CC Feb 18 15:22:23 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 15:22:23 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 15:22:23 volumio systemd[1]: shairport-sync.service: Consumed 2.289s CPU time. Feb 18 15:22:23 volumio volumio[27128]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 15:22:23 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 15:22:23 volumio sudo[27410]: pam_unix(sudo:session): session closed for user root Feb 18 15:22:23 volumio sudo[27406]: pam_unix(sudo:session): session closed for user root Feb 18 15:22:23 volumio sudo[27408]: pam_unix(sudo:session): session closed for user root Feb 18 15:22:23 volumio volumio[27128]: info: CoreCommandRouter::volumioGetState Feb 18 15:22:23 volumio volumio[27128]: info: CorePlayQueue::getTrack 0 Feb 18 15:22:23 volumio volumio[27128]: info: Shairport-Sync Started Feb 18 15:22:23 volumio volumio[27128]: Error adding Membership: Error: addMembership EINVAL Feb 18 15:22:23 volumio volumio[27128]: info: Shairport-Sync Started Feb 18 15:22:23 volumio volumio[27128]: info: Shairport-Sync Started Feb 18 15:22:23 volumio volumio[27128]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 18 15:22:23 volumio volumio[27128]: info: Spotify Successfully logged in Feb 18 15:22:23 volumio volumio[27128]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:22:23 volumio volumio[27128]: info: [1771402943786] CoreMusicLibrary::Adding element Spotify Feb 18 15:22:23 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:22:23 volumio volumio[27128]: Cannot find translation for source YouTube Music Feb 18 15:22:23 volumio volumio[27128]: Cannot find translation for source Spotify Feb 18 15:22:24 volumio volumio[27128]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 15:22:24 volumio volumio[27128]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 15:22:24 volumio volumio[27128]: info: VolumeController:: Volume=100 Mute =false Feb 18 15:22:24 volumio volumio[27128]: info: CoreCommandRouter::volumioGetState Feb 18 15:22:24 volumio volumio[27128]: info: CorePlayQueue::getTrack 0 Feb 18 15:22:24 volumio volumio[27128]: info: CoreStateMachine::pushState Feb 18 15:22:24 volumio volumio[27128]: info: CorePlayQueue::getTrack 0 Feb 18 15:22:24 volumio volumio[27128]: info: CoreCommandRouter::volumioPushState Feb 18 15:22:25 volumio volumio[27128]: info: go-librespot daemon successfully initialized Feb 18 15:22:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 18 15:22:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:22:26 volumio mpd[27349]: 2026-02-18T15:22:26 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 15:22:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:22:26 volumio go-librespot[27447]: go-librespot daemon starting... Feb 18 15:22:26 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 15:22:26 volumio sudo[27309]: pam_unix(sudo:session): session closed for user root Feb 18 15:22:26 volumio sudo[27320]: pam_unix(sudo:session): session closed for user root Feb 18 15:22:26 volumio go-librespot[27448]: time="2026-02-18T15:22:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:22:26 volumio go-librespot[27448]: time="2026-02-18T15:22:26+07:00" level=debug msg="app state loaded" Feb 18 15:22:26 volumio go-librespot[27448]: time="2026-02-18T15:22:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:22:26 volumio volumio[27128]: error: MPD error: The expression evaluated to a falsy value: Feb 18 15:22:26 volumio volumio[27128]: assert.ok(self.idling) Feb 18 15:22:26 volumio volumio[27128]: error: The expression evaluated to a falsy value: Feb 18 15:22:26 volumio volumio[27128]: assert.ok(self.idling) Feb 18 15:22:26 volumio volumio[27128]: info: MPD running with PID27349 Feb 18 15:22:26 volumio volumio[27128]: ,establishing connection Feb 18 15:22:26 volumio volumio[27128]: error: updateQueue error: null Feb 18 15:22:26 volumio volumio[27128]: info: Completed starting Core Plugins Feb 18 15:22:26 volumio volumio[27128]: info: ------------------------------------------- Feb 18 15:22:26 volumio volumio[27128]: info: ----- MyVolumio plugins startup ---- Feb 18 15:22:26 volumio volumio[27128]: info: ------------------------------------------- Feb 18 15:22:26 volumio volumio[27128]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 15:22:26 volumio volumio[27128]: error: updateQueue error: null Feb 18 15:22:26 volumio go-librespot[27448]: time="2026-02-18T15:22:26+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:22:26 volumio go-librespot[27448]: time="2026-02-18T15:22:26+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 15:22:26 volumio go-librespot[27448]: time="2026-02-18T15:22:26+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 15:22:26 volumio go-librespot[27448]: time="2026-02-18T15:22:26+07:00" level=info msg="zeroconf server listening on port 34703" Feb 18 15:22:26 volumio go-librespot[27448]: time="2026-02-18T15:22:26+07:00" level=debug msg="obtained new client token: AAA/S+xPrFhvtWLNMUsgL5xnoP2YRJ08iAB0pBzD2duNbL4SclyhC0xmSLFuiSjAm3Tu/SqecweN5X7G2PxMyH39kLSwKAplUi6mrJtvZOEQIHdZxjODxkz8yg+DpV7NqhSCJQ76O3mDoCNAQqFz/39zVZQ7LDy/28NkTNIuahJP+JUE+kG+i/YZ1dXlZxTq3DEUqalvTjnSfcxZnGfH1JfUqTcO/na3s9Gu27vAMAYsorh5QB2asNlpxw==" Feb 18 15:22:27 volumio go-librespot[27448]: time="2026-02-18T15:22:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:22:27 volumio go-librespot[27448]: time="2026-02-18T15:22: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 18 15:22:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:22:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:22:28 volumio volumio[27128]: info: Initializing connection to go-librespot Websocket Feb 18 15:22:28 volumio volumio[27128]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 15:22:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 18 15:22:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:22:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:22:30 volumio go-librespot[27459]: go-librespot daemon starting... Feb 18 15:22:30 volumio go-librespot[27460]: time="2026-02-18T15:22:30+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:22:30 volumio go-librespot[27460]: time="2026-02-18T15:22:30+07:00" level=debug msg="app state loaded" Feb 18 15:22:30 volumio go-librespot[27460]: time="2026-02-18T15:22:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:22:30 volumio go-librespot[27460]: time="2026-02-18T15:22:30+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:22:30 volumio go-librespot[27460]: time="2026-02-18T15:22:30+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 15:22:30 volumio go-librespot[27460]: time="2026-02-18T15:22:30+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 15:22:30 volumio go-librespot[27460]: time="2026-02-18T15:22:30+07:00" level=info msg="zeroconf server listening on port 41119" Feb 18 15:22:31 volumio go-librespot[27460]: time="2026-02-18T15:22:31+07:00" level=debug msg="obtained new client token: AADJwZW6OP76RfU/jrlsZxfbOdOrhg2YkvBdjrsa475UDH/83rkl3rpoBHUOyuaU8R5DpvmngdMI4qrsBhYsMo0O9siCxaOLOvfYCIYm8m2NLUsoNFRy7wdt1/WV1xiN70G+y5x80zRabW/ZHkbxYY01mAF2kuBPnE52BweXgLMTGVF4HJVN9s6+kwKCVxi1L5H4TPoQhWvJwK1CyHQ9jEDddY9d0kCp1WdLukBxysNHkqFLGv+X3+w=" Feb 18 15:22:31 volumio go-librespot[27460]: time="2026-02-18T15:22:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:22:31 volumio volumio[27128]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 15:22:31 volumio go-librespot[27460]: time="2026-02-18T15:22:31+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 15:22:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:22:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:22:31 volumio volumio[27128]: info: Initializing connection to go-librespot Websocket Feb 18 15:22:31 volumio volumio[27128]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 15:22:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 18 15:22:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:22:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:22:34 volumio go-librespot[27471]: go-librespot daemon starting... Feb 18 15:22:34 volumio go-librespot[27472]: time="2026-02-18T15:22:34+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:22:34 volumio go-librespot[27472]: time="2026-02-18T15:22:34+07:00" level=debug msg="app state loaded" Feb 18 15:22:34 volumio go-librespot[27472]: time="2026-02-18T15:22:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:22:34 volumio volumio[27128]: info: Initializing connection to go-librespot Websocket Feb 18 15:22:34 volumio go-librespot[27472]: time="2026-02-18T15:22:34+07:00" level=debug msg="new websocket client" Feb 18 15:22:34 volumio go-librespot[27472]: time="2026-02-18T15:22:34+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 15:22:34 volumio go-librespot[27472]: time="2026-02-18T15:22:34+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 15:22:34 volumio go-librespot[27472]: time="2026-02-18T15:22:34+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 15:22:34 volumio volumio[27128]: info: Connection to go-librespot Websocket established Feb 18 15:22:34 volumio go-librespot[27472]: time="2026-02-18T15:22:34+07:00" level=info msg="zeroconf server listening on port 33395" Feb 18 15:22:35 volumio go-librespot[27472]: time="2026-02-18T15:22:35+07:00" level=debug msg="obtained new client token: AAAtl9m662CPaUb6fSmp/8S2kJRT314qdqj+6XHBDoOYP+0/OXokTjXsoREaXkC/cwO3sslT6e5K3SeShze86sSi18TL9AJCiFtGZWRgCKoc1DgvrHRff8Ab1HqdQHY2fu0THLSLQEI8Pgryt/C+Z/PrZYe5J2pS1xoLnzvQoL0N6NC7ik/oq0O+aD2TkF5T4uPen9w7ND41mSisJyj2e092kLP0hm9ZRjF1Y/XkktxYbjIWq2r91ZE=" Feb 18 15:22:35 volumio go-librespot[27472]: time="2026-02-18T15:22:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:22:35 volumio volumio[27128]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 15:22:35 volumio volumio[27128]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 15:22:35 volumio volumio[27128]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 15:22:35 volumio volumio[27128]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 15:22:35 volumio volumio[27128]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 15:22:35 volumio volumio[27128]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 15:22:35 volumio volumio[27128]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 15:22:35 volumio volumio[27128]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 15:22:35 volumio volumio[27128]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 15:22:35 volumio volumio[27128]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 15:22:35 volumio volumio[27128]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 15:22:35 volumio volumio[27128]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 15:22:35 volumio volumio[27128]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 15:22:35 volumio volumio[27128]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 15:22:35 volumio volumio[27128]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 15:22:35 volumio volumio[27128]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 15:22:35 volumio volumio[27128]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 15:22:35 volumio volumio[27128]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 15:22:35 volumio volumio[27128]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 15:22:35 volumio volumio[27128]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 15:22:35 volumio volumio[27128]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 15:22:35 volumio volumio[27128]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 15:22:35 volumio volumio[27128]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 15:22:35 volumio volumio[27128]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 15:22:35 volumio volumio[27128]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 15:22:35 volumio volumio[27128]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 15:22:35 volumio volumio[27128]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 15:22:35 volumio volumio[27128]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 15:22:35 volumio volumio[27128]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 15:22:35 volumio volumio[27128]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 15:22:35 volumio volumio[27128]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 15:22:35 volumio volumio[27128]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 15:22:35 volumio volumio[27128]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 15:22:35 volumio volumio[27128]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 15:22:35 volumio volumio[27128]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 15:22:35 volumio volumio[27128]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 15:22:35 volumio go-librespot[27472]: time="2026-02-18T15:22:35+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.23:37572->104.199.241.202:4070: read: connection reset by peer" Feb 18 15:22:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:22:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:22:37 volumio volumio[27128]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 15:22:37 volumio volumio[27128]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 15:22:37 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:22:37 volumio volumio[27128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:22:37 volumio volumio[27128]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 15:22:37 volumio volumio[27128]: info: MyVolumio login type: Token Feb 18 15:22:37 volumio volumio[27128]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 15:22:37 volumio volumio[27128]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 15:22:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 18 15:22:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:22:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:22:38 volumio go-librespot[27493]: go-librespot daemon starting... Feb 18 15:22:38 volumio volumio[27128]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 15:22:38 volumio volumio[27128]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 15:22:38 volumio volumio[27128]: info: Streaming services startup Feb 18 15:22:38 volumio volumio[27128]: info: Starting Streaming Daemon Feb 18 15:22:38 volumio go-librespot[27494]: time="2026-02-18T15:22:38+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:22:38 volumio go-librespot[27494]: time="2026-02-18T15:22:38+07:00" level=debug msg="app state loaded" Feb 18 15:22:38 volumio go-librespot[27494]: time="2026-02-18T15:22:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:22:38 volumio sudo[27501]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 15:22:38 volumio sudo[27501]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:22:38 volumio volumio[27128]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 15:22:39 volumio sudo[27501]: pam_unix(sudo:session): session closed for user root Feb 18 15:22:39 volumio volumio[27128]: info: Getting Spotify volume Feb 18 15:22:39 volumio volumio[27128]: info: Connection to go-librespot Websocket closed Feb 18 15:22:39 volumio volumio[27128]: error: Cannot start Volumio Streaming Daemon Feb 18 15:22:39 volumio volumio[27128]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 15:22:39 volumio volumio[27128]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 15:22:39 volumio volumio[27128]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 18 15:22:39 volumio volumio[27128]: info: CoreCommandRouter::volumioGetState Feb 18 15:22:39 volumio volumio[27128]: info: CorePlayQueue::getTrack 0 Feb 18 15:22:39 volumio volumio[27128]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 18 15:22:39 volumio volumio[27128]: SPOTIFY: SPOTIFY VOLUME undefined Feb 18 15:22:39 volumio volumio[27128]: SPOTIFY: VOLUMIO VOLUME 100 Feb 18 15:22:39 volumio volumio[27128]: info: Aligning Spotify Volume to Volumio Volume Feb 18 15:22:39 volumio volumio[27128]: info: CoreCommandRouter::volumioGetState Feb 18 15:22:39 volumio volumio[27128]: info: CorePlayQueue::getTrack 0 Feb 18 15:22:39 volumio volumio[27128]: info: Setting Spotify Volume from Volumio: 100 Feb 18 15:22:39 volumio go-librespot[27494]: time="2026-02-18T15:22:39+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:22:39 volumio go-librespot[27494]: time="2026-02-18T15:22:39+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 15:22:39 volumio go-librespot[27494]: time="2026-02-18T15:22:39+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 15:22:39 volumio go-librespot[27494]: time="2026-02-18T15:22:39+07:00" level=info msg="zeroconf server listening on port 44087" Feb 18 15:22:39 volumio go-librespot[27494]: time="2026-02-18T15:22:39+07:00" level=debug msg="obtained new client token: AADiXsFkzSnD/dIW19b/jQoC7SjjXzZEGa6KHfD+mIIg+G1BtsYV1pfDRwKcs+g9OkQJ1f2cZ4fEnJMgPt/nzmhgIdoUrkgZXhOmwTCcZGNmbVVT5ARak3T36HVUn30O1kK4394qWiuijKGlceEagYQ0QYmmR9cvgRooMWvB4c/h5zd5Q7tVbuUE+fZKdiPMJoQ6LIlhQmM9o4/fMYYa4bsZEW5BSP9Xz0EL1vCzjVGNeoTn+uqD0NY9xQ==" Feb 18 15:22:39 volumio go-librespot[27494]: time="2026-02-18T15:22:39+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 18 15:22:39 volumio go-librespot[27494]: time="2026-02-18T15:22:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 18 15:22:40 volumio go-librespot[27494]: time="2026-02-18T15:22:40+07:00" level=debug msg="completed keyexchange" Feb 18 15:22:40 volumio go-librespot[27494]: time="2026-02-18T15:22:40+07:00" level=debug msg="completed challenge" Feb 18 15:22:40 volumio go-librespot[27494]: time="2026-02-18T15:22:40+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 15:22:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:22:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:22:40 volumio volumio[27128]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 15:22:40 volumio volumio[27128]: Error: socket hang up Feb 18 15:22:40 volumio volumio[27128]: at connResetException (node:internal/errors:720:14) Feb 18 15:22:40 volumio volumio[27128]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 18 15:22:40 volumio volumio[27128]: at Socket.emit (node:events:526:35) Feb 18 15:22:40 volumio volumio[27128]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 18 15:22:40 volumio volumio[27128]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 18 15:22:40 volumio volumio[27128]: code: 'ECONNRESET', Feb 18 15:22:40 volumio volumio[27128]: response: undefined Feb 18 15:22:40 volumio volumio[27128]: } Feb 18 15:22:40 volumio volumio[27128]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 15:22:41 volumio sudo[27523]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 15:21' Feb 18 15:22:41 volumio sudo[27523]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:22:41 volumio sudo[27523]: pam_unix(sudo:session): session closed for user root Feb 18 15:22:42 volumio volumio-remote-updater[25144]: [2026-02-18 15:22:42] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 18 15:22:42 volumio volumio-remote-updater[25144]: [2026-02-18 15:22:42] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 18 15:22:42 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:22:42 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 18 15:22:42 volumio systemd[1]: volumio.service: Consumed 55.766s CPU time. Feb 18 15:22:42 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 15:22:42 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 15:22:42 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 22071. Feb 18 15:22:42 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 15:22:42 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 18 15:22:42 volumio systemd[1]: volumio.service: Consumed 55.766s CPU time. Feb 18 15:22:42 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 18 15:22:42 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 15:22:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 18 15:22:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:22:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:22:43 volumio go-librespot[27550]: go-librespot daemon starting... Feb 18 15:22:43 volumio go-librespot[27551]: time="2026-02-18T15:22:43+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:22:43 volumio go-librespot[27551]: time="2026-02-18T15:22:43+07:00" level=debug msg="app state loaded" Feb 18 15:22:43 volumio go-librespot[27551]: time="2026-02-18T15:22:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:22:43 volumio go-librespot[27551]: time="2026-02-18T15:22:43+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:22:43 volumio go-librespot[27551]: time="2026-02-18T15:22:43+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 15:22:43 volumio go-librespot[27551]: time="2026-02-18T15:22:43+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 15:22:43 volumio go-librespot[27551]: time="2026-02-18T15:22:43+07:00" level=info msg="zeroconf server listening on port 32943" Feb 18 15:22:44 volumio go-librespot[27551]: time="2026-02-18T15:22:44+07:00" level=debug msg="obtained new client token: AAAEoJtLdWFJjcgFGm6BsbgZPg2IhGGDLw94nqZoTS4H3J3B2MAoyD4NVwvYwiC6z/hpLjaQALoPux4b6VHN7wSUDLSaDoV2We7JW36Sg5WOcdzViGNW08oEPVBKqXMeUOwpdF0y9DRy+lkNMg4+Oi1wWvQEnMrapcTg6MxNXpyyEaLUABc5zmwyK+2Bn4CDS4UlitNIhzG7gZjjiX15mzB1ZjvjDJyKj+AV5Z4HfjzbECGwYuznNBQ=" Feb 18 15:22:44 volumio go-librespot[27551]: time="2026-02-18T15:22:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:22:44 volumio go-librespot[27551]: time="2026-02-18T15:22:44+07:00" level=debug msg="completed keyexchange" Feb 18 15:22:44 volumio go-librespot[27551]: time="2026-02-18T15:22:44+07:00" level=debug msg="completed challenge" Feb 18 15:22:44 volumio go-librespot[27551]: time="2026-02-18T15:22:44+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 15:22:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:22:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:22:45 volumio volumio[27535]: info: ------------------------------------------- Feb 18 15:22:45 volumio volumio[27535]: info: ----- Volumio3 ---- Feb 18 15:22:45 volumio volumio[27535]: info: ------------------------------------------- Feb 18 15:22:45 volumio volumio[27535]: info: ----- System startup ---- Feb 18 15:22:45 volumio volumio[27535]: info: ------------------------------------------- Feb 18 15:22:47 volumio volumio-remote-updater[25144]: [2026-02-18 15:22:47] [connect] Successful connection Feb 18 15:22:47 volumio volumio[27535]: info: MYVOLUMIO Environment detected Feb 18 15:22:47 volumio volumio[27535]: info: Plugin folders cleanup Feb 18 15:22:47 volumio volumio[27535]: info: Scanning into folder /volumio/app/plugins/ Feb 18 15:22:47 volumio volumio[27535]: info: Scanning category audio_interface Feb 18 15:22:47 volumio volumio[27535]: info: Scanning category miscellanea Feb 18 15:22:47 volumio volumio[27535]: info: Scanning category music_service Feb 18 15:22:47 volumio volumio[27535]: info: Scanning category plugins.json Feb 18 15:22:47 volumio volumio[27535]: info: Scanning category system_controller Feb 18 15:22:47 volumio volumio[27535]: info: Scanning category user_interface Feb 18 15:22:47 volumio volumio[27535]: info: Scanning into folder /data/plugins/ Feb 18 15:22:47 volumio volumio[27535]: info: Scanning category music_service Feb 18 15:22:47 volumio volumio[27535]: info: Plugin folders cleanup completed Feb 18 15:22:47 volumio volumio[27535]: info: ------------------------------------------- Feb 18 15:22:47 volumio volumio[27535]: info: ----- Core plugins startup ---- Feb 18 15:22:47 volumio volumio[27535]: info: ------------------------------------------- Feb 18 15:22:47 volumio volumio[27535]: info: Loading plugins from folder /volumio/app/plugins/ Feb 18 15:22:47 volumio volumio[27535]: info: Adding plugin upnp to MyMusic Plugins Feb 18 15:22:47 volumio volumio[27535]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 18 15:22:47 volumio volumio[27535]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 18 15:22:47 volumio volumio[27535]: info: Loading plugins from folder /data/plugins/ Feb 18 15:22:47 volumio volumio[27535]: info: Loading plugin "system"... Feb 18 15:22:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 18 15:22:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:22:47 volumio volumio[27535]: info: Loading plugin "appearance"... Feb 18 15:22:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:22:47 volumio go-librespot[27568]: go-librespot daemon starting... Feb 18 15:22:47 volumio go-librespot[27572]: time="2026-02-18T15:22:47+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:22:47 volumio go-librespot[27572]: time="2026-02-18T15:22:47+07:00" level=debug msg="app state loaded" Feb 18 15:22:47 volumio go-librespot[27572]: time="2026-02-18T15:22:47+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:22:48 volumio go-librespot[27572]: time="2026-02-18T15:22:48+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:22:48 volumio go-librespot[27572]: time="2026-02-18T15:22:48+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 15:22:48 volumio go-librespot[27572]: time="2026-02-18T15:22:48+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 15:22:48 volumio go-librespot[27572]: time="2026-02-18T15:22:48+07:00" level=info msg="zeroconf server listening on port 39071" Feb 18 15:22:48 volumio go-librespot[27572]: time="2026-02-18T15:22:48+07:00" level=debug msg="obtained new client token: AAC9a59R1rDuwJi2OqqzdjcNUz/h4GT85fdT6LbRqcHN22AbCugtoVrucHGQbVaTkpb4WzlCIcfSKLQ3n842zcZvTMHcEp8XllAhc4/e+dUWPXZFDiEYhLXzAdo0qpymfd7JaMTi56plrT09xLURK+c87AF+kdaxmIVIqPZWdOPfagmdQ+b7eddKoVviLLZ8u/LzWIu/IQnHK0baanYfQb484egPCpxQQP5nc/1Inpw7IQ4HZQbdiuP94w==" Feb 18 15:22:48 volumio go-librespot[27572]: time="2026-02-18T15:22:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:22:48 volumio go-librespot[27572]: time="2026-02-18T15:22:48+07:00" level=debug msg="completed keyexchange" Feb 18 15:22:48 volumio go-librespot[27572]: time="2026-02-18T15:22:48+07:00" level=debug msg="completed challenge" Feb 18 15:22:48 volumio go-librespot[27572]: time="2026-02-18T15:22:48+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 15:22:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:22:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:22:49 volumio volumio[27535]: info: Loading plugin "network"... Feb 18 15:22:49 volumio volumio[27535]: info: Refreshing Cached IP Addresses Feb 18 15:22:49 volumio sudo[27581]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 15:22:49 volumio sudo[27581]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:22:49 volumio sudo[27583]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 15:22:49 volumio volumio[27535]: info: Loading plugin "services"... Feb 18 15:22:49 volumio sudo[27583]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:22:49 volumio sudo[27581]: pam_unix(sudo:session): session closed for user root Feb 18 15:22:49 volumio volumio[27535]: info: Loading plugin "alsa_controller"... Feb 18 15:22:49 volumio sudo[27590]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 18 15:22:49 volumio sudo[27590]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:22:49 volumio sudo[27583]: pam_unix(sudo:session): session closed for user root Feb 18 15:22:49 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 15:22:49 volumio volumio[27535]: info: Loading plugin "wizard"... Feb 18 15:22:49 volumio volumio[27535]: info: Loading plugin "networkfs"... Feb 18 15:22:49 volumio volumio[27535]: info: Starting Udev Watcher for removable devices Feb 18 15:22:49 volumio volumio[27535]: info: Ignoring mount for partition: boot Feb 18 15:22:49 volumio volumio[27535]: info: Ignoring mount for partition: volumio Feb 18 15:22:49 volumio volumio[27535]: info: Ignoring mount for partition: volumio_data Feb 18 15:22:49 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 15:22:49 volumio volumio[27535]: info: Loading plugin "volumio_command_line_client"... Feb 18 15:22:49 volumio volumio[27535]: info: Loading plugin "upnp"... Feb 18 15:22:49 volumio volumio[27535]: info: [1771402969990] Starting Upmpd Daemon Feb 18 15:22:49 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 15:22:49 volumio volumio[27535]: info: Loading plugin "my_music"... Feb 18 15:22:50 volumio volumio[27535]: info: Loading plugin "mpd"... Feb 18 15:22:50 volumio volumio[27535]: info: Loading plugin "upnp_browser"... Feb 18 15:22:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 18 15:22:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:22:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:22:52 volumio go-librespot[27614]: go-librespot daemon starting... Feb 18 15:22:52 volumio go-librespot[27615]: time="2026-02-18T15:22:52+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:22:52 volumio go-librespot[27615]: time="2026-02-18T15:22:52+07:00" level=debug msg="app state loaded" Feb 18 15:22:52 volumio go-librespot[27615]: time="2026-02-18T15:22:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:22:52 volumio sudo[27590]: pam_unix(sudo:session): session closed for user root Feb 18 15:22:52 volumio go-librespot[27615]: time="2026-02-18T15:22:52+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:22:52 volumio go-librespot[27615]: time="2026-02-18T15:22:52+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 15:22:52 volumio go-librespot[27615]: time="2026-02-18T15:22:52+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 15:22:52 volumio go-librespot[27615]: time="2026-02-18T15:22:52+07:00" level=info msg="zeroconf server listening on port 40873" Feb 18 15:22:52 volumio go-librespot[27615]: time="2026-02-18T15:22:52+07:00" level=debug msg="obtained new client token: AAB9NcgXYo20YPsKmsGMavBY0QI+AJwud2kL6nE40Za6VdyChL/vv5Aaj9AbJzr3gbgH/j7mGOP76nc1MT6ZkiGuj98kwA4e+TY5GeJGaRlkpS8YHHaGQniG1HjHTEbgVsTWbHGfkHME/pUBkct4NJBL3xjsoZzPa18O1c1vc1ZK4SFNrW5/hvUSXVAEGDCU/J4airr1l1Y9v8nSnnmmxhar4ABFReURHBbhPPbIXtgWj2ZDLV4xA9BIqg==" Feb 18 15:22:53 volumio go-librespot[27615]: time="2026-02-18T15:22:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:22:53 volumio go-librespot[27615]: time="2026-02-18T15:22:53+07:00" level=debug msg="completed keyexchange" Feb 18 15:22:53 volumio go-librespot[27615]: time="2026-02-18T15:22:53+07:00" level=debug msg="completed challenge" Feb 18 15:22:53 volumio go-librespot[27615]: time="2026-02-18T15:22:53+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 15:22:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:22:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:22:53 volumio volumio[27535]: info: Starting UPNP Browser Feb 18 15:22:53 volumio volumio[27535]: info: Loading plugin "alarm-clock"... Feb 18 15:22:53 volumio volumio[27535]: info: Loading plugin "airplay_emulation"... Feb 18 15:22:53 volumio volumio[27535]: info: Starting Shairport Sync Feb 18 15:22:53 volumio volumio[27535]: info: Loading plugin "last_100"... Feb 18 15:22:53 volumio volumio[27535]: info: Loading plugin "webradio"... Feb 18 15:22:54 volumio volumio[27535]: info: Loading plugin "i2s_dacs"... Feb 18 15:22:54 volumio volumio[27535]: info: Loading plugin "volumiodiscovery"... Feb 18 15:22:54 volumio volumio[27535]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 15:22:54 volumio volumio[27535]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 15:22:54 volumio node[27535]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 15:22:54 volumio volumio[27535]: *** WARNING *** For more information see Feb 18 15:22:54 volumio volumio[27535]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 15:22:54 volumio volumio[27535]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 15:22:54 volumio volumio[27535]: *** WARNING *** For more information see Feb 18 15:22:54 volumio node[27535]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 15:22:54 volumio node[27535]: *** WARNING *** For more information see Feb 18 15:22:54 volumio node[27535]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 15:22:54 volumio node[27535]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 15:22:54 volumio node[27535]: *** WARNING *** For more information see Feb 18 15:22:54 volumio volumio[27535]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 18 15:22:54 volumio volumio[27535]: info: Discovery: Started advertising with name: Volumio Feb 18 15:22:54 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 15:22:54 volumio volumio[27535]: info: Loading plugin "spop"... Feb 18 15:22:56 volumio volumio[27535]: info: Loading plugin "ytcr"... Feb 18 15:22:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 18 15:22:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:22:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:22:56 volumio go-librespot[27625]: go-librespot daemon starting... Feb 18 15:22:56 volumio go-librespot[27626]: time="2026-02-18T15:22:56+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:22:56 volumio go-librespot[27626]: time="2026-02-18T15:22:56+07:00" level=debug msg="app state loaded" Feb 18 15:22:56 volumio go-librespot[27626]: time="2026-02-18T15:22:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:22:56 volumio go-librespot[27626]: time="2026-02-18T15:22:56+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:22:56 volumio go-librespot[27626]: time="2026-02-18T15:22:56+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 15:22:56 volumio go-librespot[27626]: time="2026-02-18T15:22:56+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 15:22:56 volumio go-librespot[27626]: time="2026-02-18T15:22:56+07:00" level=info msg="zeroconf server listening on port 35139" Feb 18 15:22:57 volumio go-librespot[27626]: time="2026-02-18T15:22:57+07:00" level=debug msg="obtained new client token: AADmqVRIfSMd46ZCSB6Yw0nk2yw1Q0IRdT5poSf6Mr9sGpsh0ow1jRMM4yki+/6cK/7cgq+bUNkEfaPafiYuSweq2q24bb/m0ihoVWmLZe8qcoV+D9HTbRewzqjiFrMqEI8EuT2gR+T9yXtGvsdxFYZSoBOGoOwZCho/yNZlIX+F7d7fqLex1OrHZIt6a/rIzJl8BA9cxSTNGJTcgmYIDhXIq2R7V6p8J9pFgWgpOMDybHD9TgHGvfY=" Feb 18 15:22:57 volumio go-librespot[27626]: time="2026-02-18T15:22:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:22:57 volumio go-librespot[27626]: time="2026-02-18T15:22:57+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 15:22:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:22:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:22:58 volumio volumio[27535]: info: Loading plugin "ytmusic"... Feb 18 15:22:59 volumio volumio-remote-updater[25144]: [2026-02-18 15:22:59] [connect] Successful connection Feb 18 15:22:59 volumio volumio[27535]: info: Loading plugin "outputs"... Feb 18 15:22:59 volumio volumio[27535]: info: Loading plugin "albumart"... Feb 18 15:22:59 volumio volumio[27535]: info: Plugin example_plugin is not enabled Feb 18 15:22:59 volumio volumio[27535]: info: Loading plugin "inputs"... Feb 18 15:22:59 volumio volumio[27535]: info: Loading plugin "updater_comm"... Feb 18 15:23:00 volumio volumio[27535]: info: Plugin mpdemulation is not enabled Feb 18 15:23:00 volumio volumio[27535]: info: Loading plugin "rest_api"... Feb 18 15:23:00 volumio volumio[27535]: info: Loading plugin "websocket"... Feb 18 15:23:00 volumio volumio[27535]: info: Starting Socket.io Server version 1.7.4 Feb 18 15:23:00 volumio volumio[27535]: info: Loading plugin "RoonBridge"... Feb 18 15:23:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 18 15:23:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:23:00 volumio volumio[27535]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 15:23:00 volumio go-librespot[27658]: go-librespot daemon starting... Feb 18 15:23:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:23:00 volumio volumio[27535]: info: Loading i18n strings for locale en Feb 18 15:23:00 volumio go-librespot[27659]: time="2026-02-18T15:23:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:23:00 volumio go-librespot[27659]: time="2026-02-18T15:23:00+07:00" level=debug msg="app state loaded" Feb 18 15:23:00 volumio go-librespot[27659]: time="2026-02-18T15:23:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:23:00 volumio volumio[27535]: Updating browse sources language Feb 18 15:23:00 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:23:00 volumio volumio[27648]: Forking 3 albumart workers Feb 18 15:23:00 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 15:23:00 volumio volumio[27535]: info: CoreCommandRouter::initPlayerControls Feb 18 15:23:00 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:23:00 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:23:00 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:23:00 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:23:00 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:23:00 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:23:00 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:23:01 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:23:01 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 15:23:01 volumio volumio[27535]: Express server listening on port 3000 Feb 18 15:23:01 volumio volumio[27535]: [Metrics] WebUI: 16s 55.72ms Feb 18 15:23:01 volumio volumio[27535]: info: CoreStateMachine::resetVolumioState Feb 18 15:23:01 volumio volumio[27535]: info: CoreStateMachine::getcurrentVolume Feb 18 15:23:01 volumio volumio[27535]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 15:23:01 volumio go-librespot[27659]: time="2026-02-18T15:23:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:23:01 volumio go-librespot[27659]: time="2026-02-18T15:23:01+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 15:23:01 volumio go-librespot[27659]: time="2026-02-18T15:23:01+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 15:23:01 volumio sudo[27700]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 15:23:01 volumio sudo[27700]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:23:01 volumio sudo[27700]: pam_unix(sudo:session): session closed for user root Feb 18 15:23:01 volumio go-librespot[27659]: time="2026-02-18T15:23:01+07:00" level=info msg="zeroconf server listening on port 36901" Feb 18 15:23:01 volumio sudo[27702]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 15:23:01 volumio sudo[27702]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:23:01 volumio sudo[27702]: pam_unix(sudo:session): session closed for user root Feb 18 15:23:01 volumio volumio[27535]: info: Volumio Network Manager: Network status updated: 1 Feb 18 15:23:01 volumio go-librespot[27659]: time="2026-02-18T15:23:01+07:00" level=debug msg="obtained new client token: AADeyQ+BnP0FC4f0d3zQGOs9qQ6g4S55h31zuA96D9JkYxrkWZrfNJqkree49BheEzJycTPuAV/Y+1gKKEDEomlGQvy3Fas1IZjyLKwtkwITbV8BFRLwCbAn3KWQn0T6cw3mhS1HGITB+MMN66x5S6SgARWhzDKu+OmhzthGQ7Ahmo3MRKBdJJQ1tA4q4T4wW8s/QeFsShFcfa8xZOPawiFnnvl73QwLdd6072UO6gBr55BftJGFzdDmIQ==" Feb 18 15:23:01 volumio go-librespot[27659]: time="2026-02-18T15:23:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:23:01 volumio volumio[27535]: info: VolumeController:: Volume=100 Mute =false Feb 18 15:23:01 volumio volumio[27535]: info: CoreStateMachine::pushState Feb 18 15:23:01 volumio go-librespot[27659]: time="2026-02-18T15:23:01+07:00" level=debug msg="completed keyexchange" Feb 18 15:23:01 volumio go-librespot[27659]: time="2026-02-18T15:23:01+07:00" level=debug msg="completed challenge" Feb 18 15:23:01 volumio volumio[27535]: info: CorePlayQueue::getTrack 0 Feb 18 15:23:01 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 15:23:01 volumio volumio[27535]: info: CoreCommandRouter::volumioPushState Feb 18 15:23:01 volumio volumio[27535]: info: CoreStateMachine::updateTrackBlock Feb 18 15:23:01 volumio volumio[27535]: info: CorePlayQueue::getTrackBlock Feb 18 15:23:01 volumio volumio[27535]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 15:23:01 volumio go-librespot[27659]: time="2026-02-18T15:23:01+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 15:23:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:23:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:23:01 volumio volumio-remote-updater[25144]: [2026-02-18 15:23:01] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771402979 101 Feb 18 15:23:01 volumio volumio[27535]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 18 15:23:01 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:23:01 volumio volumio[27535]: info: Reloading queue from file Feb 18 15:23:01 volumio volumio[27535]: info: CoreStateMachine::setRepeat null single undefined Feb 18 15:23:01 volumio volumio[27535]: info: CoreStateMachine::pushState Feb 18 15:23:01 volumio volumio[27535]: info: CorePlayQueue::getTrack 0 Feb 18 15:23:02 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 15:23:02 volumio volumio[27535]: info: CoreCommandRouter::volumioPushState Feb 18 15:23:02 volumio volumio[27535]: info: CoreStateMachine::setRandom null Feb 18 15:23:02 volumio volumio[27535]: info: CoreStateMachine::pushState Feb 18 15:23:02 volumio volumio[27535]: info: CorePlayQueue::getTrack 0 Feb 18 15:23:02 volumio volumio[27535]: info: CoreCommandRouter::volumioPushState Feb 18 15:23:02 volumio volumio[27535]: info: Setting Device type: Raspberry PI Feb 18 15:23:02 volumio volumio[27535]: info: Completed loading Core Plugins Feb 18 15:23:02 volumio volumio[27535]: info: Preparing to generate the ALSA configuration file Feb 18 15:23:02 volumio volumio[27535]: info: VolumeController:: Volume=100 Mute =false Feb 18 15:23:02 volumio volumio[27535]: info: CoreStateMachine::pushState Feb 18 15:23:02 volumio volumio[27535]: info: CorePlayQueue::getTrack 0 Feb 18 15:23:02 volumio volumio[27535]: info: CoreCommandRouter::volumioPushState Feb 18 15:23:02 volumio volumio[27535]: info: Asound.conf file unchanged, so no further update is needed Feb 18 15:23:02 volumio volumio[27535]: info: Output device has changed, restarting MPD Feb 18 15:23:02 volumio volumio[27535]: info: Output device has changed, restarting Shairport Sync Feb 18 15:23:02 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:23:02 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:23:02 volumio sudo[27719]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 15:23:02 volumio sudo[27719]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:23:02 volumio sudo[27721]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 15:23:02 volumio sudo[27721]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:23:02 volumio sudo[27721]: pam_unix(sudo:session): session closed for user root Feb 18 15:23:02 volumio sudo[27723]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 15:23:02 volumio sudo[27723]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:23:02 volumio volumio[27535]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 15:23:02 volumio volumio[27535]: info: ___________ START PLUGINS ___________ Feb 18 15:23:02 volumio volumio[27535]: info: ControllerMpd::onStart: Initializing MPD Feb 18 15:23:02 volumio volumio[27535]: info: Creating MPD Configuration file Feb 18 15:23:02 volumio sudo[27719]: pam_unix(sudo:session): session closed for user root Feb 18 15:23:02 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 15:23:02 volumio volumio[27535]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:23:02 volumio volumio[27535]: info: [1771402982573] CoreMusicLibrary::Adding element Media Servers Feb 18 15:23:02 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:23:02 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 15:23:02 volumio sudo[27732]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 15:23:02 volumio sudo[27732]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:23:02 volumio volumio[27535]: info: UPNP Browser: Client initialized successfully Feb 18 15:23:02 volumio sudo[27732]: pam_unix(sudo:session): session closed for user root Feb 18 15:23:02 volumio sudo[27734]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 15:23:02 volumio sudo[27734]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:23:02 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 15:23:02 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 15:23:02 volumio systemd[1]: mpd.service: Consumed 7.031s CPU time. Feb 18 15:23:02 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 15:23:02 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 15:23:02 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 15:23:02 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:23:02 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:23:02 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 15:23:02 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 15:23:02 volumio volumio[27535]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 15:23:02 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:23:02 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:23:02 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 15:23:02 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 15:23:02 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 15:23:02 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 15:23:02 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 15:23:02 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 15:23:02 volumio volumio[27535]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 15:23:02 volumio volumio[27535]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:23:02 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 15:23:02 volumio volumio[27535]: info: [1771402982973] CoreMusicLibrary::Adding element Last_100 Feb 18 15:23:02 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:23:02 volumio volumio[27535]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:23:02 volumio volumio[27535]: info: [1771402982993] CoreMusicLibrary::Adding element Webradio Feb 18 15:23:02 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:23:03 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 15:23:03 volumio volumio[27535]: info: Initializing BBC Radios Feb 18 15:23:03 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 15:23:03 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:23:03 volumio volumio[27535]: info: Creating Spotify config file Feb 18 15:23:03 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:23:03 volumio sudo[27748]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 15:23:03 volumio sudo[27748]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 15:23:03 volumio sudo[27748]: pam_unix(sudo:session): session closed for user root Feb 18 15:23:04 volumio volumio[27535]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:23:04 volumio volumio[27535]: info: [1771402984335] CoreMusicLibrary::Adding element YouTube Music Feb 18 15:23:04 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:23:04 volumio volumio[27535]: Cannot find translation for source YouTube Music Feb 18 15:23:04 volumio volumio[27667]: Starting albumart workers Feb 18 15:23:04 volumio volumio[27535]: info: Volumio Calling Home Feb 18 15:23:04 volumio volumio[27666]: Starting albumart workers Feb 18 15:23:04 volumio volumio[27668]: Starting albumart workers Feb 18 15:23:04 volumio sudo[27765]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 15:23:04 volumio sudo[27765]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:23:04 volumio sudo[27765]: pam_unix(sudo:session): session closed for user root Feb 18 15:23:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 18 15:23:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:23:05 volumio volumio[27535]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 15:23:05 volumio volumio[27535]: info: Discovery: Found device Volumio Feb 18 15:23:05 volumio volumio[27535]: info: CoreCommandRouter::volumioGetState Feb 18 15:23:05 volumio volumio[27535]: info: CorePlayQueue::getTrack 0 Feb 18 15:23:05 volumio volumio[27535]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 15:23:05 volumio volumio[27535]: info: Discovery: Found device Volumio Feb 18 15:23:05 volumio volumio[27535]: info: CoreCommandRouter::volumioGetState Feb 18 15:23:05 volumio volumio[27535]: info: CorePlayQueue::getTrack 0 Feb 18 15:23:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:23:05 volumio go-librespot[27770]: go-librespot daemon starting... Feb 18 15:23:05 volumio go-librespot[27771]: time="2026-02-18T15:23:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:23:05 volumio go-librespot[27771]: time="2026-02-18T15:23:05+07:00" level=debug msg="app state loaded" Feb 18 15:23:05 volumio go-librespot[27771]: time="2026-02-18T15:23:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:23:05 volumio volumio[27535]: info: MPD Permissions set Feb 18 15:23:05 volumio volumio[27535]: info: MPD Permissions set Feb 18 15:23:05 volumio volumio[27535]: info: Upmpdcli Daemon Started Feb 18 15:23:05 volumio volumio[27535]: info: Spotify config file written Feb 18 15:23:05 volumio sudo[27778]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 15:23:05 volumio sudo[27778]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:23:05 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 18 15:23:05 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 18 15:23:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:23:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:23:05 volumio go-librespot[27781]: go-librespot daemon starting... Feb 18 15:23:05 volumio sudo[27778]: pam_unix(sudo:session): session closed for user root Feb 18 15:23:06 volumio go-librespot[27782]: time="2026-02-18T15:23:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:23:06 volumio go-librespot[27782]: time="2026-02-18T15:23:06+07:00" level=debug msg="app state loaded" Feb 18 15:23:06 volumio go-librespot[27782]: time="2026-02-18T15:23:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:23:06 volumio volumio[27535]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 18 15:23:06 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:23:06 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:23:06 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:23:06 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:23:06 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:23:06 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:23:06 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:23:06 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:23:06 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:23:06 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:23:06 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:23:06 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:23:06 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:23:06 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:23:06 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:23:06 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:23:06 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:23:06 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:23:06 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:23:06 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:23:06 volumio volumio[27535]: info: No need to fix Spotify hosts Feb 18 15:23:06 volumio go-librespot[27782]: time="2026-02-18T15:23:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 15:23:06 volumio go-librespot[27782]: time="2026-02-18T15:23:06+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 15:23:06 volumio go-librespot[27782]: time="2026-02-18T15:23:06+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 15:23:06 volumio go-librespot[27782]: time="2026-02-18T15:23:06+07:00" level=info msg="zeroconf server listening on port 39613" Feb 18 15:23:07 volumio go-librespot[27782]: time="2026-02-18T15:23:07+07:00" level=debug msg="obtained new client token: AACE3NRSBsdfAPcBglZkxM0jxdKDRsgtdC4kecGjkULxMtpVPGdFNIgzgqMF+Qm8w4YbnSF0RK4MMFHrnoQRR5omH7Aj3QP5byfFKdxAWjSpaCgnWiYEWoaei+sDOFzpKlQUxDIlojD5LbQHVgtXAFe3x1STmqN9A68bIwvm23pYH5r7TeukqmVOTzbwv1XoERLdiHRkGy0XO8LevVGoJZqMvsYtUkZouLkKTh856XSCkigcaMTceMY=" Feb 18 15:23:07 volumio go-librespot[27782]: time="2026-02-18T15:23:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:23:07 volumio go-librespot[27782]: time="2026-02-18T15:23:07+07:00" level=debug msg="completed keyexchange" Feb 18 15:23:07 volumio go-librespot[27782]: time="2026-02-18T15:23:07+07:00" level=debug msg="completed challenge" Feb 18 15:23:07 volumio volumio[27535]: info: Volumio called home Feb 18 15:23:07 volumio go-librespot[27782]: time="2026-02-18T15:23:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 15:23:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:23:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:23:07 volumio volumio[27535]: info: Starting Shairport Sync Feb 18 15:23:07 volumio volumio[27535]: info: Starting Shairport Sync Feb 18 15:23:07 volumio volumio[27535]: info: Starting Shairport Sync Feb 18 15:23:07 volumio sudo[27819]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 15:23:07 volumio sudo[27819]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:23:07 volumio sudo[27821]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 15:23:07 volumio sudo[27821]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:23:07 volumio sudo[27823]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 15:23:07 volumio sudo[27823]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:23:07 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 15:23:07 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 15:23:07 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 15:23:07 volumio systemd[1]: shairport-sync.service: Consumed 2.305s CPU time. Feb 18 15:23:07 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 15:23:07 volumio sudo[27819]: pam_unix(sudo:session): session closed for user root Feb 18 15:23:07 volumio volumio[27535]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 15:23:07 volumio volumio[27535]: SPOTIFY: BQBNEbSbCCVR66OErGCH16BNyfMpcB3fJf-NCkyOc3zN9mpILmOWNKNlqTDDUB4l2OzDsBSyp4OB7RE6or-UdBk1-DUE8RwLZr9y9-U9P3ohvWW2E5w-36QCtb8apo45Z3NEKKCFezjHz-EgHXuMr0ky08FE6mI_4Q9gtD5Zigrw6AoFktaQljShZHcXPEZk6qHIwzZe3ggOlXwXTHQHgUSeE3meWmtBhwY1k0K1Nn3DPSi5PmUZNtRmDBl-A9mmDleFvAhLxPzGdRVzjJLC8BXuXDu8J4n9XeenF0mWGR5PsOciYL-DXv5o Feb 18 15:23:07 volumio volumio[27535]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 15:23:07 volumio sudo[27821]: pam_unix(sudo:session): session closed for user root Feb 18 15:23:07 volumio volumio[27535]: info: New Spotify access token = BQBNEbSbCCVR66OErGCH16BNyfMpcB3fJf-NCkyOc3zN9mpILmOWNKNlqTDDUB4l2OzDsBSyp4OB7RE6or-UdBk1-DUE8RwLZr9y9-U9P3ohvWW2E5w-36QCtb8apo45Z3NEKKCFezjHz-EgHXuMr0ky08FE6mI_4Q9gtD5Zigrw6AoFktaQljShZHcXPEZk6qHIwzZe3ggOlXwXTHQHgUSeE3meWmtBhwY1k0K1Nn3DPSi5PmUZNtRmDBl-A9mmDleFvAhLxPzGdRVzjJLC8BXuXDu8J4n9XeenF0mWGR5PsOciYL-DXv5o Feb 18 15:23:07 volumio volumio[27535]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 15:23:07 volumio sudo[27823]: pam_unix(sudo:session): session closed for user root Feb 18 15:23:08 volumio volumio[27535]: info: Shairport-Sync Started Feb 18 15:23:08 volumio volumio[27535]: Error adding Membership: Error: addMembership EINVAL Feb 18 15:23:08 volumio volumio[27535]: info: Shairport-Sync Started Feb 18 15:23:08 volumio volumio[27535]: info: Shairport-Sync Started Feb 18 15:23:08 volumio volumio[27535]: info: CoreCommandRouter::volumioGetState Feb 18 15:23:08 volumio volumio[27535]: info: CorePlayQueue::getTrack 0 Feb 18 15:23:08 volumio volumio[27535]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 18 15:23:08 volumio volumio[27535]: info: Spotify Successfully logged in Feb 18 15:23:08 volumio volumio[27535]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:23:08 volumio volumio[27535]: info: [1771402988394] CoreMusicLibrary::Adding element Spotify Feb 18 15:23:08 volumio volumio[27535]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:23:08 volumio volumio[27535]: Cannot find translation for source YouTube Music Feb 18 15:23:08 volumio volumio[27535]: Cannot find translation for source Spotify Feb 18 15:23:08 volumio volumio[27535]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 15:23:08 volumio volumio[27535]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 15:23:09 volumio volumio[27535]: info: VolumeController:: Volume=100 Mute =false Feb 18 15:23:09 volumio volumio[27535]: info: CoreCommandRouter::volumioGetState Feb 18 15:23:09 volumio volumio[27535]: info: CorePlayQueue::getTrack 0 Feb 18 15:23:09 volumio volumio[27535]: info: CoreStateMachine::pushState Feb 18 15:23:09 volumio volumio[27535]: info: CorePlayQueue::getTrack 0 Feb 18 15:23:09 volumio volumio[27535]: info: CoreCommandRouter::volumioPushState Feb 18 15:23:10 volumio volumio[27535]: info: go-librespot daemon successfully initialized Feb 18 15:23:10 volumio mpd[27763]: 2026-02-18T15:23:10 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 15:23:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 18 15:23:10 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 15:23:10 volumio sudo[27734]: pam_unix(sudo:session): session closed for user root Feb 18 15:23:10 volumio sudo[27723]: pam_unix(sudo:session): session closed for user root Feb 18 15:23:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:23:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:23:10 volumio go-librespot[27861]: go-librespot daemon starting... Feb 18 15:23:10 volumio go-librespot[27864]: time="2026-02-18T15:23:10+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:23:10 volumio go-librespot[27864]: time="2026-02-18T15:23:10+07:00" level=debug msg="app state loaded" Feb 18 15:23:10 volumio go-librespot[27864]: time="2026-02-18T15:23:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:23:10 volumio volumio[27535]: error: MPD error: The expression evaluated to a falsy value: Feb 18 15:23:10 volumio volumio[27535]: assert.ok(self.idling) Feb 18 15:23:10 volumio volumio[27535]: error: The expression evaluated to a falsy value: Feb 18 15:23:10 volumio volumio[27535]: assert.ok(self.idling) Feb 18 15:23:10 volumio volumio[27535]: error: updateQueue error: null Feb 18 15:23:10 volumio volumio[27535]: info: MPD running with PID27763 Feb 18 15:23:10 volumio volumio[27535]: ,establishing connection Feb 18 15:23:10 volumio volumio[27535]: info: Completed starting Core Plugins Feb 18 15:23:10 volumio volumio[27535]: info: ------------------------------------------- Feb 18 15:23:10 volumio volumio[27535]: info: ----- MyVolumio plugins startup ---- Feb 18 15:23:10 volumio volumio[27535]: info: ------------------------------------------- Feb 18 15:23:10 volumio volumio[27535]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 15:23:10 volumio volumio[27535]: error: updateQueue error: null Feb 18 15:23:11 volumio go-librespot[27864]: time="2026-02-18T15:23:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:23:11 volumio go-librespot[27864]: time="2026-02-18T15:23:11+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 15:23:11 volumio go-librespot[27864]: time="2026-02-18T15:23:11+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 15:23:11 volumio go-librespot[27864]: time="2026-02-18T15:23:11+07:00" level=info msg="zeroconf server listening on port 42259" Feb 18 15:23:11 volumio go-librespot[27864]: time="2026-02-18T15:23:11+07:00" level=debug msg="obtained new client token: AAD8fMAzB2w1XhToT7Yry6jlQnNdyGOTqjvo+n4mBHXoQHH9bbyp1dg1lgVtP7R+kFWyAMxgg9QFZae5sBGbrhGUvrmqsMSV9gExwxPGfVA+7LWJzBgdq9FalZwwNILO+kTIGa06mlmC/nez44S8bwjksd/XKLWm6mFGvmkSUC48ACO7SOtXkj6jZeh9VFb5mnzS/SdryOuBnIynTpRqxyRMjfXqOOEP9qlkEUx1gEvppVJOPqcVfo3epA==" Feb 18 15:23:11 volumio go-librespot[27864]: time="2026-02-18T15:23:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:23:12 volumio go-librespot[27864]: time="2026-02-18T15:23:12+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.23:56520->104.199.241.202:4070: read: connection reset by peer" Feb 18 15:23:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:23:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:23:13 volumio volumio[27535]: info: Initializing connection to go-librespot Websocket Feb 18 15:23:13 volumio volumio[27535]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 15:23:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 18 15:23:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:23:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:23:15 volumio go-librespot[27874]: go-librespot daemon starting... Feb 18 15:23:15 volumio go-librespot[27875]: time="2026-02-18T15:23:15+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:23:15 volumio go-librespot[27875]: time="2026-02-18T15:23:15+07:00" level=debug msg="app state loaded" Feb 18 15:23:15 volumio go-librespot[27875]: time="2026-02-18T15:23:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:23:15 volumio volumio[27535]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 15:23:16 volumio go-librespot[27875]: time="2026-02-18T15:23:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:23:16 volumio go-librespot[27875]: time="2026-02-18T15:23:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 15:23:16 volumio go-librespot[27875]: time="2026-02-18T15:23:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 15:23:16 volumio go-librespot[27875]: time="2026-02-18T15:23:16+07:00" level=info msg="zeroconf server listening on port 43451" Feb 18 15:23:16 volumio go-librespot[27875]: time="2026-02-18T15:23:16+07:00" level=debug msg="obtained new client token: AAB0iDRZMIJoil5NyJ8SdoZ8aGGnNiPc3zi9CEcOpxUhgToLTdFSOUpRBCXIbD+eVaQ/Qs+4ZPeXPWYZcLC99DfbjsmGfnLHOP/5UidtyRJXg0rk9o/bzELEWOTZNCRJq2fyvmJwLCz1ioQg3s8ApnLoGJmwJxG+YfLbQTpO1k7sy0u/4SLt5d1X4kMm681hJXyWK4l9x0wvhlThQKthEc7T3tkMpe2OpAojhEqTT1OjLW+MtpBvczk=" Feb 18 15:23:16 volumio go-librespot[27875]: time="2026-02-18T15:23:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:23:16 volumio volumio[27535]: info: Initializing connection to go-librespot Websocket Feb 18 15:23:16 volumio go-librespot[27875]: time="2026-02-18T15:23:16+07:00" level=debug msg="new websocket client" Feb 18 15:23:16 volumio volumio[27535]: info: Connection to go-librespot Websocket established Feb 18 15:23:16 volumio go-librespot[27875]: time="2026-02-18T15:23:16+07:00" level=debug msg="completed keyexchange" Feb 18 15:23:16 volumio go-librespot[27875]: time="2026-02-18T15:23:16+07:00" level=debug msg="completed challenge" Feb 18 15:23:16 volumio go-librespot[27875]: time="2026-02-18T15:23:16+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 15:23:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:23:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:23:16 volumio volumio[27535]: info: Connection to go-librespot Websocket closed Feb 18 15:23:19 volumio volumio[27535]: info: Getting Spotify volume Feb 18 15:23:19 volumio volumio[27535]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 15:23:19 volumio volumio[27535]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 15:23:19 volumio volumio[27535]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 18 15:23:19 volumio volumio[27535]: errno: -111, Feb 18 15:23:19 volumio volumio[27535]: code: 'ECONNREFUSED', Feb 18 15:23:19 volumio volumio[27535]: syscall: 'connect', Feb 18 15:23:19 volumio volumio[27535]: address: '127.0.0.1', Feb 18 15:23:19 volumio volumio[27535]: port: 9879, Feb 18 15:23:19 volumio volumio[27535]: response: undefined Feb 18 15:23:19 volumio volumio[27535]: } Feb 18 15:23:19 volumio volumio[27535]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 15:23:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 18 15:23:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:23:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:23:19 volumio go-librespot[27893]: go-librespot daemon starting... Feb 18 15:23:19 volumio go-librespot[27894]: time="2026-02-18T15:23:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:23:19 volumio go-librespot[27894]: time="2026-02-18T15:23:19+07:00" level=debug msg="app state loaded" Feb 18 15:23:19 volumio go-librespot[27894]: time="2026-02-18T15:23:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:23:20 volumio go-librespot[27894]: time="2026-02-18T15:23:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:23:20 volumio go-librespot[27894]: time="2026-02-18T15:23:20+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 15:23:20 volumio go-librespot[27894]: time="2026-02-18T15:23:20+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 15:23:20 volumio go-librespot[27894]: time="2026-02-18T15:23:20+07:00" level=info msg="zeroconf server listening on port 40317" Feb 18 15:23:20 volumio go-librespot[27894]: time="2026-02-18T15:23:20+07:00" level=debug msg="obtained new client token: AABdOrFv+CrfLZ8GzzLDGNAyKiJukRMSP7UeJ3J0SkNdTQJD3n6ZYaloTyzh0gvFiTbpJ/vbTkkJNsyloZ8rTT9TfyChviy5GTy5wghsgypHjYEg0EYTwyOkWfUkJb7DwjTs5cGhFnmyPWqbniRT+LI1RURRzJaS8FEI70dKS1HYQmtU8z7GB6HQh2o+2bJaGaaW/gm5Pvtw0GNDLNSk5msplBjtxXMsuheN2R+UbVDg+5mzoz7jSSSJWA==" Feb 18 15:23:20 volumio go-librespot[27894]: time="2026-02-18T15:23:20+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 18 15:23:20 volumio go-librespot[27894]: time="2026-02-18T15:23:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 18 15:23:20 volumio go-librespot[27894]: time="2026-02-18T15:23:20+07:00" level=debug msg="completed keyexchange" Feb 18 15:23:20 volumio go-librespot[27894]: time="2026-02-18T15:23:20+07:00" level=debug msg="completed challenge" Feb 18 15:23:20 volumio go-librespot[27894]: time="2026-02-18T15:23: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 18 15:23:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:23:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:23:21 volumio sudo[27918]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 15:22' Feb 18 15:23:21 volumio sudo[27918]: 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"