Feb 11 16:53:00 volumio volumio[13269]: info: Loading plugin "network"... Feb 11 16:53:00 volumio volumio[13269]: info: Refreshing Cached IP Addresses Feb 11 16:53:00 volumio sudo[13310]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 16:53:00 volumio sudo[13310]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:53:00 volumio sudo[13310]: pam_unix(sudo:session): session closed for user root Feb 11 16:53:00 volumio sudo[13312]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 16:53:01 volumio sudo[13312]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:53:01 volumio volumio[13269]: info: Loading plugin "services"... Feb 11 16:53:01 volumio sudo[13312]: pam_unix(sudo:session): session closed for user root Feb 11 16:53:01 volumio volumio[13269]: info: Loading plugin "alsa_controller"... Feb 11 16:53:01 volumio sudo[13320]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 11 16:53:01 volumio sudo[13320]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:53:01 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 16:53:01 volumio volumio[13269]: info: Loading plugin "wizard"... Feb 11 16:53:01 volumio volumio[13269]: info: Loading plugin "networkfs"... Feb 11 16:53:01 volumio volumio[13269]: info: Starting Udev Watcher for removable devices Feb 11 16:53:01 volumio volumio[13269]: info: Ignoring mount for partition: boot Feb 11 16:53:01 volumio volumio[13269]: info: Ignoring mount for partition: volumio Feb 11 16:53:01 volumio volumio[13269]: info: Ignoring mount for partition: volumio_data Feb 11 16:53:01 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 16:53:01 volumio volumio[13269]: info: Loading plugin "volumio_command_line_client"... Feb 11 16:53:01 volumio volumio[13269]: info: Loading plugin "upnp"... Feb 11 16:53:01 volumio volumio[13269]: info: [1770803581318] Starting Upmpd Daemon Feb 11 16:53:01 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 16:53:01 volumio volumio[13269]: info: Loading plugin "my_music"... Feb 11 16:53:01 volumio volumio[13269]: info: Loading plugin "mpd"... Feb 11 16:53:01 volumio volumio[13269]: info: Loading plugin "upnp_browser"... Feb 11 16:53:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 11 16:53:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:53:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:53:02 volumio go-librespot[13343]: go-librespot daemon starting... Feb 11 16:53:02 volumio go-librespot[13344]: time="2026-02-11T16:53:02+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 16:53:02 volumio go-librespot[13344]: time="2026-02-11T16:53:02+07:00" level=debug msg="app state loaded" Feb 11 16:53:02 volumio go-librespot[13344]: time="2026-02-11T16:53:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 16:53:02 volumio go-librespot[13344]: time="2026-02-11T16:53: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 16:53:02 volumio go-librespot[13344]: time="2026-02-11T16:53:02+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 16:53:02 volumio go-librespot[13344]: time="2026-02-11T16:53:02+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 16:53:02 volumio go-librespot[13344]: time="2026-02-11T16:53:02+07:00" level=info msg="zeroconf server listening on port 43007" Feb 11 16:53:02 volumio go-librespot[13344]: time="2026-02-11T16:53:02+07:00" level=debug msg="obtained new client token: AAAEwUFu6pQz5Cjtft4XMQUVgX04XbsqjsqFdoOiwwxMI2W7aR/Q5mbthBoKypCLY8ghsexOSxvb146oOVWO9ll71svUN/uE7SR/A06KyQI38xzOmbhfbDstEiQPf2Rwiiqk3wuFQ/YbnoOwJb5uv42lrX5BKXof/tyibmdUnmUk4Y9qM0ez7a3/tD/XpkwMvIGVyAABhqNiV6I6eNDivzeXBQnqWbAhr2KpwReDkTJDGO6D1Y6BCksv/g==" Feb 11 16:53:03 volumio go-librespot[13344]: time="2026-02-11T16:53:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 16:53:03 volumio go-librespot[13344]: time="2026-02-11T16:53:03+07:00" level=debug msg="completed keyexchange" Feb 11 16:53:03 volumio go-librespot[13344]: time="2026-02-11T16:53:03+07:00" level=debug msg="completed challenge" Feb 11 16:53:03 volumio go-librespot[13344]: time="2026-02-11T16:53: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 11 16:53:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 16:53:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 16:53:03 volumio sudo[13320]: pam_unix(sudo:session): session closed for user root Feb 11 16:53:04 volumio volumio[13269]: info: Starting UPNP Browser Feb 11 16:53:04 volumio volumio[13269]: info: Loading plugin "alarm-clock"... Feb 11 16:53:05 volumio volumio[13269]: info: Loading plugin "airplay_emulation"... Feb 11 16:53:05 volumio volumio[13269]: info: Starting Shairport Sync Feb 11 16:53:05 volumio volumio[13269]: info: Loading plugin "last_100"... Feb 11 16:53:05 volumio volumio[13269]: info: Loading plugin "webradio"... Feb 11 16:53:05 volumio volumio[13269]: info: Loading plugin "i2s_dacs"... Feb 11 16:53:05 volumio volumio[13269]: info: Loading plugin "volumiodiscovery"... Feb 11 16:53:05 volumio volumio[13269]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 11 16:53:05 volumio volumio[13269]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 16:53:05 volumio volumio[13269]: *** WARNING *** For more information see Feb 11 16:53:05 volumio volumio[13269]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 11 16:53:05 volumio volumio[13269]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 16:53:05 volumio volumio[13269]: *** WARNING *** For more information see Feb 11 16:53:05 volumio node[13269]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 11 16:53:05 volumio node[13269]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 16:53:05 volumio node[13269]: *** WARNING *** For more information see Feb 11 16:53:05 volumio node[13269]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 11 16:53:05 volumio node[13269]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 16:53:05 volumio node[13269]: *** WARNING *** For more information see Feb 11 16:53:05 volumio volumio[13269]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 11 16:53:05 volumio volumio[13269]: info: Discovery: Started advertising with name: Volumio Feb 11 16:53:05 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 16:53:05 volumio volumio[13269]: info: Loading plugin "spop"... Feb 11 16:53:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Feb 11 16:53:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:53:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:53:06 volumio go-librespot[13353]: go-librespot daemon starting... Feb 11 16:53:06 volumio go-librespot[13354]: time="2026-02-11T16:53:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 16:53:06 volumio go-librespot[13354]: time="2026-02-11T16:53:06+07:00" level=debug msg="app state loaded" Feb 11 16:53:06 volumio go-librespot[13354]: time="2026-02-11T16:53:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 16:53:06 volumio go-librespot[13354]: time="2026-02-11T16:53: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 11 16:53:06 volumio go-librespot[13354]: time="2026-02-11T16:53: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 11 16:53:06 volumio go-librespot[13354]: time="2026-02-11T16:53: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 11 16:53:06 volumio go-librespot[13354]: time="2026-02-11T16:53:06+07:00" level=info msg="zeroconf server listening on port 45149" Feb 11 16:53:07 volumio go-librespot[13354]: time="2026-02-11T16:53:07+07:00" level=debug msg="obtained new client token: AAC0to0tNsRC8HmbsHswCk9WJZdETrKWiKnbPIW6PLIE/h3VbfxvsJkJIGmxGRif9/6SFAXyt7z+JMSSj8PW12tR8dQbuxqIEeLikd1OJezP7f0dXoI2q+K3/FfBrFJ1/3d8gN6TRJH8oXkQGNGMuJMHXu+pJaXjoqdZzYDCFDjwIHDO/txf0pkCTTXbnub1F+qAeaUVSv3L6GLqqWgj53FEzEA7lbcgzBMkEKIGTGv0gwY3v+QPk5U=" Feb 11 16:53:07 volumio go-librespot[13354]: time="2026-02-11T16:53:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 16:53:07 volumio go-librespot[13354]: time="2026-02-11T16:53:07+07:00" level=debug msg="completed keyexchange" Feb 11 16:53:07 volumio go-librespot[13354]: time="2026-02-11T16:53:07+07:00" level=debug msg="completed challenge" Feb 11 16:53:07 volumio go-librespot[13354]: time="2026-02-11T16:53: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 11 16:53:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 16:53:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 16:53:07 volumio volumio[13269]: info: Loading plugin "ytcr"... Feb 11 16:53:10 volumio volumio[13269]: info: Loading plugin "ytmusic"... Feb 11 16:53:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Feb 11 16:53:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:53:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:53:10 volumio go-librespot[13361]: go-librespot daemon starting... Feb 11 16:53:10 volumio go-librespot[13362]: time="2026-02-11T16:53:10+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 16:53:10 volumio go-librespot[13362]: time="2026-02-11T16:53:10+07:00" level=debug msg="app state loaded" Feb 11 16:53:10 volumio go-librespot[13362]: time="2026-02-11T16:53:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 16:53:11 volumio volumio-remote-updater[643]: [2026-02-11 16:53:11] [connect] Successful connection Feb 11 16:53:11 volumio go-librespot[13362]: time="2026-02-11T16:53:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 16:53:11 volumio go-librespot[13362]: time="2026-02-11T16:53:11+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 16:53:11 volumio go-librespot[13362]: time="2026-02-11T16:53:11+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 16:53:11 volumio go-librespot[13362]: time="2026-02-11T16:53:11+07:00" level=info msg="zeroconf server listening on port 40383" Feb 11 16:53:11 volumio volumio[13269]: info: Loading plugin "outputs"... Feb 11 16:53:11 volumio volumio[13269]: info: Loading plugin "albumart"... Feb 11 16:53:11 volumio go-librespot[13362]: time="2026-02-11T16:53:11+07:00" level=debug msg="obtained new client token: AACXZuCaJCaTbNT9hgLVdf9tFHIH9UmX+Ha0im3VpVEv9et5KcFo928b3jA8PzBaw9qbTWGYC6/gSBGEyJ+VnxQku/XHXDgkIIHrOHZPuUkQcxxJowgCXa8PNrRKLCOd9FYqVm4wiWECRdIP6sL4xnV0cGbX7ieN1ki538RWRvgmZdEDz49kjqfhJYsMjvTFKAFgRAeXxEWLa8aA7JwkN9BAgHHK5uUERbVEKWwTn6EFH2v7BjeQk4Cksg==" Feb 11 16:53:11 volumio volumio[13269]: info: Plugin example_plugin is not enabled Feb 11 16:53:11 volumio volumio[13269]: info: Loading plugin "inputs"... Feb 11 16:53:11 volumio volumio[13269]: info: Loading plugin "updater_comm"... Feb 11 16:53:11 volumio go-librespot[13362]: time="2026-02-11T16:53:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 16:53:11 volumio go-librespot[13362]: time="2026-02-11T16:53:11+07:00" level=debug msg="completed keyexchange" Feb 11 16:53:11 volumio go-librespot[13362]: time="2026-02-11T16:53:11+07:00" level=debug msg="completed challenge" Feb 11 16:53:11 volumio volumio[13269]: info: Plugin mpdemulation is not enabled Feb 11 16:53:11 volumio volumio[13269]: info: Loading plugin "rest_api"... Feb 11 16:53:11 volumio go-librespot[13362]: time="2026-02-11T16:53:11+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 16:53:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 16:53:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 16:53:11 volumio volumio[13269]: info: Loading plugin "websocket"... Feb 11 16:53:11 volumio volumio[13269]: info: Starting Socket.io Server version 1.7.4 Feb 11 16:53:11 volumio volumio[13269]: info: Loading plugin "RoonBridge"... Feb 11 16:53:12 volumio volumio[13269]: info: Applying required configuration parameters for plugin RoonBridge Feb 11 16:53:12 volumio volumio[13269]: info: Loading i18n strings for locale en Feb 11 16:53:12 volumio volumio[13269]: Updating browse sources language Feb 11 16:53:12 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 16:53:12 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 16:53:12 volumio volumio[13269]: info: CoreCommandRouter::initPlayerControls Feb 11 16:53:12 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:12 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:12 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:12 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:12 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:12 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:12 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:12 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:12 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 16:53:12 volumio volumio[13383]: Forking 3 albumart workers Feb 11 16:53:12 volumio volumio[13269]: Express server listening on port 3000 Feb 11 16:53:12 volumio volumio[13269]: [Metrics] WebUI: 16s 142.76ms Feb 11 16:53:12 volumio volumio[13269]: info: CoreStateMachine::resetVolumioState Feb 11 16:53:12 volumio volumio[13269]: info: CoreStateMachine::getcurrentVolume Feb 11 16:53:12 volumio volumio[13269]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 16:53:12 volumio sudo[13418]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 16:53:12 volumio sudo[13418]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:53:12 volumio sudo[13427]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 16:53:12 volumio sudo[13427]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:53:12 volumio sudo[13418]: pam_unix(sudo:session): session closed for user root Feb 11 16:53:12 volumio volumio[13269]: info: Volumio Network Manager: Network status updated: 1 Feb 11 16:53:12 volumio sudo[13427]: pam_unix(sudo:session): session closed for user root Feb 11 16:53:13 volumio volumio[13269]: info: VolumeController:: Volume=100 Mute =false Feb 11 16:53:13 volumio volumio[13269]: info: CoreStateMachine::pushState Feb 11 16:53:13 volumio volumio[13269]: info: CorePlayQueue::getTrack 0 Feb 11 16:53:13 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 16:53:13 volumio volumio[13269]: info: CoreCommandRouter::volumioPushState Feb 11 16:53:13 volumio volumio[13269]: info: CoreStateMachine::updateTrackBlock Feb 11 16:53:13 volumio volumio[13269]: info: CorePlayQueue::getTrackBlock Feb 11 16:53:13 volumio volumio[13269]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 16:53:13 volumio volumio-remote-updater[643]: [2026-02-11 16:53:13] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770803591 101 Feb 11 16:53:13 volumio volumio[13269]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 11 16:53:13 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 16:53:13 volumio volumio[13269]: info: Reloading queue from file Feb 11 16:53:13 volumio volumio[13269]: info: CoreStateMachine::setRepeat null single undefined Feb 11 16:53:13 volumio volumio[13269]: info: CoreStateMachine::pushState Feb 11 16:53:13 volumio volumio[13269]: info: CorePlayQueue::getTrack 0 Feb 11 16:53:13 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 16:53:13 volumio volumio[13269]: info: CoreCommandRouter::volumioPushState Feb 11 16:53:13 volumio volumio[13269]: info: CoreStateMachine::setRandom null Feb 11 16:53:13 volumio volumio[13269]: info: CoreStateMachine::pushState Feb 11 16:53:13 volumio volumio[13269]: info: CorePlayQueue::getTrack 0 Feb 11 16:53:13 volumio volumio[13269]: info: CoreCommandRouter::volumioPushState Feb 11 16:53:13 volumio volumio[13269]: info: Setting Device type: Raspberry PI Feb 11 16:53:13 volumio volumio[13269]: info: Completed loading Core Plugins Feb 11 16:53:13 volumio volumio[13269]: info: Preparing to generate the ALSA configuration file Feb 11 16:53:13 volumio volumio[13269]: info: VolumeController:: Volume=100 Mute =false Feb 11 16:53:13 volumio volumio[13269]: info: CoreStateMachine::pushState Feb 11 16:53:13 volumio volumio[13269]: info: CorePlayQueue::getTrack 0 Feb 11 16:53:13 volumio volumio[13269]: info: CoreCommandRouter::volumioPushState Feb 11 16:53:13 volumio volumio[13269]: info: Asound.conf file unchanged, so no further update is needed Feb 11 16:53:13 volumio volumio[13269]: info: Output device has changed, restarting MPD Feb 11 16:53:13 volumio volumio[13269]: info: Output device has changed, restarting Shairport Sync Feb 11 16:53:13 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:13 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 16:53:13 volumio sudo[13444]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 11 16:53:13 volumio sudo[13444]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:53:13 volumio sudo[13446]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 16:53:13 volumio sudo[13448]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 16:53:13 volumio sudo[13448]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:53:13 volumio sudo[13446]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:53:13 volumio sudo[13446]: pam_unix(sudo:session): session closed for user root Feb 11 16:53:13 volumio volumio[13269]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 16:53:13 volumio volumio[13269]: info: ___________ START PLUGINS ___________ Feb 11 16:53:13 volumio volumio[13269]: info: ControllerMpd::onStart: Initializing MPD Feb 11 16:53:13 volumio volumio[13269]: info: Creating MPD Configuration file Feb 11 16:53:13 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 16:53:13 volumio volumio[13269]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 16:53:13 volumio volumio[13269]: info: [1770803593940] CoreMusicLibrary::Adding element Media Servers Feb 11 16:53:13 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 16:53:13 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 11 16:53:13 volumio volumio[13269]: info: UPNP Browser: Client initialized successfully Feb 11 16:53:14 volumio sudo[13444]: pam_unix(sudo:session): session closed for user root Feb 11 16:53:14 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:14 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 16:53:14 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 11 16:53:14 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 11 16:53:14 volumio systemd[1]: mpd.service: Consumed 7.138s CPU time. Feb 11 16:53:14 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 11 16:53:14 volumio sudo[13457]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 16:53:14 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 11 16:53:14 volumio sudo[13457]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:53:14 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 11 16:53:14 volumio sudo[13457]: pam_unix(sudo:session): session closed for user root Feb 11 16:53:14 volumio volumio[13269]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 16:53:14 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:14 volumio sudo[13459]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 16:53:14 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 16:53:14 volumio sudo[13459]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:53:14 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 11 16:53:14 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 11 16:53:14 volumio volumio[13269]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 16:53:14 volumio volumio[13269]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 16:53:14 volumio volumio[13269]: info: [1770803594245] CoreMusicLibrary::Adding element Last_100 Feb 11 16:53:14 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 16:53:14 volumio volumio[13269]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 16:53:14 volumio volumio[13269]: info: [1770803594257] CoreMusicLibrary::Adding element Webradio Feb 11 16:53:14 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 16:53:14 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 16:53:14 volumio volumio[13269]: info: Initializing BBC Radios Feb 11 16:53:14 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 11 16:53:14 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 11 16:53:14 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 11 16:53:14 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 11 16:53:14 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 11 16:53:14 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 11 16:53:14 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 16:53:14 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 16:53:14 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 11 16:53:14 volumio volumio[13269]: info: Creating Spotify config file Feb 11 16:53:14 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Feb 11 16:53:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:53:14 volumio sudo[13486]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 11 16:53:14 volumio sudo[13486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 11 16:53:14 volumio sudo[13486]: pam_unix(sudo:session): session closed for user root Feb 11 16:53:14 volumio go-librespot[13487]: go-librespot daemon starting... Feb 11 16:53:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:53:15 volumio go-librespot[13489]: time="2026-02-11T16:53:15+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 16:53:15 volumio volumio[13269]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 16:53:15 volumio volumio[13269]: info: [1770803595493] CoreMusicLibrary::Adding element YouTube Music Feb 11 16:53:15 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 16:53:15 volumio volumio[13269]: Cannot find translation for source YouTube Music Feb 11 16:53:15 volumio volumio[13269]: info: Volumio Calling Home Feb 11 16:53:15 volumio sudo[13499]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 11 16:53:15 volumio sudo[13499]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:53:15 volumio go-librespot[13489]: time="2026-02-11T16:53:15+07:00" level=info msg="zeroconf server listening on port 33299" Feb 11 16:53:15 volumio sudo[13499]: pam_unix(sudo:session): session closed for user root Feb 11 16:53:15 volumio volumio[13394]: Starting albumart workers Feb 11 16:53:16 volumio volumio[13399]: Starting albumart workers Feb 11 16:53:16 volumio volumio[13269]: info: MPD Permissions set Feb 11 16:53:16 volumio volumio[13269]: info: MPD Permissions set Feb 11 16:53:16 volumio volumio[13269]: info: Upmpdcli Daemon Started Feb 11 16:53:16 volumio volumio[13269]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 11 16:53:16 volumio volumio[13398]: Starting albumart workers Feb 11 16:53:16 volumio volumio[13269]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 11 16:53:16 volumio volumio[13269]: info: Discovery: Found device Volumio Feb 11 16:53:16 volumio volumio[13269]: info: CoreCommandRouter::volumioGetState Feb 11 16:53:16 volumio volumio[13269]: info: CorePlayQueue::getTrack 0 Feb 11 16:53:16 volumio volumio[13269]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 11 16:53:16 volumio volumio[13269]: info: Discovery: Found device Volumio Feb 11 16:53:16 volumio volumio[13269]: info: CoreCommandRouter::volumioGetState Feb 11 16:53:16 volumio volumio[13269]: info: CorePlayQueue::getTrack 0 Feb 11 16:53:16 volumio volumio[13269]: info: Spotify config file written Feb 11 16:53:16 volumio sudo[13506]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 11 16:53:16 volumio sudo[13506]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:53:16 volumio volumio[13269]: info: Volumio called home Feb 11 16:53:17 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 11 16:53:17 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 11 16:53:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:53:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:53:17 volumio go-librespot[13508]: go-librespot daemon starting... Feb 11 16:53:17 volumio sudo[13506]: pam_unix(sudo:session): session closed for user root Feb 11 16:53:17 volumio go-librespot[13510]: time="2026-02-11T16:53:17+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 16:53:17 volumio go-librespot[13510]: time="2026-02-11T16:53:17+07:00" level=debug msg="app state loaded" Feb 11 16:53:17 volumio go-librespot[13510]: time="2026-02-11T16:53:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 16:53:17 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:17 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:17 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:17 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:17 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:17 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:17 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:17 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:17 volumio go-librespot[13510]: time="2026-02-11T16:53:17+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 16:53:17 volumio go-librespot[13510]: time="2026-02-11T16:53:17+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 16:53:17 volumio go-librespot[13510]: time="2026-02-11T16:53:17+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 16:53:17 volumio go-librespot[13510]: time="2026-02-11T16:53:17+07:00" level=info msg="zeroconf server listening on port 46519" Feb 11 16:53:18 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 16:53:18 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:18 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:18 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:18 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:18 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:18 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:18 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:18 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:18 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:18 volumio go-librespot[13510]: time="2026-02-11T16:53:18+07:00" level=debug msg="obtained new client token: AADFM+e6AxQ0e5WYfdWzhVAYOArACJ0yjKdGOBFMTnHHLA+mKPyvv3bQ3uZIl8VKDumbVO3w++58p4bygJnxdQ/h30tMNeDGeBD3BRRx302tcaVrKrsV4U2M7SimJcxtev7c3t3bu8+v835LgPlkZm+cM/BSfJ0nWm4L8K+Lrn5F634r97M2M9PgsmJXWHz4Nuhew6qs/OfZKOf+6X7KZ7aAO2CkDvA5GpkqwZnm8Au1+4nnZWLuT0E=" Feb 11 16:53:18 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 16:53:18 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:18 volumio volumio[13269]: info: No need to fix Spotify hosts Feb 11 16:53:18 volumio go-librespot[13510]: time="2026-02-11T16:53:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 16:53:18 volumio go-librespot[13510]: time="2026-02-11T16:53:18+07:00" level=debug msg="completed keyexchange" Feb 11 16:53:18 volumio go-librespot[13510]: time="2026-02-11T16:53:18+07:00" level=debug msg="completed challenge" Feb 11 16:53:18 volumio go-librespot[13510]: time="2026-02-11T16:53:18+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 16:53:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 16:53:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 16:53:18 volumio volumio[13269]: info: Starting Shairport Sync Feb 11 16:53:18 volumio volumio[13269]: info: Starting Shairport Sync Feb 11 16:53:18 volumio volumio[13269]: info: Starting Shairport Sync Feb 11 16:53:18 volumio sudo[13536]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 16:53:18 volumio sudo[13536]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:53:18 volumio sudo[13534]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 16:53:18 volumio sudo[13534]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:53:18 volumio sudo[13538]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 16:53:18 volumio sudo[13538]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:53:18 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 11 16:53:18 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 11 16:53:18 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 16:53:18 volumio systemd[1]: shairport-sync.service: Consumed 2.338s CPU time. Feb 11 16:53:19 volumio volumio[13269]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 11 16:53:19 volumio volumio[13269]: SPOTIFY: BQCoTKhkOgwXQ3zJ0jFVIgejqTdTTziB5K3d5fvFWA7Nxd1GOBdm3VgdTsbr8910Dkq6iqTtr7QlKaeI0cFGlKlVP-G7m5-5cZi-rK0ClgC7lletcWILfNvzl_xX_VKh1mNLCwDBd4R5O4eCgKGKVl4meirnIi8EIVNUMu9IGPysu4WCWlYe6Z2tELorV2Fn7SK16_5gSDZgCof1QmPlaLkkAYKb1I6POMp92F6yCejxhbtATr35ulmslm68XN4V9ZKbRNvhfXU3H1RdJftSmQ9cc07XzzzN8Tajoya7zmVVHB_2ybg11-CE Feb 11 16:53:19 volumio volumio[13269]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 11 16:53:19 volumio volumio[13269]: info: New Spotify access token = BQCoTKhkOgwXQ3zJ0jFVIgejqTdTTziB5K3d5fvFWA7Nxd1GOBdm3VgdTsbr8910Dkq6iqTtr7QlKaeI0cFGlKlVP-G7m5-5cZi-rK0ClgC7lletcWILfNvzl_xX_VKh1mNLCwDBd4R5O4eCgKGKVl4meirnIi8EIVNUMu9IGPysu4WCWlYe6Z2tELorV2Fn7SK16_5gSDZgCof1QmPlaLkkAYKb1I6POMp92F6yCejxhbtATr35ulmslm68XN4V9ZKbRNvhfXU3H1RdJftSmQ9cc07XzzzN8Tajoya7zmVVHB_2ybg11-CE Feb 11 16:53:19 volumio volumio[13269]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 11 16:53:19 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 16:53:19 volumio sudo[13536]: pam_unix(sudo:session): session closed for user root Feb 11 16:53:19 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 11 16:53:19 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 11 16:53:19 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 16:53:19 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 16:53:19 volumio sudo[13538]: pam_unix(sudo:session): session closed for user root Feb 11 16:53:19 volumio sudo[13534]: pam_unix(sudo:session): session closed for user root Feb 11 16:53:19 volumio volumio[13269]: info: CoreCommandRouter::volumioGetState Feb 11 16:53:19 volumio volumio[13269]: info: CorePlayQueue::getTrack 0 Feb 11 16:53:19 volumio volumio[13269]: info: Shairport-Sync Started Feb 11 16:53:19 volumio volumio[13269]: Error adding Membership: Error: addMembership EINVAL Feb 11 16:53:19 volumio volumio[13269]: info: Shairport-Sync Started Feb 11 16:53:19 volumio volumio[13269]: info: Shairport-Sync Started Feb 11 16:53:19 volumio volumio[13269]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 11 16:53:19 volumio volumio[13269]: info: Spotify Successfully logged in Feb 11 16:53:19 volumio volumio[13269]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 16:53:19 volumio volumio[13269]: info: [1770803599876] CoreMusicLibrary::Adding element Spotify Feb 11 16:53:19 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 16:53:19 volumio volumio[13269]: Cannot find translation for source YouTube Music Feb 11 16:53:19 volumio volumio[13269]: Cannot find translation for source Spotify Feb 11 16:53:20 volumio volumio[13269]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 11 16:53:20 volumio volumio[13269]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 16:53:20 volumio volumio[13269]: info: VolumeController:: Volume=100 Mute =false Feb 11 16:53:20 volumio volumio[13269]: info: CoreCommandRouter::volumioGetState Feb 11 16:53:20 volumio volumio[13269]: info: CorePlayQueue::getTrack 0 Feb 11 16:53:20 volumio volumio[13269]: info: CoreStateMachine::pushState Feb 11 16:53:20 volumio volumio[13269]: info: CorePlayQueue::getTrack 0 Feb 11 16:53:20 volumio volumio[13269]: info: CoreCommandRouter::volumioPushState Feb 11 16:53:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 11 16:53:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:53:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:53:21 volumio go-librespot[13587]: go-librespot daemon starting... Feb 11 16:53:21 volumio volumio[13269]: info: go-librespot daemon successfully initialized Feb 11 16:53:21 volumio go-librespot[13588]: time="2026-02-11T16:53:21+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 16:53:21 volumio go-librespot[13588]: time="2026-02-11T16:53:21+07:00" level=debug msg="app state loaded" Feb 11 16:53:21 volumio go-librespot[13588]: time="2026-02-11T16:53:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 16:53:22 volumio mpd[13490]: 2026-02-11T16:53:22 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 11 16:53:22 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 11 16:53:22 volumio sudo[13448]: pam_unix(sudo:session): session closed for user root Feb 11 16:53:22 volumio sudo[13459]: pam_unix(sudo:session): session closed for user root Feb 11 16:53:22 volumio go-librespot[13588]: time="2026-02-11T16:53:22+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 16:53:22 volumio go-librespot[13588]: time="2026-02-11T16:53:22+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 16:53:22 volumio go-librespot[13588]: time="2026-02-11T16:53:22+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 16:53:22 volumio go-librespot[13588]: time="2026-02-11T16:53:22+07:00" level=info msg="zeroconf server listening on port 44393" Feb 11 16:53:22 volumio volumio[13269]: error: MPD error: The expression evaluated to a falsy value: Feb 11 16:53:22 volumio volumio[13269]: assert.ok(self.idling) Feb 11 16:53:22 volumio volumio[13269]: error: The expression evaluated to a falsy value: Feb 11 16:53:22 volumio volumio[13269]: assert.ok(self.idling) Feb 11 16:53:22 volumio volumio[13269]: info: MPD running with PID13490 Feb 11 16:53:22 volumio volumio[13269]: ,establishing connection Feb 11 16:53:22 volumio volumio[13269]: error: updateQueue error: null Feb 11 16:53:22 volumio volumio[13269]: info: Completed starting Core Plugins Feb 11 16:53:22 volumio volumio[13269]: info: ------------------------------------------- Feb 11 16:53:22 volumio volumio[13269]: info: ----- MyVolumio plugins startup ---- Feb 11 16:53:22 volumio volumio[13269]: info: ------------------------------------------- Feb 11 16:53:22 volumio volumio[13269]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 11 16:53:22 volumio volumio[13269]: error: updateQueue error: null Feb 11 16:53:22 volumio go-librespot[13588]: time="2026-02-11T16:53:22+07:00" level=debug msg="obtained new client token: AAApwcNdRyFyIOS79DHBQCYJOFAYJ0BrUO6wchKlbkmbWP5VZJe4RumlCU5rSsIQwP6qyz4vdVvI6ZY3TgBvpb1Oxy5ioQPbXFMA+jiJO0sv3cvyMpFH6bbevsu9OXcSKP3/Qfm06Bte/eS22jZdWcWKg92rmW8IGXkSfDZ+eb1+065G8iHECMOUhS0putYzXgCOsKVVv9+c5aBs6ZOmOvT0Ns+StzvZ8l0PEwRwuzh+LdAxzrmuQpJoew==" Feb 11 16:53:22 volumio go-librespot[13588]: time="2026-02-11T16:53:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 16:53:22 volumio go-librespot[13588]: time="2026-02-11T16:53:22+07:00" level=debug msg="completed keyexchange" Feb 11 16:53:22 volumio go-librespot[13588]: time="2026-02-11T16:53:22+07:00" level=debug msg="completed challenge" Feb 11 16:53:22 volumio go-librespot[13588]: time="2026-02-11T16:53:22+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 16:53:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 16:53:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 16:53:24 volumio volumio[13269]: info: Initializing connection to go-librespot Websocket Feb 11 16:53:24 volumio volumio[13269]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 16:53:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 11 16:53:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:53:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:53:25 volumio go-librespot[13599]: go-librespot daemon starting... Feb 11 16:53:25 volumio go-librespot[13600]: time="2026-02-11T16:53:25+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 16:53:25 volumio go-librespot[13600]: time="2026-02-11T16:53:25+07:00" level=debug msg="app state loaded" Feb 11 16:53:25 volumio go-librespot[13600]: time="2026-02-11T16:53:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 16:53:26 volumio go-librespot[13600]: time="2026-02-11T16:53: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 16:53:26 volumio go-librespot[13600]: time="2026-02-11T16:53:26+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 16:53:26 volumio go-librespot[13600]: time="2026-02-11T16:53:26+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 16:53:26 volumio go-librespot[13600]: time="2026-02-11T16:53:26+07:00" level=info msg="zeroconf server listening on port 34147" Feb 11 16:53:26 volumio go-librespot[13600]: time="2026-02-11T16:53:26+07:00" level=debug msg="obtained new client token: AACzN1pKfQ5ZzBVb9b1RTvt74EDZ6q7AxnKHPJS2Q86utLWzcqDjPEihiDfPcvTMHijNR4VRt8gTOWzYltG3ju7isbjab27VWKrqlB1Th/AK4rLD2PhcWh3wSVOHYG5+CfNf225y0gznkBYQYd7hh4yE2WN2Z66RKlOHa92DDPtNXgqgplvB3Wig2XT5Dx9FmpoOoCInio+Dx5OjjR4HY/g4h131r7GaKmfX3EeR5PU3t+/PKYm+8ytmTw==" Feb 11 16:53:26 volumio go-librespot[13600]: time="2026-02-11T16:53:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 16:53:26 volumio go-librespot[13600]: time="2026-02-11T16:53:26+07:00" level=debug msg="completed keyexchange" Feb 11 16:53:26 volumio go-librespot[13600]: time="2026-02-11T16:53:26+07:00" level=debug msg="completed challenge" Feb 11 16:53:26 volumio go-librespot[13600]: time="2026-02-11T16:53:26+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 16:53:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 16:53:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 16:53:27 volumio volumio[13269]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 11 16:53:27 volumio volumio[13269]: info: Initializing connection to go-librespot Websocket Feb 11 16:53:27 volumio volumio[13269]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 16:53:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 11 16:53:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:53:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:53:30 volumio go-librespot[13607]: go-librespot daemon starting... Feb 11 16:53:30 volumio go-librespot[13608]: time="2026-02-11T16:53:30+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 16:53:30 volumio go-librespot[13608]: time="2026-02-11T16:53:30+07:00" level=debug msg="app state loaded" Feb 11 16:53:30 volumio go-librespot[13608]: time="2026-02-11T16:53:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 16:53:30 volumio go-librespot[13608]: time="2026-02-11T16:53:30+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 16:53:30 volumio go-librespot[13608]: time="2026-02-11T16:53:30+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 16:53:30 volumio go-librespot[13608]: time="2026-02-11T16:53:30+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 16:53:30 volumio volumio[13269]: info: Initializing connection to go-librespot Websocket Feb 11 16:53:30 volumio go-librespot[13608]: time="2026-02-11T16:53:30+07:00" level=debug msg="new websocket client" Feb 11 16:53:30 volumio volumio[13269]: info: Connection to go-librespot Websocket established Feb 11 16:53:30 volumio go-librespot[13608]: time="2026-02-11T16:53:30+07:00" level=info msg="zeroconf server listening on port 41809" Feb 11 16:53:30 volumio go-librespot[13608]: time="2026-02-11T16:53:30+07:00" level=debug msg="obtained new client token: AABqBYpB+cS+AfEldxzMrbRzB6mSTvBRLt/+LBDzwQEbZGQKH6pLvDBViRJULZ8d3sAc+30IMShvXaqOfF9FmLgjK5n2hKo5IkJonlC+8PuF/waQ4JDXiWWaUr85jOyBLyH989adiY+KtNdu1FCjABiyA6L1ZWONnin0HNyR6kVkyJEFbLTFWdSy2lPsh30I5tkz4e9D3GPLk5OeTHTArpwaX1SJ2zTC45kFXZG3zr7ofFeREp4YpZERMA==" Feb 11 16:53:31 volumio go-librespot[13608]: time="2026-02-11T16:53:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 16:53:31 volumio go-librespot[13608]: time="2026-02-11T16:53:31+07:00" level=debug msg="completed keyexchange" Feb 11 16:53:31 volumio go-librespot[13608]: time="2026-02-11T16:53:31+07:00" level=debug msg="completed challenge" Feb 11 16:53:31 volumio go-librespot[13608]: time="2026-02-11T16:53:31+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 16:53:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 16:53:31 volumio volumio[13269]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 11 16:53:31 volumio volumio[13269]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 11 16:53:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 16:53:31 volumio volumio[13269]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 11 16:53:31 volumio volumio[13269]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 11 16:53:31 volumio volumio[13269]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 11 16:53:31 volumio volumio[13269]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 11 16:53:31 volumio volumio[13269]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 11 16:53:31 volumio volumio[13269]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 11 16:53:31 volumio volumio[13269]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 11 16:53:31 volumio volumio[13269]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 11 16:53:31 volumio volumio[13269]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 11 16:53:31 volumio volumio[13269]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 11 16:53:31 volumio volumio[13269]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 11 16:53:31 volumio volumio[13269]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 11 16:53:31 volumio volumio[13269]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 11 16:53:31 volumio volumio[13269]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 11 16:53:31 volumio volumio[13269]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 11 16:53:31 volumio volumio[13269]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 11 16:53:31 volumio volumio[13269]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 11 16:53:31 volumio volumio[13269]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 11 16:53:31 volumio volumio[13269]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 11 16:53:31 volumio volumio[13269]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 11 16:53:31 volumio volumio[13269]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 11 16:53:31 volumio volumio[13269]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 11 16:53:31 volumio volumio[13269]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 11 16:53:31 volumio volumio[13269]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 11 16:53:31 volumio volumio[13269]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 11 16:53:31 volumio volumio[13269]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 11 16:53:31 volumio volumio[13269]: info: Adding plugin bluetooth to MyMusic Plugins Feb 11 16:53:31 volumio volumio[13269]: info: Adding plugin multiroom to MyMusic Plugins Feb 11 16:53:31 volumio volumio[13269]: info: Adding plugin metavolumio to MyMusic Plugins Feb 11 16:53:31 volumio volumio[13269]: info: Adding plugin cd_controller to MyMusic Plugins Feb 11 16:53:31 volumio volumio[13269]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 11 16:53:31 volumio volumio[13269]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 11 16:53:31 volumio volumio[13269]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 11 16:53:31 volumio volumio[13269]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 11 16:53:32 volumio volumio[13269]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 11 16:53:33 volumio volumio[13269]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 11 16:53:33 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 16:53:33 volumio volumio[13269]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 16:53:33 volumio volumio[13269]: info: Starting MyVolumio Remote Streaming Endpoints Feb 11 16:53:33 volumio volumio[13269]: info: MyVolumio login type: Token Feb 11 16:53:33 volumio volumio[13269]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 11 16:53:33 volumio volumio[13269]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 11 16:53:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 11 16:53:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:53:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:53:34 volumio go-librespot[13632]: go-librespot daemon starting... Feb 11 16:53:34 volumio go-librespot[13633]: time="2026-02-11T16:53:34+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 16:53:34 volumio go-librespot[13633]: time="2026-02-11T16:53:34+07:00" level=debug msg="app state loaded" Feb 11 16:53:34 volumio go-librespot[13633]: time="2026-02-11T16:53:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 16:53:34 volumio volumio[13269]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 11 16:53:34 volumio volumio[13269]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 11 16:53:34 volumio volumio[13269]: info: Streaming services startup Feb 11 16:53:34 volumio volumio[13269]: info: Starting Streaming Daemon Feb 11 16:53:34 volumio sudo[13642]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 11 16:53:34 volumio sudo[13642]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:53:34 volumio volumio[13269]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 11 16:53:34 volumio go-librespot[13633]: time="2026-02-11T16:53: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 16:53:34 volumio go-librespot[13633]: time="2026-02-11T16:53:34+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 16:53:34 volumio go-librespot[13633]: time="2026-02-11T16:53:34+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 16:53:35 volumio sudo[13642]: pam_unix(sudo:session): session closed for user root Feb 11 16:53:35 volumio go-librespot[13633]: time="2026-02-11T16:53:35+07:00" level=info msg="zeroconf server listening on port 33713" Feb 11 16:53:35 volumio volumio[13269]: info: Getting Spotify volume Feb 11 16:53:35 volumio volumio[13269]: info: Connection to go-librespot Websocket closed Feb 11 16:53:35 volumio volumio[13269]: error: Cannot start Volumio Streaming Daemon Feb 11 16:53:35 volumio volumio[13269]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 11 16:53:35 volumio volumio[13269]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 11 16:53:35 volumio volumio[13269]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 11 16:53:35 volumio go-librespot[13633]: time="2026-02-11T16:53:35+07:00" level=debug msg="obtained new client token: AABNH9oHyvaC98DlZqV1eoKm2k321Jtpwdzn4HpBmBKiZ7cdAh7ctTNFk09WWqO3jh7nyx3/LDsodit4iRMOiDCySbvQZN9RntXW24ScRzFEzRPDd3ui3/pM63ahgrFYPipyPeps44p/lx4y6mna+r7at0eZY2e6Q59VjVbxl2SK3t2KfcirvpmDRdL/cEYBV1sGB2msZ+SmGcXk2AuOFn1awBzA4N6/pmfPoD6a8Ywa2qI1w2FPbrE=" Feb 11 16:53:35 volumio go-librespot[13633]: time="2026-02-11T16:53:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 16:53:35 volumio volumio[13269]: info: CoreCommandRouter::volumioGetState Feb 11 16:53:35 volumio volumio[13269]: info: CorePlayQueue::getTrack 0 Feb 11 16:53:35 volumio volumio[13269]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 11 16:53:35 volumio volumio[13269]: SPOTIFY: SPOTIFY VOLUME undefined Feb 11 16:53:35 volumio volumio[13269]: SPOTIFY: VOLUMIO VOLUME 100 Feb 11 16:53:35 volumio go-librespot[13633]: time="2026-02-11T16:53:35+07:00" level=debug msg="completed keyexchange" Feb 11 16:53:35 volumio volumio[13269]: info: Aligning Spotify Volume to Volumio Volume Feb 11 16:53:35 volumio volumio[13269]: info: CoreCommandRouter::volumioGetState Feb 11 16:53:35 volumio volumio[13269]: info: CorePlayQueue::getTrack 0 Feb 11 16:53:35 volumio volumio[13269]: info: Setting Spotify Volume from Volumio: 100 Feb 11 16:53:35 volumio go-librespot[13633]: time="2026-02-11T16:53:35+07:00" level=debug msg="completed challenge" Feb 11 16:53:35 volumio go-librespot[13633]: time="2026-02-11T16:53:35+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 16:53:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 16:53:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 16:53:35 volumio volumio[13269]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 16:53:35 volumio volumio[13269]: Error: socket hang up Feb 11 16:53:35 volumio volumio[13269]: at connResetException (node:internal/errors:720:14) Feb 11 16:53:35 volumio volumio[13269]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 11 16:53:35 volumio volumio[13269]: at Socket.emit (node:events:526:35) Feb 11 16:53:35 volumio volumio[13269]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 11 16:53:35 volumio volumio[13269]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 11 16:53:35 volumio volumio[13269]: code: 'ECONNRESET', Feb 11 16:53:35 volumio volumio[13269]: response: undefined Feb 11 16:53:35 volumio volumio[13269]: } Feb 11 16:53:35 volumio volumio[13269]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 16:53:36 volumio sudo[13662]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-11 16:52' Feb 11 16:53:36 volumio sudo[13662]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:53:37 volumio sudo[13662]: pam_unix(sudo:session): session closed for user root Feb 11 16:53:37 volumio volumio-remote-updater[643]: [2026-02-11 16:53:37] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 11 16:53:37 volumio volumio-remote-updater[643]: [2026-02-11 16:53:37] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 11 16:53:37 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 11 16:53:37 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 11 16:53:37 volumio systemd[1]: volumio.service: Consumed 55.451s CPU time. Feb 11 16:53:37 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 11 16:53:37 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 11 16:53:37 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 11967. Feb 11 16:53:37 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 11 16:53:37 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 11 16:53:37 volumio systemd[1]: volumio.service: Consumed 55.451s CPU time. Feb 11 16:53:37 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 11 16:53:37 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 11 16:53:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 11 16:53:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:53:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:53:38 volumio go-librespot[13693]: go-librespot daemon starting... Feb 11 16:53:38 volumio go-librespot[13694]: time="2026-02-11T16:53:38+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 16:53:38 volumio go-librespot[13694]: time="2026-02-11T16:53:38+07:00" level=debug msg="app state loaded" Feb 11 16:53:38 volumio go-librespot[13694]: time="2026-02-11T16:53:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 16:53:39 volumio go-librespot[13694]: time="2026-02-11T16:53:39+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 16:53:39 volumio go-librespot[13694]: time="2026-02-11T16:53:39+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 16:53:39 volumio go-librespot[13694]: time="2026-02-11T16:53:39+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 16:53:39 volumio go-librespot[13694]: time="2026-02-11T16:53:39+07:00" level=info msg="zeroconf server listening on port 35401" Feb 11 16:53:39 volumio go-librespot[13694]: time="2026-02-11T16:53:39+07:00" level=debug msg="obtained new client token: AAAgos18yckT7orj++0W7X6KXnG0/uDUi6k/YuLAOTXYtLSyj3lPz48hgmR86fjDgeC0yVQSvzmaY9nQdsUcdBzYIg92oHor74Z/Yiw9KYzZXOHtoUBPoyq+0fElU+S62Bsl1Kfaiz7eG4VEtlKO/kXPIZD8tzxuALbTjRT/yWq9qHHX2fGEojzSQTwTD8LnWXy9fGwWOeMBjkvvR/K4qlcIGCBjAmwqLmyaTXiwMuF7mrPUUPXJdJn4qg==" Feb 11 16:53:39 volumio go-librespot[13694]: time="2026-02-11T16:53:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 16:53:39 volumio go-librespot[13694]: time="2026-02-11T16:53:39+07:00" level=debug msg="completed keyexchange" Feb 11 16:53:39 volumio go-librespot[13694]: time="2026-02-11T16:53:39+07:00" level=debug msg="completed challenge" Feb 11 16:53:39 volumio go-librespot[13694]: time="2026-02-11T16:53:39+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 16:53:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 16:53:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 16:53:41 volumio volumio[13678]: info: ------------------------------------------- Feb 11 16:53:41 volumio volumio[13678]: info: ----- Volumio3 ---- Feb 11 16:53:41 volumio volumio[13678]: info: ------------------------------------------- Feb 11 16:53:41 volumio volumio[13678]: info: ----- System startup ---- Feb 11 16:53:41 volumio volumio[13678]: info: ------------------------------------------- Feb 11 16:53:42 volumio volumio-remote-updater[643]: [2026-02-11 16:53:42] [connect] Successful connection Feb 11 16:53:42 volumio volumio[13678]: info: MYVOLUMIO Environment detected Feb 11 16:53:42 volumio volumio[13678]: info: Plugin folders cleanup Feb 11 16:53:42 volumio volumio[13678]: info: Scanning into folder /volumio/app/plugins/ Feb 11 16:53:42 volumio volumio[13678]: info: Scanning category audio_interface Feb 11 16:53:42 volumio volumio[13678]: info: Scanning category miscellanea Feb 11 16:53:42 volumio volumio[13678]: info: Scanning category music_service Feb 11 16:53:42 volumio volumio[13678]: info: Scanning category plugins.json Feb 11 16:53:42 volumio volumio[13678]: info: Scanning category system_controller Feb 11 16:53:42 volumio volumio[13678]: info: Scanning category user_interface Feb 11 16:53:42 volumio volumio[13678]: info: Scanning into folder /data/plugins/ Feb 11 16:53:42 volumio volumio[13678]: info: Scanning category music_service Feb 11 16:53:42 volumio volumio[13678]: info: Plugin folders cleanup completed Feb 11 16:53:42 volumio volumio[13678]: info: ------------------------------------------- Feb 11 16:53:42 volumio volumio[13678]: info: ----- Core plugins startup ---- Feb 11 16:53:42 volumio volumio[13678]: info: ------------------------------------------- Feb 11 16:53:42 volumio volumio[13678]: info: Loading plugins from folder /volumio/app/plugins/ Feb 11 16:53:42 volumio volumio[13678]: info: Adding plugin upnp to MyMusic Plugins Feb 11 16:53:42 volumio volumio[13678]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 11 16:53:42 volumio volumio[13678]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 11 16:53:42 volumio volumio[13678]: info: Loading plugins from folder /data/plugins/ Feb 11 16:53:42 volumio volumio[13678]: info: Loading plugin "system"... Feb 11 16:53:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 11 16:53:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:53:42 volumio volumio[13678]: info: Loading plugin "appearance"... Feb 11 16:53:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:53:42 volumio go-librespot[13715]: go-librespot daemon starting... Feb 11 16:53:42 volumio go-librespot[13716]: time="2026-02-11T16:53:42+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 16:53:42 volumio go-librespot[13716]: time="2026-02-11T16:53:42+07:00" level=debug msg="app state loaded" Feb 11 16:53:42 volumio go-librespot[13716]: time="2026-02-11T16:53:42+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 16:53:43 volumio go-librespot[13716]: time="2026-02-11T16:53:43+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 16:53:43 volumio go-librespot[13716]: time="2026-02-11T16:53:43+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 16:53:43 volumio go-librespot[13716]: time="2026-02-11T16:53:43+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 16:53:43 volumio go-librespot[13716]: time="2026-02-11T16:53:43+07:00" level=info msg="zeroconf server listening on port 46743" Feb 11 16:53:43 volumio go-librespot[13716]: time="2026-02-11T16:53:43+07:00" level=debug msg="obtained new client token: AACg3mRljTlFCwiR80hT1fPl1fnobdbDwsveXrC6S6bukanRDJujjBKwDsf9g3gB7XTktq/Ns/FXYtanfngRPSzFg40MG6TeTipIVzc9AKrQzcIQ5WBiw+3qE0/Tv3R3hFult05GPhi6Cd9ogEAGLaqcUh3pp0MIP34VyhIMkRdlUsunHtarGNsIWez09WqitcjresCK3C51MXdZ77DlXDwQXtb/82SEdceL3M32zifdSHXfBdWIBFK9lQ==" Feb 11 16:53:43 volumio go-librespot[13716]: time="2026-02-11T16:53:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 16:53:43 volumio go-librespot[13716]: time="2026-02-11T16:53:43+07:00" level=debug msg="completed keyexchange" Feb 11 16:53:43 volumio go-librespot[13716]: time="2026-02-11T16:53:43+07:00" level=debug msg="completed challenge" Feb 11 16:53:44 volumio go-librespot[13716]: time="2026-02-11T16:53: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 11 16:53:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 16:53:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 16:53:44 volumio volumio[13678]: info: Loading plugin "network"... Feb 11 16:53:44 volumio volumio[13678]: info: Refreshing Cached IP Addresses Feb 11 16:53:44 volumio sudo[13724]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 16:53:44 volumio sudo[13724]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:53:44 volumio sudo[13726]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 16:53:44 volumio sudo[13724]: pam_unix(sudo:session): session closed for user root Feb 11 16:53:44 volumio sudo[13726]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:53:44 volumio sudo[13726]: pam_unix(sudo:session): session closed for user root Feb 11 16:53:44 volumio volumio[13678]: info: Loading plugin "services"... Feb 11 16:53:44 volumio volumio[13678]: info: Loading plugin "alsa_controller"... Feb 11 16:53:44 volumio sudo[13735]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 11 16:53:44 volumio sudo[13735]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:53:45 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 16:53:45 volumio volumio[13678]: info: Loading plugin "wizard"... Feb 11 16:53:45 volumio volumio[13678]: info: Loading plugin "networkfs"... Feb 11 16:53:45 volumio volumio[13678]: info: Starting Udev Watcher for removable devices Feb 11 16:53:45 volumio volumio[13678]: info: Ignoring mount for partition: boot Feb 11 16:53:45 volumio volumio[13678]: info: Ignoring mount for partition: volumio Feb 11 16:53:45 volumio volumio[13678]: info: Ignoring mount for partition: volumio_data Feb 11 16:53:45 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 16:53:45 volumio volumio[13678]: info: Loading plugin "volumio_command_line_client"... Feb 11 16:53:45 volumio volumio[13678]: info: Loading plugin "upnp"... Feb 11 16:53:45 volumio volumio[13678]: info: [1770803625149] Starting Upmpd Daemon Feb 11 16:53:45 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 16:53:45 volumio volumio[13678]: info: Loading plugin "my_music"... Feb 11 16:53:45 volumio volumio[13678]: info: Loading plugin "mpd"... Feb 11 16:53:45 volumio volumio[13678]: info: Loading plugin "upnp_browser"... Feb 11 16:53:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 11 16:53:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:53:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:53:47 volumio go-librespot[13757]: go-librespot daemon starting... Feb 11 16:53:47 volumio go-librespot[13758]: time="2026-02-11T16:53:47+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 16:53:47 volumio go-librespot[13758]: time="2026-02-11T16:53:47+07:00" level=debug msg="app state loaded" Feb 11 16:53:47 volumio go-librespot[13758]: time="2026-02-11T16:53:47+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 16:53:47 volumio sudo[13735]: pam_unix(sudo:session): session closed for user root Feb 11 16:53:47 volumio go-librespot[13758]: time="2026-02-11T16:53:47+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 11 16:53:47 volumio go-librespot[13758]: time="2026-02-11T16:53:47+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 11 16:53:47 volumio go-librespot[13758]: time="2026-02-11T16:53:47+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 11 16:53:47 volumio go-librespot[13758]: time="2026-02-11T16:53:47+07:00" level=info msg="zeroconf server listening on port 34677" Feb 11 16:53:48 volumio go-librespot[13758]: time="2026-02-11T16:53:48+07:00" level=debug msg="obtained new client token: AAA+oI6ggYrAsVa/4K+fWktbgD+0hv89G9eaFROLLDU7qRaiBe8N+ON3XmdmO9gXcHeYXofadMlbdEC3k+sIgig9kj2pLwFum+JBYh4J0mib54husFvz14aqojW/N28oNDeOXNEfwIDKybxhEZ/sosbyjLH5tzAa7N0aj60kw7NoCtgWDEaUgDD2Vgw7z2zCx5fMzUTrbj4V4jOI0kPu5Oe3KpKqevDiJeAjEDrePARMFK4NFT9mq4M=" Feb 11 16:53:48 volumio go-librespot[13758]: time="2026-02-11T16:53:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 16:53:48 volumio go-librespot[13758]: time="2026-02-11T16:53:48+07:00" level=debug msg="completed keyexchange" Feb 11 16:53:48 volumio go-librespot[13758]: time="2026-02-11T16:53:48+07:00" level=debug msg="completed challenge" Feb 11 16:53:48 volumio go-librespot[13758]: time="2026-02-11T16:53:48+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 16:53:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 16:53:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 16:53:48 volumio volumio[13678]: info: Starting UPNP Browser Feb 11 16:53:48 volumio volumio[13678]: info: Loading plugin "alarm-clock"... Feb 11 16:53:49 volumio volumio[13678]: info: Loading plugin "airplay_emulation"... Feb 11 16:53:49 volumio volumio[13678]: info: Starting Shairport Sync Feb 11 16:53:49 volumio volumio[13678]: info: Loading plugin "last_100"... Feb 11 16:53:49 volumio volumio[13678]: info: Loading plugin "webradio"... Feb 11 16:53:49 volumio volumio[13678]: info: Loading plugin "i2s_dacs"... Feb 11 16:53:49 volumio volumio[13678]: info: Loading plugin "volumiodiscovery"... Feb 11 16:53:49 volumio volumio[13678]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 11 16:53:49 volumio volumio[13678]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 16:53:49 volumio volumio[13678]: *** WARNING *** For more information see Feb 11 16:53:49 volumio volumio[13678]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 11 16:53:49 volumio volumio[13678]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 16:53:49 volumio volumio[13678]: *** WARNING *** For more information see Feb 11 16:53:49 volumio node[13678]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 11 16:53:49 volumio node[13678]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 16:53:49 volumio node[13678]: *** WARNING *** For more information see Feb 11 16:53:49 volumio node[13678]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 11 16:53:49 volumio node[13678]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 16:53:49 volumio node[13678]: *** WARNING *** For more information see Feb 11 16:53:49 volumio volumio[13678]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 11 16:53:49 volumio volumio[13678]: info: Discovery: Started advertising with name: Volumio Feb 11 16:53:49 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 16:53:49 volumio volumio[13678]: info: Loading plugin "spop"... Feb 11 16:53:51 volumio volumio[13678]: info: Loading plugin "ytcr"... Feb 11 16:53:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 11 16:53:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:53:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:53:51 volumio go-librespot[13768]: go-librespot daemon starting... Feb 11 16:53:51 volumio go-librespot[13769]: time="2026-02-11T16:53:51+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 16:53:51 volumio go-librespot[13769]: time="2026-02-11T16:53:51+07:00" level=debug msg="app state loaded" Feb 11 16:53:51 volumio go-librespot[13769]: time="2026-02-11T16:53:51+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 16:53:52 volumio go-librespot[13769]: time="2026-02-11T16:53: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 16:53:52 volumio go-librespot[13769]: time="2026-02-11T16:53:52+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 16:53:52 volumio go-librespot[13769]: time="2026-02-11T16:53:52+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 16:53:52 volumio go-librespot[13769]: time="2026-02-11T16:53:52+07:00" level=info msg="zeroconf server listening on port 44981" Feb 11 16:53:52 volumio go-librespot[13769]: time="2026-02-11T16:53:52+07:00" level=debug msg="obtained new client token: AAC9VG68R6DO8nAR1wP09+Dvw5dJva21WFZMJc0W0A0Ca0IWG8W8+SX02u9t57fauwxHvOnt1FiihP/sC/mfXvYw+nfMqkpUF5RTHULao9bQ2fw3xlpX5LQ6EhuL5Dm4tSItaZZBq+uDoAlPbk9OmPSrU/2d2Yj5beJF40+MrBclkOFL8TA8ht7+PBNFpxLks53mVmtVmQVtiNZROvVK98MbqPC0vQJ8tUYy/vIpxNbHKhcAEI/kjH5VzQ==" Feb 11 16:53:52 volumio go-librespot[13769]: time="2026-02-11T16:53:52+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 11 16:53:52 volumio go-librespot[13769]: time="2026-02-11T16:53:52+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 11 16:53:52 volumio go-librespot[13769]: time="2026-02-11T16:53:52+07:00" level=debug msg="completed keyexchange" Feb 11 16:53:52 volumio go-librespot[13769]: time="2026-02-11T16:53:52+07:00" level=debug msg="completed challenge" Feb 11 16:53:52 volumio go-librespot[13769]: time="2026-02-11T16:53:52+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 16:53:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 16:53:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 16:53:53 volumio volumio[13678]: info: Loading plugin "ytmusic"... Feb 11 16:53:54 volumio volumio-remote-updater[643]: [2026-02-11 16:53:54] [connect] Successful connection Feb 11 16:53:54 volumio volumio[13678]: info: Loading plugin "outputs"... Feb 11 16:53:55 volumio volumio[13678]: info: Loading plugin "albumart"... Feb 11 16:53:55 volumio volumio[13678]: info: Plugin example_plugin is not enabled Feb 11 16:53:55 volumio volumio[13678]: info: Loading plugin "inputs"... Feb 11 16:53:55 volumio volumio[13678]: info: Loading plugin "updater_comm"... Feb 11 16:53:55 volumio volumio[13678]: info: Plugin mpdemulation is not enabled Feb 11 16:53:55 volumio volumio[13678]: info: Loading plugin "rest_api"... Feb 11 16:53:55 volumio volumio[13678]: info: Loading plugin "websocket"... Feb 11 16:53:55 volumio volumio[13678]: info: Starting Socket.io Server version 1.7.4 Feb 11 16:53:55 volumio volumio[13678]: info: Loading plugin "RoonBridge"... Feb 11 16:53:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 11 16:53:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:53:55 volumio volumio[13678]: info: Applying required configuration parameters for plugin RoonBridge Feb 11 16:53:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:53:55 volumio volumio[13678]: info: Loading i18n strings for locale en Feb 11 16:53:55 volumio go-librespot[13801]: go-librespot daemon starting... Feb 11 16:53:55 volumio volumio[13678]: Updating browse sources language Feb 11 16:53:55 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 16:53:55 volumio go-librespot[13802]: time="2026-02-11T16:53:55+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 16:53:55 volumio go-librespot[13802]: time="2026-02-11T16:53:55+07:00" level=debug msg="app state loaded" Feb 11 16:53:55 volumio go-librespot[13802]: time="2026-02-11T16:53:55+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 16:53:56 volumio volumio[13791]: Forking 3 albumart workers Feb 11 16:53:56 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 16:53:56 volumio volumio[13678]: info: CoreCommandRouter::initPlayerControls Feb 11 16:53:56 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:56 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:56 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:56 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:56 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:56 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:56 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:56 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:56 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 16:53:56 volumio volumio[13678]: Express server listening on port 3000 Feb 11 16:53:56 volumio volumio[13678]: [Metrics] WebUI: 15s 977.88ms Feb 11 16:53:56 volumio volumio[13678]: info: CoreStateMachine::resetVolumioState Feb 11 16:53:56 volumio volumio[13678]: info: CoreStateMachine::getcurrentVolume Feb 11 16:53:56 volumio volumio[13678]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 16:53:56 volumio sudo[13844]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 16:53:56 volumio sudo[13844]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:53:56 volumio go-librespot[13802]: time="2026-02-11T16:53: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 11 16:53:56 volumio go-librespot[13802]: time="2026-02-11T16:53: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 11 16:53:56 volumio go-librespot[13802]: time="2026-02-11T16:53: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 11 16:53:56 volumio sudo[13844]: pam_unix(sudo:session): session closed for user root Feb 11 16:53:56 volumio go-librespot[13802]: time="2026-02-11T16:53:56+07:00" level=info msg="zeroconf server listening on port 42843" Feb 11 16:53:56 volumio sudo[13846]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 16:53:56 volumio sudo[13846]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:53:56 volumio sudo[13846]: pam_unix(sudo:session): session closed for user root Feb 11 16:53:56 volumio volumio[13678]: info: Volumio Network Manager: Network status updated: 1 Feb 11 16:53:56 volumio go-librespot[13802]: time="2026-02-11T16:53:56+07:00" level=debug msg="obtained new client token: AADr7VFSsYEZnk1LaQjMPAap0fN9TDh28XIx72OAcPOyBfrj/WyvYyfsPDx5qMv6OJpzvTqAeltX0PT4uINc9wPPQSoFmyjGNhpgIm4R0Xi1R9OyKXG3vGsKsHjOOrKYoaEJA/7MFnyvptaDdRoKlkQnpztHN232phve6ZEal5/l9/fxhNlLelzjPRtsmmk2Udz/taSt5zk/P+X80w6Sc/xKaN4gc0rrTRcNyRw1vgOh7ayCNayKXw2n8Q==" Feb 11 16:53:56 volumio go-librespot[13802]: time="2026-02-11T16:53:56+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 11 16:53:57 volumio volumio-remote-updater[643]: [2026-02-11 16:53:57] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770803634 101 Feb 11 16:53:57 volumio volumio[13678]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 11 16:53:57 volumio go-librespot[13802]: time="2026-02-11T16:53:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 11 16:53:57 volumio volumio[13678]: info: VolumeController:: Volume=100 Mute =false Feb 11 16:53:57 volumio volumio[13678]: info: CoreStateMachine::pushState Feb 11 16:53:57 volumio volumio[13678]: info: CorePlayQueue::getTrack 0 Feb 11 16:53:57 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 16:53:57 volumio volumio[13678]: info: CoreCommandRouter::volumioPushState Feb 11 16:53:57 volumio volumio[13678]: info: CoreStateMachine::updateTrackBlock Feb 11 16:53:57 volumio volumio[13678]: info: CorePlayQueue::getTrackBlock Feb 11 16:53:57 volumio volumio[13678]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 16:53:57 volumio go-librespot[13802]: time="2026-02-11T16:53:57+07:00" level=debug msg="completed keyexchange" Feb 11 16:53:57 volumio go-librespot[13802]: time="2026-02-11T16:53:57+07:00" level=debug msg="completed challenge" Feb 11 16:53:57 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 16:53:57 volumio volumio[13678]: info: Reloading queue from file Feb 11 16:53:57 volumio go-librespot[13802]: time="2026-02-11T16:53:57+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 16:53:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 16:53:57 volumio volumio[13678]: info: CoreStateMachine::setRepeat null single undefined Feb 11 16:53:57 volumio volumio[13678]: info: CoreStateMachine::pushState Feb 11 16:53:57 volumio volumio[13678]: info: CorePlayQueue::getTrack 0 Feb 11 16:53:57 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 16:53:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 16:53:57 volumio volumio[13678]: info: CoreCommandRouter::volumioPushState Feb 11 16:53:57 volumio volumio[13678]: info: CoreStateMachine::setRandom null Feb 11 16:53:57 volumio volumio[13678]: info: CoreStateMachine::pushState Feb 11 16:53:57 volumio volumio[13678]: info: CorePlayQueue::getTrack 0 Feb 11 16:53:57 volumio volumio[13678]: info: CoreCommandRouter::volumioPushState Feb 11 16:53:57 volumio volumio[13678]: info: Setting Device type: Raspberry PI Feb 11 16:53:57 volumio volumio[13678]: info: Completed loading Core Plugins Feb 11 16:53:57 volumio volumio[13678]: info: Preparing to generate the ALSA configuration file Feb 11 16:53:57 volumio volumio[13678]: info: VolumeController:: Volume=100 Mute =false Feb 11 16:53:57 volumio volumio[13678]: info: CoreStateMachine::pushState Feb 11 16:53:57 volumio volumio[13678]: info: CorePlayQueue::getTrack 0 Feb 11 16:53:57 volumio volumio[13678]: info: CoreCommandRouter::volumioPushState Feb 11 16:53:57 volumio sudo[13862]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 11 16:53:57 volumio sudo[13862]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:53:57 volumio volumio[13678]: info: Asound.conf file unchanged, so no further update is needed Feb 11 16:53:57 volumio volumio[13678]: info: Output device has changed, restarting MPD Feb 11 16:53:57 volumio volumio[13678]: info: Output device has changed, restarting Shairport Sync Feb 11 16:53:57 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:57 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 16:53:57 volumio sudo[13865]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 16:53:57 volumio sudo[13865]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:53:57 volumio sudo[13862]: pam_unix(sudo:session): session closed for user root Feb 11 16:53:57 volumio sudo[13865]: pam_unix(sudo:session): session closed for user root Feb 11 16:53:57 volumio sudo[13867]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 16:53:57 volumio sudo[13867]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:53:57 volumio volumio[13678]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 16:53:57 volumio volumio[13678]: info: ___________ START PLUGINS ___________ Feb 11 16:53:57 volumio volumio[13678]: info: ControllerMpd::onStart: Initializing MPD Feb 11 16:53:57 volumio volumio[13678]: info: Creating MPD Configuration file Feb 11 16:53:57 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 11 16:53:58 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 16:53:58 volumio volumio[13678]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 16:53:58 volumio volumio[13678]: info: [1770803638077] CoreMusicLibrary::Adding element Media Servers Feb 11 16:53:58 volumio sudo[13875]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 16:53:58 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 16:53:58 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 11 16:53:58 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 11 16:53:58 volumio systemd[1]: mpd.service: Consumed 7.198s CPU time. Feb 11 16:53:58 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 11 16:53:58 volumio sudo[13875]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:53:58 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 11 16:53:58 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 11 16:53:58 volumio sudo[13877]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 16:53:58 volumio sudo[13877]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:53:58 volumio sudo[13875]: pam_unix(sudo:session): session closed for user root Feb 11 16:53:58 volumio volumio[13678]: info: UPNP Browser: Client initialized successfully Feb 11 16:53:58 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:58 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 16:53:58 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 11 16:53:58 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 11 16:53:58 volumio volumio[13678]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 16:53:58 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:58 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 16:53:58 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 11 16:53:58 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 11 16:53:58 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 11 16:53:58 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 11 16:53:58 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 11 16:53:58 volumio volumio[13678]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 16:53:58 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 11 16:53:58 volumio volumio[13678]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 16:53:58 volumio volumio[13678]: info: [1770803638375] CoreMusicLibrary::Adding element Last_100 Feb 11 16:53:58 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 16:53:58 volumio volumio[13678]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 16:53:58 volumio volumio[13678]: info: [1770803638398] CoreMusicLibrary::Adding element Webradio Feb 11 16:53:58 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 16:53:58 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 11 16:53:58 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 16:53:58 volumio volumio[13678]: info: Initializing BBC Radios Feb 11 16:53:58 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 16:53:58 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 16:53:58 volumio volumio[13678]: info: Creating Spotify config file Feb 11 16:53:58 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:53:58 volumio sudo[13891]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 11 16:53:58 volumio sudo[13891]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 11 16:53:58 volumio sudo[13891]: pam_unix(sudo:session): session closed for user root Feb 11 16:53:59 volumio volumio[13808]: Starting albumart workers Feb 11 16:53:59 volumio volumio[13810]: Starting albumart workers Feb 11 16:53:59 volumio volumio[13809]: Starting albumart workers Feb 11 16:54:00 volumio volumio[13678]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 16:54:00 volumio volumio[13678]: info: [1770803640004] CoreMusicLibrary::Adding element YouTube Music Feb 11 16:54:00 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 16:54:00 volumio volumio[13678]: Cannot find translation for source YouTube Music Feb 11 16:54:00 volumio volumio[13678]: info: Volumio Calling Home Feb 11 16:54:00 volumio sudo[13911]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 11 16:54:00 volumio sudo[13911]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:54:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 11 16:54:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:54:00 volumio go-librespot[13916]: go-librespot daemon starting... Feb 11 16:54:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:54:00 volumio sudo[13911]: pam_unix(sudo:session): session closed for user root Feb 11 16:54:00 volumio go-librespot[13917]: time="2026-02-11T16:54:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 16:54:01 volumio volumio[13678]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 11 16:54:01 volumio volumio[13678]: info: Discovery: Found device Volumio Feb 11 16:54:01 volumio volumio[13678]: info: CoreCommandRouter::volumioGetState Feb 11 16:54:01 volumio volumio[13678]: info: CorePlayQueue::getTrack 0 Feb 11 16:54:01 volumio volumio[13678]: info: MPD Permissions set Feb 11 16:54:01 volumio volumio[13678]: info: MPD Permissions set Feb 11 16:54:01 volumio volumio[13678]: info: Upmpdcli Daemon Started Feb 11 16:54:01 volumio go-librespot[13917]: time="2026-02-11T16:54:01+07:00" level=info msg="zeroconf server listening on port 34251" Feb 11 16:54:01 volumio volumio[13678]: info: Spotify config file written Feb 11 16:54:01 volumio volumio[13678]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 11 16:54:01 volumio volumio[13678]: info: Discovery: Found device Volumio Feb 11 16:54:01 volumio volumio[13678]: info: CoreCommandRouter::volumioGetState Feb 11 16:54:01 volumio volumio[13678]: info: CorePlayQueue::getTrack 0 Feb 11 16:54:01 volumio volumio[13678]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 11 16:54:01 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:54:01 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:54:01 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:54:01 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:54:01 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:54:01 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:54:01 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:54:01 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:54:01 volumio sudo[13943]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 11 16:54:01 volumio sudo[13943]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:54:01 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 16:54:01 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:54:01 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:54:01 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:54:01 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:54:01 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:54:01 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:54:01 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:54:01 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:54:01 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:54:01 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 16:54:01 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 16:54:01 volumio volumio[13678]: info: No need to fix Spotify hosts Feb 11 16:54:01 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 11 16:54:01 volumio systemd[1]: go-librespot-daemon.service: Killing process 13918 (go-librespot) with signal SIGKILL. Feb 11 16:54:01 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 11 16:54:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:54:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:54:01 volumio go-librespot[13956]: go-librespot daemon starting... Feb 11 16:54:01 volumio sudo[13943]: pam_unix(sudo:session): session closed for user root Feb 11 16:54:01 volumio go-librespot[13957]: time="2026-02-11T16:54:01+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 16:54:01 volumio go-librespot[13957]: time="2026-02-11T16:54:01+07:00" level=debug msg="app state loaded" Feb 11 16:54:01 volumio go-librespot[13957]: time="2026-02-11T16:54:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 16:54:02 volumio go-librespot[13957]: time="2026-02-11T16:54:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 11 16:54:02 volumio go-librespot[13957]: time="2026-02-11T16:54:02+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 11 16:54:02 volumio go-librespot[13957]: time="2026-02-11T16:54:02+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 11 16:54:02 volumio go-librespot[13957]: time="2026-02-11T16:54:02+07:00" level=info msg="zeroconf server listening on port 44837" Feb 11 16:54:02 volumio volumio[13678]: info: Volumio called home Feb 11 16:54:02 volumio volumio[13678]: info: Starting Shairport Sync Feb 11 16:54:02 volumio volumio[13678]: info: Starting Shairport Sync Feb 11 16:54:02 volumio volumio[13678]: info: Starting Shairport Sync Feb 11 16:54:02 volumio sudo[13965]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 16:54:02 volumio sudo[13965]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:54:02 volumio sudo[13967]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 16:54:02 volumio sudo[13967]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:54:02 volumio go-librespot[13957]: time="2026-02-11T16:54:02+07:00" level=debug msg="obtained new client token: AACjRAoDs2qfkQppujB4ko8kqQKKpnt0Nh7iu/uuLRulXPsdkVOxWd7XDEREf8EvWYgsssCToOq1moEcemHAUvG8kX8Ozdj7BXcI9e9XyQXr72jsNRaC0S8n67uZmYjcOhIL1chJ77uOWimUcp8dJW3dT7RTgrEsKjRxGbJ5jBXaGF+JQAmrj4NpOW0FbUsfVb4kWhI8il+AdRpR4lL5hQ16gUA6qd7SLWOUVDTAF1M26RAztwcWyIJDfg==" Feb 11 16:54:02 volumio sudo[13970]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 16:54:02 volumio sudo[13970]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:54:02 volumio go-librespot[13957]: time="2026-02-11T16:54:02+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 11 16:54:02 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 11 16:54:02 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 11 16:54:02 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 16:54:02 volumio systemd[1]: shairport-sync.service: Consumed 2.312s CPU time. Feb 11 16:54:03 volumio go-librespot[13957]: time="2026-02-11T16:54:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 11 16:54:03 volumio volumio[13678]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 11 16:54:03 volumio volumio[13678]: SPOTIFY: BQCNbgcjd3SA9qhHJqPBaRMGuZYk1EpPgS1ZZWxKJcTr5NSGTURYjm9c6MybIeoW-aJV6rV43-U36RcucinfAlGcGLzvMuwPMyj8LKY1UfLO2dmFUF2_qDLaPnmDP-dxokCSt_rRXP1ly0DpToZ1CeiTln6BMl5SkYMM14HotOdPaQKQ4cm6QuHy2zNT0hCKl6q8M6e8hq3DjxJDlk22u7BGnCVT6MzyY-jfCLuHOAesqe9Ov5Na_h2BvTDVmSKKFpbTxBSRFpHvBBbNBwdppgdKvY-P8pqEAFR9bFNoLpebNU2lGOyvpTNV Feb 11 16:54:03 volumio volumio[13678]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 11 16:54:03 volumio volumio[13678]: info: New Spotify access token = BQCNbgcjd3SA9qhHJqPBaRMGuZYk1EpPgS1ZZWxKJcTr5NSGTURYjm9c6MybIeoW-aJV6rV43-U36RcucinfAlGcGLzvMuwPMyj8LKY1UfLO2dmFUF2_qDLaPnmDP-dxokCSt_rRXP1ly0DpToZ1CeiTln6BMl5SkYMM14HotOdPaQKQ4cm6QuHy2zNT0hCKl6q8M6e8hq3DjxJDlk22u7BGnCVT6MzyY-jfCLuHOAesqe9Ov5Na_h2BvTDVmSKKFpbTxBSRFpHvBBbNBwdppgdKvY-P8pqEAFR9bFNoLpebNU2lGOyvpTNV Feb 11 16:54:03 volumio volumio[13678]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 11 16:54:03 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 16:54:03 volumio sudo[13970]: pam_unix(sudo:session): session closed for user root Feb 11 16:54:03 volumio sudo[13965]: pam_unix(sudo:session): session closed for user root Feb 11 16:54:03 volumio sudo[13967]: pam_unix(sudo:session): session closed for user root Feb 11 16:54:03 volumio go-librespot[13957]: time="2026-02-11T16:54:03+07:00" level=debug msg="completed keyexchange" Feb 11 16:54:03 volumio go-librespot[13957]: time="2026-02-11T16:54:03+07:00" level=debug msg="completed challenge" Feb 11 16:54:03 volumio volumio[13678]: info: CoreCommandRouter::volumioGetState Feb 11 16:54:03 volumio volumio[13678]: info: CorePlayQueue::getTrack 0 Feb 11 16:54:03 volumio volumio[13678]: info: Shairport-Sync Started Feb 11 16:54:03 volumio volumio[13678]: Error adding Membership: Error: addMembership EINVAL Feb 11 16:54:03 volumio volumio[13678]: info: Shairport-Sync Started Feb 11 16:54:03 volumio volumio[13678]: info: Shairport-Sync Started Feb 11 16:54:03 volumio go-librespot[13957]: time="2026-02-11T16:54: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 11 16:54:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 16:54:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 16:54:03 volumio volumio[13678]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 11 16:54:03 volumio volumio[13678]: info: Spotify Successfully logged in Feb 11 16:54:03 volumio volumio[13678]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 16:54:03 volumio volumio[13678]: info: [1770803643601] CoreMusicLibrary::Adding element Spotify Feb 11 16:54:03 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 16:54:03 volumio volumio[13678]: Cannot find translation for source YouTube Music Feb 11 16:54:03 volumio volumio[13678]: Cannot find translation for source Spotify Feb 11 16:54:04 volumio volumio[13678]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 11 16:54:04 volumio volumio[13678]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 16:54:04 volumio volumio[13678]: info: VolumeController:: Volume=100 Mute =false Feb 11 16:54:04 volumio volumio[13678]: info: CoreCommandRouter::volumioGetState Feb 11 16:54:04 volumio volumio[13678]: info: CorePlayQueue::getTrack 0 Feb 11 16:54:04 volumio volumio[13678]: info: CoreStateMachine::pushState Feb 11 16:54:04 volumio volumio[13678]: info: CorePlayQueue::getTrack 0 Feb 11 16:54:04 volumio volumio[13678]: info: CoreCommandRouter::volumioPushState Feb 11 16:54:05 volumio volumio[13678]: info: go-librespot daemon successfully initialized Feb 11 16:54:05 volumio mpd[13906]: 2026-02-11T16:54:05 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 11 16:54:05 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 11 16:54:05 volumio sudo[13877]: pam_unix(sudo:session): session closed for user root Feb 11 16:54:05 volumio sudo[13867]: pam_unix(sudo:session): session closed for user root Feb 11 16:54:05 volumio volumio[13678]: error: MPD error: The expression evaluated to a falsy value: Feb 11 16:54:05 volumio volumio[13678]: assert.ok(self.idling) Feb 11 16:54:05 volumio volumio[13678]: error: The expression evaluated to a falsy value: Feb 11 16:54:05 volumio volumio[13678]: assert.ok(self.idling) Feb 11 16:54:05 volumio volumio[13678]: error: updateQueue error: null Feb 11 16:54:05 volumio volumio[13678]: info: MPD running with PID13906 Feb 11 16:54:05 volumio volumio[13678]: ,establishing connection Feb 11 16:54:06 volumio volumio[13678]: info: Completed starting Core Plugins Feb 11 16:54:06 volumio volumio[13678]: info: ------------------------------------------- Feb 11 16:54:06 volumio volumio[13678]: info: ----- MyVolumio plugins startup ---- Feb 11 16:54:06 volumio volumio[13678]: info: ------------------------------------------- Feb 11 16:54:06 volumio volumio[13678]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 11 16:54:06 volumio volumio[13678]: error: updateQueue error: null Feb 11 16:54:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 11 16:54:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:54:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:54:06 volumio go-librespot[14009]: go-librespot daemon starting... Feb 11 16:54:06 volumio go-librespot[14010]: time="2026-02-11T16:54:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 16:54:06 volumio go-librespot[14010]: time="2026-02-11T16:54:06+07:00" level=debug msg="app state loaded" Feb 11 16:54:06 volumio go-librespot[14010]: time="2026-02-11T16:54:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 16:54:07 volumio go-librespot[14010]: time="2026-02-11T16:54:07+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 16:54:07 volumio go-librespot[14010]: time="2026-02-11T16:54:07+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 16:54:07 volumio go-librespot[14010]: time="2026-02-11T16:54:07+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 16:54:07 volumio go-librespot[14010]: time="2026-02-11T16:54:07+07:00" level=info msg="zeroconf server listening on port 35005" Feb 11 16:54:07 volumio go-librespot[14010]: time="2026-02-11T16:54:07+07:00" level=debug msg="obtained new client token: AADBeE2sWbG39bePfCEJtnP2Jgs4LUTVS1PWxOILSL7VofvvXmTNFBQDtOhJIfJ4DqtwYF1OAC52M9c3Pu515QsRtlfSjsx1Ew18/b2nmEX9UCiquTs/Uyy5aadYarlhC9vWbXI4QpYN8nFqzGW1mZ/GbLMGi+gTtf4PE1yUolI32CONKrLLpNJzZ0wUeKG5bJQNepoqpR8EYDlFBXRGRXWxks1fQCEcYw8PRMm/fNZqtRxCNrVXJ/hc1Q==" Feb 11 16:54:07 volumio go-librespot[14010]: time="2026-02-11T16:54:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 16:54:07 volumio go-librespot[14010]: time="2026-02-11T16:54:07+07:00" level=debug msg="completed keyexchange" Feb 11 16:54:07 volumio go-librespot[14010]: time="2026-02-11T16:54:07+07:00" level=debug msg="completed challenge" Feb 11 16:54:07 volumio go-librespot[14010]: time="2026-02-11T16:54: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 11 16:54:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 16:54:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 16:54:08 volumio volumio[13678]: info: Initializing connection to go-librespot Websocket Feb 11 16:54:08 volumio volumio[13678]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 16:54:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 11 16:54:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:54:10 volumio volumio[13678]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 11 16:54:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:54:10 volumio go-librespot[14018]: go-librespot daemon starting... Feb 11 16:54:10 volumio go-librespot[14019]: time="2026-02-11T16:54:10+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 16:54:10 volumio go-librespot[14019]: time="2026-02-11T16:54:10+07:00" level=debug msg="app state loaded" Feb 11 16:54:10 volumio go-librespot[14019]: time="2026-02-11T16:54:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 16:54:11 volumio go-librespot[14019]: time="2026-02-11T16:54:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 16:54:11 volumio go-librespot[14019]: time="2026-02-11T16:54:11+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 16:54:11 volumio go-librespot[14019]: time="2026-02-11T16:54:11+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 16:54:11 volumio go-librespot[14019]: time="2026-02-11T16:54:11+07:00" level=info msg="zeroconf server listening on port 38431" Feb 11 16:54:11 volumio volumio[13678]: info: Initializing connection to go-librespot Websocket Feb 11 16:54:11 volumio go-librespot[14019]: time="2026-02-11T16:54:11+07:00" level=debug msg="new websocket client" Feb 11 16:54:11 volumio volumio[13678]: info: Connection to go-librespot Websocket established Feb 11 16:54:11 volumio go-librespot[14019]: time="2026-02-11T16:54:11+07:00" level=debug msg="obtained new client token: AADCMK6uncuXw2WtTrLt8mD+abRpV3rt75wIqstPLqO8bEtHZFtuTVA0dUQPsYMkJP7hSZgtJVu5ZTlvzgaZe10nLpD8XoyXDvBWvhMgdWhIi98nZyQp9quv/OTvDpvwGmjWOoo04af/GOngdlqv4vWcIem0oFYqTl9TtAtKwxuA9fPoENjNm/cA+QM4xBGgeuJzxH/25HPv54a88nD6lmfMKwFWPQt9cS0YRB2jnFEOOnzf1s/w/y/vFw==" Feb 11 16:54:11 volumio go-librespot[14019]: time="2026-02-11T16:54:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 16:54:11 volumio go-librespot[14019]: time="2026-02-11T16:54:11+07:00" level=debug msg="completed keyexchange" Feb 11 16:54:11 volumio go-librespot[14019]: time="2026-02-11T16:54:11+07:00" level=debug msg="completed challenge" Feb 11 16:54:11 volumio go-librespot[14019]: time="2026-02-11T16:54:11+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 16:54:11 volumio volumio[13678]: info: Connection to go-librespot Websocket closed Feb 11 16:54:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 16:54:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 16:54:14 volumio volumio[13678]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 11 16:54:14 volumio volumio[13678]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 11 16:54:14 volumio volumio[13678]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 11 16:54:14 volumio volumio[13678]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 11 16:54:14 volumio volumio[13678]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 11 16:54:14 volumio volumio[13678]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 11 16:54:14 volumio volumio[13678]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 11 16:54:14 volumio volumio[13678]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 11 16:54:14 volumio volumio[13678]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 11 16:54:14 volumio volumio[13678]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 11 16:54:14 volumio volumio[13678]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 11 16:54:14 volumio volumio[13678]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 11 16:54:14 volumio volumio[13678]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 11 16:54:14 volumio volumio[13678]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 11 16:54:14 volumio volumio[13678]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 11 16:54:14 volumio volumio[13678]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 11 16:54:14 volumio volumio[13678]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 11 16:54:14 volumio volumio[13678]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 11 16:54:14 volumio volumio[13678]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 11 16:54:14 volumio volumio[13678]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 11 16:54:14 volumio volumio[13678]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 11 16:54:14 volumio volumio[13678]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 11 16:54:14 volumio volumio[13678]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 11 16:54:14 volumio volumio[13678]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 11 16:54:14 volumio volumio[13678]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 11 16:54:14 volumio volumio[13678]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 11 16:54:14 volumio volumio[13678]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 11 16:54:14 volumio volumio[13678]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 11 16:54:14 volumio volumio[13678]: info: Adding plugin bluetooth to MyMusic Plugins Feb 11 16:54:14 volumio volumio[13678]: info: Adding plugin multiroom to MyMusic Plugins Feb 11 16:54:14 volumio volumio[13678]: info: Adding plugin metavolumio to MyMusic Plugins Feb 11 16:54:14 volumio volumio[13678]: info: Adding plugin cd_controller to MyMusic Plugins Feb 11 16:54:14 volumio volumio[13678]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 11 16:54:14 volumio volumio[13678]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 11 16:54:14 volumio volumio[13678]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 11 16:54:14 volumio volumio[13678]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 11 16:54:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 11 16:54:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:54:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:54:15 volumio go-librespot[14034]: go-librespot daemon starting... Feb 11 16:54:15 volumio go-librespot[14041]: time="2026-02-11T16:54:15+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 16:54:15 volumio go-librespot[14041]: time="2026-02-11T16:54:15+07:00" level=debug msg="app state loaded" Feb 11 16:54:15 volumio go-librespot[14041]: time="2026-02-11T16:54:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 16:54:15 volumio go-librespot[14041]: time="2026-02-11T16:54: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 16:54:15 volumio go-librespot[14041]: time="2026-02-11T16:54:15+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 16:54:15 volumio go-librespot[14041]: time="2026-02-11T16:54:15+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 16:54:15 volumio go-librespot[14041]: time="2026-02-11T16:54:15+07:00" level=info msg="zeroconf server listening on port 37165" Feb 11 16:54:15 volumio go-librespot[14041]: time="2026-02-11T16:54:15+07:00" level=debug msg="obtained new client token: AABoqywi024/vBMJxTQsfpognOZ8hLCuQYfCdTI7TCDt9rhhWSEsiElRxe1Xj8bDoy3YCZqQnxI4siwFzfG7ecgJ2deBq/wkImvvkKDjH8ZwMrvZE6sDFl8Ftanuhb4YwolNKRMD3uP9Vvxy6fbkaKsyryCYNeMFedUkYXko8d7zh3umj8cQg6yAHr8DDAw1fAzLqMbeaOEy2a2jf+29Xum0uLCRz5ckwDP3cPGHZqHJ8m2uAdus1i87Dg==" Feb 11 16:54:16 volumio go-librespot[14041]: time="2026-02-11T16:54:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 16:54:16 volumio go-librespot[14041]: time="2026-02-11T16:54:16+07:00" level=debug msg="completed keyexchange" Feb 11 16:54:16 volumio go-librespot[14041]: time="2026-02-11T16:54:16+07:00" level=debug msg="completed challenge" Feb 11 16:54:16 volumio go-librespot[14041]: time="2026-02-11T16:54: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 11 16:54:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 16:54:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 16:54:16 volumio volumio[13678]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 11 16:54:16 volumio volumio[13678]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 11 16:54:16 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 16:54:16 volumio volumio[13678]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 16:54:16 volumio volumio[13678]: info: Starting MyVolumio Remote Streaming Endpoints Feb 11 16:54:16 volumio volumio[13678]: info: MyVolumio login type: Token Feb 11 16:54:16 volumio volumio[13678]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 11 16:54:16 volumio volumio[13678]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 11 16:54:18 volumio volumio[13678]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 11 16:54:18 volumio volumio[13678]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 11 16:54:18 volumio volumio[13678]: info: Streaming services startup Feb 11 16:54:18 volumio volumio[13678]: info: Starting Streaming Daemon Feb 11 16:54:18 volumio sudo[14049]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 11 16:54:18 volumio sudo[14049]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:54:18 volumio volumio[13678]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 11 16:54:18 volumio sudo[14049]: pam_unix(sudo:session): session closed for user root Feb 11 16:54:18 volumio volumio[13678]: info: Getting Spotify volume Feb 11 16:54:18 volumio volumio[13678]: info: Initializing connection to go-librespot Websocket Feb 11 16:54:18 volumio volumio[13678]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 16:54:18 volumio volumio[13678]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 16:54:18 volumio volumio[13678]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 11 16:54:18 volumio volumio[13678]: errno: -111, Feb 11 16:54:18 volumio volumio[13678]: code: 'ECONNREFUSED', Feb 11 16:54:18 volumio volumio[13678]: syscall: 'connect', Feb 11 16:54:18 volumio volumio[13678]: address: '127.0.0.1', Feb 11 16:54:18 volumio volumio[13678]: port: 9879, Feb 11 16:54:18 volumio volumio[13678]: response: undefined Feb 11 16:54:18 volumio volumio[13678]: } Feb 11 16:54:18 volumio volumio[13678]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 16:54:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 11 16:54:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:54:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 16:54:19 volumio go-librespot[14068]: go-librespot daemon starting... Feb 11 16:54:19 volumio go-librespot[14069]: time="2026-02-11T16:54:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 16:54:19 volumio go-librespot[14069]: time="2026-02-11T16:54:19+07:00" level=debug msg="app state loaded" Feb 11 16:54:19 volumio go-librespot[14069]: time="2026-02-11T16:54:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 16:54:19 volumio go-librespot[14069]: time="2026-02-11T16:54:19+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 16:54:19 volumio go-librespot[14069]: time="2026-02-11T16:54:19+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 16:54:19 volumio go-librespot[14069]: time="2026-02-11T16:54:19+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 16:54:19 volumio go-librespot[14069]: time="2026-02-11T16:54:19+07:00" level=info msg="zeroconf server listening on port 38969" Feb 11 16:54:20 volumio sudo[14078]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-11 16:53' Feb 11 16:54:20 volumio sudo[14078]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 16:54:20 volumio go-librespot[14069]: time="2026-02-11T16:54:20+07:00" level=debug msg="obtained new client token: AADXkbboEG5jOODwHlm9NfUON5JHzbw8znwTMDBeqDHUfm04ZHA2mVaGDUb9ONlghbQ3bEabU8YWg4Q+xwkl8+oloRQpJC4KrrBGGKhFjUkOYv800FtBBc9D9c/mRAlRgECHzXQ4DXeVGTeaetgVA60iftfEUpa6nOuK/eJkXTs0c4p9KS+cIhQzTqC5aje/PyzlU/hWXBpftS7csu0iaxXbO2tMNzHLObddwksrXQkoxnkrMm6QdzM=" Feb 11 16:54:20 volumio go-librespot[14069]: time="2026-02-11T16:54:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 16:54:20 volumio go-librespot[14069]: time="2026-02-11T16:54:20+07:00" level=debug msg="completed keyexchange" Feb 11 16:54:20 volumio go-librespot[14069]: time="2026-02-11T16:54:20+07:00" level=debug msg="completed challenge" Feb 11 16:54:20 volumio go-librespot[14069]: time="2026-02-11T16:54: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 11 16:54:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 16:54:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. 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"