Feb 09 22:31:00 volumio sudo[13651]: pam_unix(sudo:session): session closed for user root Feb 09 22:31:02 volumio volumio[13598]: info: Starting UPNP Browser Feb 09 22:31:02 volumio volumio[13598]: info: Loading plugin "alarm-clock"... Feb 09 22:31:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 36. Feb 09 22:31:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:31:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:31:02 volumio go-librespot[13676]: go-librespot daemon starting... Feb 09 22:31:02 volumio go-librespot[13677]: time="2026-02-09T22:31:02+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 22:31:02 volumio go-librespot[13677]: time="2026-02-09T22:31:02+07:00" level=debug msg="app state loaded" Feb 09 22:31:02 volumio go-librespot[13677]: time="2026-02-09T22:31:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 22:31:02 volumio volumio[13598]: info: Loading plugin "airplay_emulation"... Feb 09 22:31:02 volumio volumio[13598]: info: Starting Shairport Sync Feb 09 22:31:02 volumio volumio[13598]: info: Loading plugin "last_100"... Feb 09 22:31:02 volumio volumio[13598]: info: Loading plugin "webradio"... Feb 09 22:31:02 volumio volumio[13598]: info: Loading plugin "i2s_dacs"... Feb 09 22:31:02 volumio volumio[13598]: info: Loading plugin "volumiodiscovery"... Feb 09 22:31:02 volumio volumio[13598]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 22:31:02 volumio volumio[13598]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 22:31:02 volumio volumio[13598]: *** WARNING *** For more information see Feb 09 22:31:02 volumio volumio[13598]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 22:31:02 volumio volumio[13598]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 22:31:02 volumio volumio[13598]: *** WARNING *** For more information see Feb 09 22:31:02 volumio node[13598]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 22:31:02 volumio node[13598]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 22:31:02 volumio node[13598]: *** WARNING *** For more information see Feb 09 22:31:02 volumio node[13598]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 22:31:02 volumio node[13598]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 22:31:02 volumio node[13598]: *** WARNING *** For more information see Feb 09 22:31:02 volumio volumio[13598]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 09 22:31:02 volumio volumio[13598]: info: Discovery: Started advertising with name: Volumio Feb 09 22:31:02 volumio go-librespot[13677]: time="2026-02-09T22:31:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 22:31:02 volumio go-librespot[13677]: time="2026-02-09T22:31:02+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 22:31:02 volumio go-librespot[13677]: time="2026-02-09T22:31:02+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 22:31:02 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 22:31:02 volumio volumio[13598]: info: Loading plugin "spop"... Feb 09 22:31:02 volumio go-librespot[13677]: time="2026-02-09T22:31:02+07:00" level=info msg="zeroconf server listening on port 44353" Feb 09 22:31:02 volumio go-librespot[13677]: time="2026-02-09T22:31:02+07:00" level=debug msg="obtained new client token: AABpTeeCa/lNqE0wOh/Xbr7kAUJe7yXq8vZFtMzTEJ+JF3ans6OBb489MVyOOzVZHotuG4OuMbKsvdjMaUZlpxsug2ueyK5/omCWv9F55c4/TvltdCi9vpnqc1UvI4ZMLprKtMHHLgVDDGtfKeF1Pps8Yga7LwgAwz3k4AWRIpftw5nmcPDq3iNzmYgN8yK2dup32FSkNLcfwy/uGjKJRN7Gsu0rAKVlbPB9lgM7dAlmVVJs5ddRIF1/Ig==" Feb 09 22:31:03 volumio go-librespot[13677]: time="2026-02-09T22:31:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 22:31:03 volumio go-librespot[13677]: time="2026-02-09T22:31:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 09 22:31:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 22:31:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 22:31:04 volumio volumio[13598]: info: Loading plugin "ytcr"... Feb 09 22:31:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 37. Feb 09 22:31:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:31:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:31:06 volumio go-librespot[13687]: go-librespot daemon starting... Feb 09 22:31:06 volumio go-librespot[13688]: time="2026-02-09T22:31:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 22:31:06 volumio go-librespot[13688]: time="2026-02-09T22:31:06+07:00" level=debug msg="app state loaded" Feb 09 22:31:06 volumio go-librespot[13688]: time="2026-02-09T22:31:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 22:31:07 volumio go-librespot[13688]: time="2026-02-09T22:31:07+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 22:31:07 volumio go-librespot[13688]: time="2026-02-09T22:31:07+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 22:31:07 volumio go-librespot[13688]: time="2026-02-09T22:31:07+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 22:31:07 volumio go-librespot[13688]: time="2026-02-09T22:31:07+07:00" level=info msg="zeroconf server listening on port 33761" Feb 09 22:31:07 volumio go-librespot[13688]: time="2026-02-09T22:31:07+07:00" level=debug msg="obtained new client token: AADlQRJBbk0ysXkL6eLARNkVwc3IxWhS0OwknwChm1sUjgJYZxYLwv1rRytymPl5toXQW4NTvzx3EjiB3+W5pQEsY9Ae8inonasSd7c+iHiy+kTZpnX7DBBMAPjgIDTfSn/FMT1UWxFV+9Zc6uFpuEcW36uyT5jCcyf6rXYAN6YcEICE77xFc9ESyIvndFVtBscNQ64FJ5d5cO/eoD28nDR/d3MKI7f5f5PxkAlGWRGWzCM5tRTs3L0=" Feb 09 22:31:07 volumio volumio[13598]: info: Loading plugin "ytmusic"... Feb 09 22:31:07 volumio go-librespot[13688]: time="2026-02-09T22:31:07+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 09 22:31:07 volumio go-librespot[13688]: time="2026-02-09T22:31:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 09 22:31:07 volumio go-librespot[13688]: time="2026-02-09T22:31:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 09 22:31:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 22:31:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 22:31:08 volumio volumio-remote-updater[643]: [2026-02-09 22:31:08] [connect] Successful connection Feb 09 22:31:08 volumio volumio[13598]: info: Loading plugin "outputs"... Feb 09 22:31:08 volumio volumio[13598]: info: Loading plugin "albumart"... Feb 09 22:31:08 volumio volumio[13598]: info: Plugin example_plugin is not enabled Feb 09 22:31:08 volumio volumio[13598]: info: Loading plugin "inputs"... Feb 09 22:31:08 volumio volumio[13598]: info: Loading plugin "updater_comm"... Feb 09 22:31:08 volumio volumio[13598]: info: Plugin mpdemulation is not enabled Feb 09 22:31:08 volumio volumio[13598]: info: Loading plugin "rest_api"... Feb 09 22:31:08 volumio volumio[13598]: info: Loading plugin "websocket"... Feb 09 22:31:08 volumio volumio[13598]: info: Starting Socket.io Server version 1.7.4 Feb 09 22:31:08 volumio volumio[13598]: info: Loading plugin "RoonBridge"... Feb 09 22:31:09 volumio volumio[13598]: info: Applying required configuration parameters for plugin RoonBridge Feb 09 22:31:09 volumio volumio[13598]: info: Loading i18n strings for locale en Feb 09 22:31:09 volumio volumio[13598]: Updating browse sources language Feb 09 22:31:09 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 22:31:09 volumio volumio[13709]: Forking 3 albumart workers Feb 09 22:31:09 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 22:31:09 volumio volumio[13598]: info: CoreCommandRouter::initPlayerControls Feb 09 22:31:09 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:09 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:09 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:09 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:09 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:09 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:09 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:09 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:09 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 22:31:09 volumio volumio[13598]: Express server listening on port 3000 Feb 09 22:31:09 volumio volumio[13598]: [Metrics] WebUI: 16s 110.13ms Feb 09 22:31:09 volumio volumio[13598]: info: CoreStateMachine::resetVolumioState Feb 09 22:31:09 volumio volumio[13598]: info: CoreStateMachine::getcurrentVolume Feb 09 22:31:09 volumio volumio[13598]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 22:31:09 volumio sudo[13753]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 22:31:09 volumio sudo[13753]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:31:09 volumio sudo[13751]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 22:31:09 volumio sudo[13751]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:31:09 volumio sudo[13753]: pam_unix(sudo:session): session closed for user root Feb 09 22:31:09 volumio sudo[13751]: pam_unix(sudo:session): session closed for user root Feb 09 22:31:09 volumio volumio[13598]: info: Volumio Network Manager: Network status updated: 1 Feb 09 22:31:10 volumio volumio[13598]: info: VolumeController:: Volume=100 Mute =false Feb 09 22:31:10 volumio volumio[13598]: info: CoreStateMachine::pushState Feb 09 22:31:10 volumio volumio[13598]: info: CorePlayQueue::getTrack 0 Feb 09 22:31:10 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 22:31:10 volumio volumio[13598]: info: CoreCommandRouter::volumioPushState Feb 09 22:31:10 volumio volumio[13598]: info: CoreStateMachine::updateTrackBlock Feb 09 22:31:10 volumio volumio[13598]: info: CorePlayQueue::getTrackBlock Feb 09 22:31:10 volumio volumio[13598]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 22:31:10 volumio volumio-remote-updater[643]: [2026-02-09 22:31:10] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770651068 101 Feb 09 22:31:10 volumio volumio[13598]: 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 09 22:31:10 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 22:31:10 volumio volumio[13598]: info: Reloading queue from file Feb 09 22:31:10 volumio volumio[13598]: info: CoreStateMachine::setRepeat null single undefined Feb 09 22:31:10 volumio volumio[13598]: info: CoreStateMachine::pushState Feb 09 22:31:10 volumio volumio[13598]: info: CorePlayQueue::getTrack 0 Feb 09 22:31:10 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 22:31:10 volumio volumio[13598]: info: CoreCommandRouter::volumioPushState Feb 09 22:31:10 volumio volumio[13598]: info: CoreStateMachine::setRandom null Feb 09 22:31:10 volumio volumio[13598]: info: CoreStateMachine::pushState Feb 09 22:31:10 volumio volumio[13598]: info: CorePlayQueue::getTrack 0 Feb 09 22:31:10 volumio volumio[13598]: info: CoreCommandRouter::volumioPushState Feb 09 22:31:10 volumio volumio[13598]: info: Setting Device type: Raspberry PI Feb 09 22:31:10 volumio volumio[13598]: info: Completed loading Core Plugins Feb 09 22:31:10 volumio volumio[13598]: info: Preparing to generate the ALSA configuration file Feb 09 22:31:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38. Feb 09 22:31:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:31:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:31:10 volumio go-librespot[13768]: go-librespot daemon starting... Feb 09 22:31:10 volumio volumio[13598]: info: VolumeController:: Volume=100 Mute =false Feb 09 22:31:10 volumio volumio[13598]: info: CoreStateMachine::pushState Feb 09 22:31:10 volumio volumio[13598]: info: CorePlayQueue::getTrack 0 Feb 09 22:31:10 volumio volumio[13598]: info: CoreCommandRouter::volumioPushState Feb 09 22:31:10 volumio go-librespot[13770]: time="2026-02-09T22:31:10+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 22:31:10 volumio go-librespot[13770]: time="2026-02-09T22:31:10+07:00" level=debug msg="app state loaded" Feb 09 22:31:10 volumio go-librespot[13770]: time="2026-02-09T22:31:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 22:31:10 volumio volumio[13598]: info: Asound.conf file unchanged, so no further update is needed Feb 09 22:31:10 volumio volumio[13598]: info: Output device has changed, restarting MPD Feb 09 22:31:10 volumio sudo[13777]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 09 22:31:10 volumio sudo[13777]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:31:10 volumio volumio[13598]: info: Output device has changed, restarting Shairport Sync Feb 09 22:31:10 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:10 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 22:31:10 volumio sudo[13779]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 22:31:10 volumio sudo[13779]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:31:10 volumio sudo[13777]: pam_unix(sudo:session): session closed for user root Feb 09 22:31:10 volumio sudo[13779]: pam_unix(sudo:session): session closed for user root Feb 09 22:31:10 volumio sudo[13782]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 22:31:10 volumio sudo[13782]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:31:11 volumio volumio[13598]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 22:31:11 volumio volumio[13598]: info: ___________ START PLUGINS ___________ Feb 09 22:31:11 volumio volumio[13598]: info: ControllerMpd::onStart: Initializing MPD Feb 09 22:31:11 volumio volumio[13598]: info: Creating MPD Configuration file Feb 09 22:31:11 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 09 22:31:11 volumio sudo[13792]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 22:31:11 volumio sudo[13792]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:31:11 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 09 22:31:11 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 22:31:11 volumio systemd[1]: mpd.service: Consumed 7.192s CPU time. Feb 09 22:31:11 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 09 22:31:11 volumio sudo[13792]: pam_unix(sudo:session): session closed for user root Feb 09 22:31:11 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 22:31:11 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 22:31:11 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 22:31:11 volumio volumio[13598]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 22:31:11 volumio volumio[13598]: info: [1770651071297] CoreMusicLibrary::Adding element Media Servers Feb 09 22:31:11 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 22:31:11 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 22:31:11 volumio sudo[13794]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 22:31:11 volumio sudo[13794]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:31:11 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 22:31:11 volumio go-librespot[13770]: time="2026-02-09T22:31:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 22:31:11 volumio go-librespot[13770]: time="2026-02-09T22:31:11+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 22:31:11 volumio go-librespot[13770]: time="2026-02-09T22:31:11+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 22:31:11 volumio volumio[13598]: info: UPNP Browser: Client initialized successfully Feb 09 22:31:11 volumio go-librespot[13770]: time="2026-02-09T22:31:11+07:00" level=info msg="zeroconf server listening on port 40969" Feb 09 22:31:11 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:11 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 22:31:11 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 09 22:31:11 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 22:31:11 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 09 22:31:11 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 22:31:11 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 22:31:11 volumio volumio[13598]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 22:31:11 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:11 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 22:31:11 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 22:31:11 volumio volumio[13598]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 22:31:11 volumio volumio[13598]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 22:31:11 volumio volumio[13598]: info: [1770651071612] CoreMusicLibrary::Adding element Last_100 Feb 09 22:31:11 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 22:31:11 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 22:31:11 volumio volumio[13598]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 22:31:11 volumio go-librespot[13770]: time="2026-02-09T22:31:11+07:00" level=debug msg="obtained new client token: AADxkChDdHUgnPa1eFH9I10tpRWKuFLc0HaRfWT/naQQZlaVqMC+w91QJcyevqIABrAWeeYDZ+HqDMGEaspDXIKde6vY/jChwlfuyYlVW2HkZK0fsOlnf7OMYdGdBgKRzcBLGpVftw3lHqLXP75rDXxs4jeq4dKNz0DSgk6qPL4IgWVPRuTj+8UVujUofFxhuaUqNo/GjIEqoyBLMmoGToD5tR1NqBtHIxc9B5ZaNILemm7E53sp4410tA==" Feb 09 22:31:11 volumio volumio[13598]: info: [1770651071637] CoreMusicLibrary::Adding element Webradio Feb 09 22:31:11 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 22:31:11 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 22:31:11 volumio volumio[13598]: info: Initializing BBC Radios Feb 09 22:31:11 volumio go-librespot[13770]: time="2026-02-09T22:31:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 22:31:11 volumio go-librespot[13770]: time="2026-02-09T22:31:11+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 09 22:31:11 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 22:31:11 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 22:31:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 22:31:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 22:31:11 volumio volumio[13598]: info: Creating Spotify config file Feb 09 22:31:11 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:12 volumio sudo[13808]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 09 22:31:12 volumio sudo[13808]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 09 22:31:12 volumio sudo[13808]: pam_unix(sudo:session): session closed for user root Feb 09 22:31:12 volumio volumio[13720]: Starting albumart workers Feb 09 22:31:12 volumio volumio[13598]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 22:31:12 volumio volumio[13598]: info: [1770651072926] CoreMusicLibrary::Adding element YouTube Music Feb 09 22:31:12 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 22:31:12 volumio volumio[13598]: Cannot find translation for source YouTube Music Feb 09 22:31:12 volumio volumio[13598]: info: Volumio Calling Home Feb 09 22:31:13 volumio sudo[13825]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 09 22:31:13 volumio sudo[13825]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:31:13 volumio sudo[13825]: pam_unix(sudo:session): session closed for user root Feb 09 22:31:13 volumio volumio[13721]: Starting albumart workers Feb 09 22:31:13 volumio volumio[13719]: Starting albumart workers Feb 09 22:31:13 volumio volumio[13598]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 09 22:31:13 volumio volumio[13598]: info: Discovery: Found device Volumio Feb 09 22:31:13 volumio volumio[13598]: info: CoreCommandRouter::volumioGetState Feb 09 22:31:13 volumio volumio[13598]: info: CorePlayQueue::getTrack 0 Feb 09 22:31:13 volumio volumio[13598]: info: MPD Permissions set Feb 09 22:31:13 volumio volumio[13598]: info: MPD Permissions set Feb 09 22:31:13 volumio volumio[13598]: info: Upmpdcli Daemon Started Feb 09 22:31:13 volumio volumio[13598]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 09 22:31:13 volumio volumio[13598]: info: Discovery: Found device Volumio Feb 09 22:31:13 volumio volumio[13598]: info: CoreCommandRouter::volumioGetState Feb 09 22:31:13 volumio volumio[13598]: info: CorePlayQueue::getTrack 0 Feb 09 22:31:13 volumio volumio[13598]: info: Volumio called home Feb 09 22:31:13 volumio volumio[13598]: info: Spotify config file written Feb 09 22:31:13 volumio sudo[13831]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 09 22:31:13 volumio sudo[13831]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:31:14 volumio volumio[13598]: 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 09 22:31:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:31:14 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:14 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:14 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:14 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:14 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:14 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:14 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:14 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:31:14 volumio go-librespot[13833]: go-librespot daemon starting... Feb 09 22:31:14 volumio sudo[13831]: pam_unix(sudo:session): session closed for user root Feb 09 22:31:14 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 22:31:14 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:14 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:14 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:14 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:14 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:14 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:14 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:14 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:14 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:14 volumio go-librespot[13836]: time="2026-02-09T22:31:14+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 22:31:14 volumio go-librespot[13836]: time="2026-02-09T22:31:14+07:00" level=debug msg="app state loaded" Feb 09 22:31:14 volumio go-librespot[13836]: time="2026-02-09T22:31:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 22:31:14 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 22:31:14 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:14 volumio volumio[13598]: info: No need to fix Spotify hosts Feb 09 22:31:15 volumio go-librespot[13836]: time="2026-02-09T22:31: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 09 22:31:15 volumio go-librespot[13836]: time="2026-02-09T22:31: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 09 22:31:15 volumio go-librespot[13836]: time="2026-02-09T22:31: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 09 22:31:15 volumio go-librespot[13836]: time="2026-02-09T22:31:15+07:00" level=info msg="zeroconf server listening on port 45689" Feb 09 22:31:15 volumio go-librespot[13836]: time="2026-02-09T22:31:15+07:00" level=debug msg="obtained new client token: AAAIlzbs6SBxzElww/DwFCiTNkEh95OpkU26agDNUsweIYP5zgtRTSs4Emf1zBVvi69TRiFEQml7CVYXjx96eUBKSYDvdMT5JS68abEd9LQQawMkWoP2NImVXQUkJwUCr3K1sHbFUvGg9rY+tBjZ+Bjz2EhOnsASLNTmbP47chg38ZphQZZyyV5DCcM6/XJ6E12hpvSoLtefAl5ziEwz+3Enqcf0H+Q7ghpCTBnUUgLMrOZdryGee32BEg==" Feb 09 22:31:15 volumio go-librespot[13836]: time="2026-02-09T22:31:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 22:31:15 volumio go-librespot[13836]: time="2026-02-09T22:31:15+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 09 22:31:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 22:31:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 22:31:15 volumio volumio[13598]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 09 22:31:15 volumio volumio[13598]: SPOTIFY: BQB-IUIF_mxELKJ96fmv1M6yMZ8ReozY7Se4ftjoqvrBnZXiehFyWue_7xdaN15FgAShnUn_96WqNhmM9ujcAi6kuCI3izZdwA2vQfSIX_9tMMmT2hdNlq2fqEPVNj0vwA9lMt1RucmzmeNqxYfdbvMwKaoi9ddCwqzaewng-cuJu6QttSjYzZKCz8kmAIA6E3YvS9b7oHa8umS627B86URnWt2Ad9j3VH2cOuwaMPYnNm0pxaPTXqyjtzaLK9_oUCQ6S5yjsfOmTnJ9QHdlk1-pyZC68BGwYgKfZZgLO92T3ePxvSQpXmJd Feb 09 22:31:15 volumio volumio[13598]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 09 22:31:15 volumio volumio[13598]: info: New Spotify access token = BQB-IUIF_mxELKJ96fmv1M6yMZ8ReozY7Se4ftjoqvrBnZXiehFyWue_7xdaN15FgAShnUn_96WqNhmM9ujcAi6kuCI3izZdwA2vQfSIX_9tMMmT2hdNlq2fqEPVNj0vwA9lMt1RucmzmeNqxYfdbvMwKaoi9ddCwqzaewng-cuJu6QttSjYzZKCz8kmAIA6E3YvS9b7oHa8umS627B86URnWt2Ad9j3VH2cOuwaMPYnNm0pxaPTXqyjtzaLK9_oUCQ6S5yjsfOmTnJ9QHdlk1-pyZC68BGwYgKfZZgLO92T3ePxvSQpXmJd Feb 09 22:31:15 volumio volumio[13598]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 09 22:31:15 volumio volumio[13598]: info: Starting Shairport Sync Feb 09 22:31:15 volumio volumio[13598]: info: Starting Shairport Sync Feb 09 22:31:15 volumio volumio[13598]: info: Starting Shairport Sync Feb 09 22:31:15 volumio sudo[13871]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 22:31:15 volumio sudo[13871]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:31:15 volumio sudo[13873]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 22:31:15 volumio sudo[13873]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:31:15 volumio sudo[13875]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 22:31:15 volumio sudo[13875]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:31:15 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 09 22:31:15 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 09 22:31:15 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 22:31:15 volumio systemd[1]: shairport-sync.service: Consumed 2.436s CPU time. Feb 09 22:31:16 volumio volumio[13598]: info: CoreCommandRouter::volumioGetState Feb 09 22:31:16 volumio volumio[13598]: info: CorePlayQueue::getTrack 0 Feb 09 22:31:16 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 22:31:16 volumio sudo[13871]: pam_unix(sudo:session): session closed for user root Feb 09 22:31:16 volumio volumio[13598]: info: Shairport-Sync Started Feb 09 22:31:16 volumio volumio[13598]: Error adding Membership: Error: addMembership EINVAL Feb 09 22:31:16 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 09 22:31:16 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 09 22:31:16 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 22:31:16 volumio volumio[13598]: 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 09 22:31:16 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 22:31:16 volumio volumio[13598]: info: Spotify Successfully logged in Feb 09 22:31:16 volumio sudo[13875]: pam_unix(sudo:session): session closed for user root Feb 09 22:31:16 volumio sudo[13873]: pam_unix(sudo:session): session closed for user root Feb 09 22:31:16 volumio volumio[13598]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 22:31:16 volumio volumio[13598]: info: [1770651076349] CoreMusicLibrary::Adding element Spotify Feb 09 22:31:16 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 22:31:16 volumio volumio[13598]: Cannot find translation for source YouTube Music Feb 09 22:31:16 volumio volumio[13598]: Cannot find translation for source Spotify Feb 09 22:31:16 volumio volumio[13598]: info: Shairport-Sync Started Feb 09 22:31:16 volumio volumio[13598]: info: Shairport-Sync Started Feb 09 22:31:17 volumio volumio[13598]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 09 22:31:17 volumio volumio[13598]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 22:31:17 volumio volumio[13598]: info: VolumeController:: Volume=100 Mute =false Feb 09 22:31:17 volumio volumio[13598]: info: CoreCommandRouter::volumioGetState Feb 09 22:31:17 volumio volumio[13598]: info: CorePlayQueue::getTrack 0 Feb 09 22:31:17 volumio volumio[13598]: info: CoreStateMachine::pushState Feb 09 22:31:17 volumio volumio[13598]: info: CorePlayQueue::getTrack 0 Feb 09 22:31:17 volumio volumio[13598]: info: CoreCommandRouter::volumioPushState Feb 09 22:31:18 volumio volumio[13598]: info: go-librespot daemon successfully initialized Feb 09 22:31:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 39. Feb 09 22:31:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:31:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:31:18 volumio go-librespot[13923]: go-librespot daemon starting... Feb 09 22:31:18 volumio go-librespot[13924]: time="2026-02-09T22:31:18+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 22:31:18 volumio go-librespot[13924]: time="2026-02-09T22:31:18+07:00" level=debug msg="app state loaded" Feb 09 22:31:18 volumio go-librespot[13924]: time="2026-02-09T22:31:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 22:31:19 volumio mpd[13823]: 2026-02-09T22:31:19 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 09 22:31:19 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 09 22:31:19 volumio sudo[13782]: pam_unix(sudo:session): session closed for user root Feb 09 22:31:19 volumio sudo[13794]: pam_unix(sudo:session): session closed for user root Feb 09 22:31:19 volumio go-librespot[13924]: time="2026-02-09T22:31: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 22:31:19 volumio go-librespot[13924]: time="2026-02-09T22:31:19+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 09 22:31:19 volumio go-librespot[13924]: time="2026-02-09T22:31:19+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 09 22:31:19 volumio go-librespot[13924]: time="2026-02-09T22:31:19+07:00" level=info msg="zeroconf server listening on port 36471" Feb 09 22:31:19 volumio volumio[13598]: error: MPD error: The expression evaluated to a falsy value: Feb 09 22:31:19 volumio volumio[13598]: assert.ok(self.idling) Feb 09 22:31:19 volumio volumio[13598]: error: The expression evaluated to a falsy value: Feb 09 22:31:19 volumio volumio[13598]: assert.ok(self.idling) Feb 09 22:31:19 volumio volumio[13598]: info: MPD running with PID13823 Feb 09 22:31:19 volumio volumio[13598]: ,establishing connection Feb 09 22:31:19 volumio volumio[13598]: error: updateQueue error: null Feb 09 22:31:19 volumio volumio[13598]: info: Completed starting Core Plugins Feb 09 22:31:19 volumio volumio[13598]: info: ------------------------------------------- Feb 09 22:31:19 volumio volumio[13598]: info: ----- MyVolumio plugins startup ---- Feb 09 22:31:19 volumio volumio[13598]: info: ------------------------------------------- Feb 09 22:31:19 volumio volumio[13598]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 09 22:31:19 volumio volumio[13598]: error: updateQueue error: null Feb 09 22:31:19 volumio go-librespot[13924]: time="2026-02-09T22:31:19+07:00" level=debug msg="obtained new client token: AABoi6VznnRC+/5PqguYBbCO0Xgdy3HZy2pUnirVT1S4rduz6q3GLBWnmIkY7ygXNYgZCHxjRZHtUxRoBBwz/M0l+A0cnr6Vg/R2+xiAYGgzXQ1mLc1temZSU5QAkUl6yo8/t9s3amVmYfwfwLCd1Q3v+24irnKPwXTHGQRlWpkfS+ZrsZPcd8CZZZxXr5h1jOctlveeVCi0k/VcaM5zv0hGr+Ygcw0a6Tg+B0lFTTAplv26age94VcbwQ==" Feb 09 22:31:19 volumio go-librespot[13924]: time="2026-02-09T22:31:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 22:31:19 volumio go-librespot[13924]: time="2026-02-09T22:31:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 09 22:31:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 22:31:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 22:31:21 volumio volumio[13598]: info: Initializing connection to go-librespot Websocket Feb 09 22:31:21 volumio volumio[13598]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 22:31:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 40. Feb 09 22:31:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:31:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:31:22 volumio go-librespot[13936]: go-librespot daemon starting... Feb 09 22:31:22 volumio go-librespot[13937]: time="2026-02-09T22:31:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 22:31:22 volumio go-librespot[13937]: time="2026-02-09T22:31:22+07:00" level=debug msg="app state loaded" Feb 09 22:31:22 volumio go-librespot[13937]: time="2026-02-09T22:31:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 22:31:23 volumio go-librespot[13937]: time="2026-02-09T22:31:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 22:31:23 volumio go-librespot[13937]: time="2026-02-09T22:31:23+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 09 22:31:23 volumio go-librespot[13937]: time="2026-02-09T22:31:23+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 09 22:31:23 volumio go-librespot[13937]: time="2026-02-09T22:31:23+07:00" level=info msg="zeroconf server listening on port 44763" Feb 09 22:31:23 volumio go-librespot[13937]: time="2026-02-09T22:31:23+07:00" level=debug msg="obtained new client token: AAAXYl0XpmSv6/3VKG1taD0Fo4Fg9qsVQjMVs+JF7ODyZVL1ygVuhf/GE+jpVYjbW84x3E/8AjG2pe0gHQ+KuODl6dJFMsSDsPqDGt45cPOH0IaYOCAVv+2bET9GYnXulUMBAUVL8RXKOrReB+iywYiVs3YILCZnlvMwP4l5uYmRo/ARQg7b8a6bQMxIqZIEpTT2rLco+MpNy6/wpYDtoscxuDAggW04A/QlRsaMobxbhncG66vfVJaCOA==" Feb 09 22:31:23 volumio go-librespot[13937]: time="2026-02-09T22:31:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 22:31:23 volumio go-librespot[13937]: time="2026-02-09T22:31:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 09 22:31:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 22:31:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 22:31:24 volumio volumio[13598]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 09 22:31:24 volumio volumio[13598]: info: Initializing connection to go-librespot Websocket Feb 09 22:31:24 volumio volumio[13598]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 22:31:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 41. Feb 09 22:31:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:31:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:31:27 volumio go-librespot[13944]: go-librespot daemon starting... Feb 09 22:31:27 volumio go-librespot[13945]: time="2026-02-09T22:31:27+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 22:31:27 volumio go-librespot[13945]: time="2026-02-09T22:31:27+07:00" level=debug msg="app state loaded" Feb 09 22:31:27 volumio go-librespot[13945]: time="2026-02-09T22:31:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 22:31:27 volumio go-librespot[13945]: time="2026-02-09T22:31:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 22:31:27 volumio go-librespot[13945]: time="2026-02-09T22:31:27+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 09 22:31:27 volumio go-librespot[13945]: time="2026-02-09T22:31:27+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 09 22:31:27 volumio volumio[13598]: info: Initializing connection to go-librespot Websocket Feb 09 22:31:27 volumio go-librespot[13945]: time="2026-02-09T22:31:27+07:00" level=info msg="zeroconf server listening on port 41953" Feb 09 22:31:27 volumio go-librespot[13945]: time="2026-02-09T22:31:27+07:00" level=debug msg="new websocket client" Feb 09 22:31:27 volumio volumio[13598]: info: Connection to go-librespot Websocket established Feb 09 22:31:27 volumio go-librespot[13945]: time="2026-02-09T22:31:27+07:00" level=debug msg="obtained new client token: AAA/r4xTLwrtOHzaUQB3bJF/1OPbiPbHO9DWoq2FL7Mmza0HmJo5ciFgGGArV/BFVL1kUW0e0e7DUSuzA5wg2TBhBz6gQ/o90TRr33xZ8pocdeSYD/1gze7fLqQTX/PLiQwVUKDkUoJSVKzPswzy6Vo60BlqVJ4xvmkunXmIi6M4hpDux3jSv20dGza+RLcBcXw0IPgCV4t+UZhXoF970B94wiohV7UMK0e1SoZgGeOQG7SUftEYmzXzqA==" Feb 09 22:31:27 volumio go-librespot[13945]: time="2026-02-09T22:31:27+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 09 22:31:28 volumio go-librespot[13945]: time="2026-02-09T22:31:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 09 22:31:28 volumio go-librespot[13945]: time="2026-02-09T22:31:28+07:00" level=debug msg="completed keyexchange" Feb 09 22:31:28 volumio go-librespot[13945]: time="2026-02-09T22:31:28+07:00" level=debug msg="completed challenge" Feb 09 22:31:28 volumio go-librespot[13945]: time="2026-02-09T22:31:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 22:31:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 22:31:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 22:31:28 volumio volumio[13598]: info: Connection to go-librespot Websocket closed Feb 09 22:31:28 volumio volumio[13598]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 09 22:31:28 volumio volumio[13598]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 09 22:31:28 volumio volumio[13598]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 09 22:31:28 volumio volumio[13598]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 09 22:31:28 volumio volumio[13598]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 09 22:31:28 volumio volumio[13598]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 09 22:31:28 volumio volumio[13598]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 09 22:31:28 volumio volumio[13598]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 09 22:31:28 volumio volumio[13598]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 09 22:31:28 volumio volumio[13598]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 09 22:31:28 volumio volumio[13598]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 09 22:31:28 volumio volumio[13598]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 09 22:31:28 volumio volumio[13598]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 09 22:31:28 volumio volumio[13598]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 09 22:31:28 volumio volumio[13598]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 09 22:31:28 volumio volumio[13598]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 09 22:31:28 volumio volumio[13598]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 09 22:31:28 volumio volumio[13598]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 09 22:31:28 volumio volumio[13598]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 09 22:31:28 volumio volumio[13598]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 09 22:31:28 volumio volumio[13598]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 09 22:31:28 volumio volumio[13598]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 09 22:31:28 volumio volumio[13598]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 09 22:31:28 volumio volumio[13598]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 09 22:31:28 volumio volumio[13598]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 09 22:31:28 volumio volumio[13598]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 09 22:31:28 volumio volumio[13598]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 09 22:31:28 volumio volumio[13598]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 09 22:31:28 volumio volumio[13598]: info: Adding plugin bluetooth to MyMusic Plugins Feb 09 22:31:28 volumio volumio[13598]: info: Adding plugin multiroom to MyMusic Plugins Feb 09 22:31:28 volumio volumio[13598]: info: Adding plugin metavolumio to MyMusic Plugins Feb 09 22:31:28 volumio volumio[13598]: info: Adding plugin cd_controller to MyMusic Plugins Feb 09 22:31:28 volumio volumio[13598]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 09 22:31:28 volumio volumio[13598]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 09 22:31:28 volumio volumio[13598]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 09 22:31:28 volumio volumio[13598]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 09 22:31:30 volumio volumio[13598]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 09 22:31:30 volumio volumio[13598]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 09 22:31:30 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 22:31:30 volumio volumio[13598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 22:31:30 volumio volumio[13598]: info: Starting MyVolumio Remote Streaming Endpoints Feb 09 22:31:30 volumio volumio[13598]: info: MyVolumio login type: Token Feb 09 22:31:30 volumio volumio[13598]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 09 22:31:30 volumio volumio[13598]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 09 22:31:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 42. Feb 09 22:31:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:31:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:31:31 volumio go-librespot[13966]: go-librespot daemon starting... Feb 09 22:31:31 volumio go-librespot[13967]: time="2026-02-09T22:31:31+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 22:31:31 volumio go-librespot[13967]: time="2026-02-09T22:31:31+07:00" level=debug msg="app state loaded" Feb 09 22:31:31 volumio go-librespot[13967]: time="2026-02-09T22:31:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 22:31:31 volumio go-librespot[13967]: time="2026-02-09T22:31:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 22:31:31 volumio go-librespot[13967]: time="2026-02-09T22:31:31+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 09 22:31:31 volumio go-librespot[13967]: time="2026-02-09T22:31:31+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 09 22:31:31 volumio go-librespot[13967]: time="2026-02-09T22:31:31+07:00" level=info msg="zeroconf server listening on port 41113" Feb 09 22:31:32 volumio go-librespot[13967]: time="2026-02-09T22:31:32+07:00" level=debug msg="obtained new client token: AADJDBptW2ijYX6jBPIfn6/AfQNydJQ/ULPMCtMeEEe6NTPj7NV2JZHg7l0LgFZh3hl32nQeO7JKIh7Y7mZxzlLsztuWPpLkbYdtJ43TVmoejBrG+d93xnjsmxawKUnWiCBup4CEWEyPs0eq4/ZHZ+Jc+vl9wfjePWaH4dRnbsB/y/gBv2F94m3dyk+n5JhOprLjTH7723aqSMHeZqH1LkP3o7DBj3lftnicIhGQgxdLkPLJnKnkBaQ=" Feb 09 22:31:32 volumio volumio[13598]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 09 22:31:32 volumio volumio[13598]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 09 22:31:32 volumio volumio[13598]: info: Streaming services startup Feb 09 22:31:32 volumio volumio[13598]: info: Starting Streaming Daemon Feb 09 22:31:32 volumio go-librespot[13967]: time="2026-02-09T22:31:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 22:31:32 volumio sudo[13976]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 09 22:31:32 volumio sudo[13976]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:31:32 volumio volumio[13598]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 09 22:31:32 volumio go-librespot[13967]: time="2026-02-09T22:31:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 09 22:31:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 22:31:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 22:31:32 volumio sudo[13976]: pam_unix(sudo:session): session closed for user root Feb 09 22:31:32 volumio volumio[13598]: info: Getting Spotify volume Feb 09 22:31:32 volumio volumio[13598]: info: Initializing connection to go-librespot Websocket Feb 09 22:31:32 volumio volumio[13598]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 22:31:32 volumio volumio[13598]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 22:31:32 volumio volumio[13598]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 09 22:31:32 volumio volumio[13598]: errno: -111, Feb 09 22:31:32 volumio volumio[13598]: code: 'ECONNREFUSED', Feb 09 22:31:32 volumio volumio[13598]: syscall: 'connect', Feb 09 22:31:32 volumio volumio[13598]: address: '127.0.0.1', Feb 09 22:31:32 volumio volumio[13598]: port: 9879, Feb 09 22:31:32 volumio volumio[13598]: response: undefined Feb 09 22:31:32 volumio volumio[13598]: } Feb 09 22:31:32 volumio volumio[13598]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 22:31:33 volumio sudo[13996]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-09 22:30' Feb 09 22:31:33 volumio sudo[13996]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:31:34 volumio sudo[13996]: pam_unix(sudo:session): session closed for user root Feb 09 22:31:34 volumio volumio-remote-updater[643]: [2026-02-09 22:31:34] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 09 22:31:34 volumio volumio-remote-updater[643]: [2026-02-09 22:31:34] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 09 22:31:34 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 09 22:31:34 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 09 22:31:34 volumio systemd[1]: volumio.service: Consumed 54.870s CPU time. Feb 09 22:31:34 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 22:31:34 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 22:31:34 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 9333. Feb 09 22:31:34 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 22:31:34 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 09 22:31:34 volumio systemd[1]: volumio.service: Consumed 54.870s CPU time. Feb 09 22:31:34 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 09 22:31:34 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 22:31:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 43. Feb 09 22:31:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:31:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:31:35 volumio go-librespot[14023]: go-librespot daemon starting... Feb 09 22:31:35 volumio go-librespot[14024]: time="2026-02-09T22:31:35+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 22:31:35 volumio go-librespot[14024]: time="2026-02-09T22:31:35+07:00" level=debug msg="app state loaded" Feb 09 22:31:35 volumio go-librespot[14024]: time="2026-02-09T22:31:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 22:31:36 volumio go-librespot[14024]: time="2026-02-09T22:31:36+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 22:31:36 volumio go-librespot[14024]: time="2026-02-09T22:31:36+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 09 22:31:36 volumio go-librespot[14024]: time="2026-02-09T22:31:36+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 09 22:31:36 volumio go-librespot[14024]: time="2026-02-09T22:31:36+07:00" level=info msg="zeroconf server listening on port 42677" Feb 09 22:31:36 volumio go-librespot[14024]: time="2026-02-09T22:31:36+07:00" level=debug msg="obtained new client token: AABbt4a6A1mBIRbL9Imf7fQLBgixIohnKODbOnY/a4mR3+ybZ0HINWuGOraXFy3vJLTbTl9p2KCd81kFhGoT5R5IeZ/gv2/4YaLpFxa+1l+WOAAwIso3c7OHmTziamY677eGDdHjg65xQ8okRn9DWXlm9BF6suk+fZ+eX20KWMBaQa0LC8OU03WCY+8pmme0l5MCWfT/MpvQWZy4C7rfiE2K7PwqIrFXfUCu39mX03jATlzTor55EghP8w==" Feb 09 22:31:36 volumio go-librespot[14024]: time="2026-02-09T22:31:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 22:31:36 volumio go-librespot[14024]: time="2026-02-09T22:31:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 09 22:31:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 22:31:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 22:31:38 volumio volumio[14008]: info: ------------------------------------------- Feb 09 22:31:38 volumio volumio[14008]: info: ----- Volumio3 ---- Feb 09 22:31:38 volumio volumio[14008]: info: ------------------------------------------- Feb 09 22:31:38 volumio volumio[14008]: info: ----- System startup ---- Feb 09 22:31:38 volumio volumio[14008]: info: ------------------------------------------- Feb 09 22:31:39 volumio volumio-remote-updater[643]: [2026-02-09 22:31:39] [connect] Successful connection Feb 09 22:31:39 volumio volumio[14008]: info: MYVOLUMIO Environment detected Feb 09 22:31:39 volumio volumio[14008]: info: Plugin folders cleanup Feb 09 22:31:39 volumio volumio[14008]: info: Scanning into folder /volumio/app/plugins/ Feb 09 22:31:39 volumio volumio[14008]: info: Scanning category audio_interface Feb 09 22:31:39 volumio volumio[14008]: info: Scanning category miscellanea Feb 09 22:31:39 volumio volumio[14008]: info: Scanning category music_service Feb 09 22:31:39 volumio volumio[14008]: info: Scanning category plugins.json Feb 09 22:31:39 volumio volumio[14008]: info: Scanning category system_controller Feb 09 22:31:39 volumio volumio[14008]: info: Scanning category user_interface Feb 09 22:31:39 volumio volumio[14008]: info: Scanning into folder /data/plugins/ Feb 09 22:31:39 volumio volumio[14008]: info: Scanning category music_service Feb 09 22:31:39 volumio volumio[14008]: info: Plugin folders cleanup completed Feb 09 22:31:39 volumio volumio[14008]: info: ------------------------------------------- Feb 09 22:31:39 volumio volumio[14008]: info: ----- Core plugins startup ---- Feb 09 22:31:39 volumio volumio[14008]: info: ------------------------------------------- Feb 09 22:31:39 volumio volumio[14008]: info: Loading plugins from folder /volumio/app/plugins/ Feb 09 22:31:39 volumio volumio[14008]: info: Adding plugin upnp to MyMusic Plugins Feb 09 22:31:39 volumio volumio[14008]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 09 22:31:39 volumio volumio[14008]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 09 22:31:39 volumio volumio[14008]: info: Loading plugins from folder /data/plugins/ Feb 09 22:31:39 volumio volumio[14008]: info: Loading plugin "system"... Feb 09 22:31:39 volumio volumio[14008]: info: Loading plugin "appearance"... Feb 09 22:31:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 44. Feb 09 22:31:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:31:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:31:39 volumio go-librespot[14043]: go-librespot daemon starting... Feb 09 22:31:39 volumio go-librespot[14044]: time="2026-02-09T22:31:39+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 22:31:39 volumio go-librespot[14044]: time="2026-02-09T22:31:39+07:00" level=debug msg="app state loaded" Feb 09 22:31:39 volumio go-librespot[14044]: time="2026-02-09T22:31:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 22:31:40 volumio go-librespot[14044]: time="2026-02-09T22:31:40+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 22:31:40 volumio go-librespot[14044]: time="2026-02-09T22:31:40+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 09 22:31:40 volumio go-librespot[14044]: time="2026-02-09T22:31:40+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 09 22:31:40 volumio go-librespot[14044]: time="2026-02-09T22:31:40+07:00" level=info msg="zeroconf server listening on port 35629" Feb 09 22:31:40 volumio go-librespot[14044]: time="2026-02-09T22:31:40+07:00" level=debug msg="obtained new client token: AACIt/v7fJ0054km8PO1O1IO0lsWNYFwJ1zWsSluLl6lxnAG2ncGKrtX+mGBoLM6u0dNo1qen+77AqONnB9w0yZtOfqBxjSfY43EXdC5eyqx/1OZgZV0kh7/HBwnag5eLf6AHi5xRPC2UK9scpWkeWWpKlyS3LmqOlQlZYJMg7ksmCUK1Qy1J3HXeRxihnoT0w2LM3hSVLTACE2gucZ2Dei/YBJ1ypmXTIB5llkt7kYobN4DE+SoUNgFDA==" Feb 09 22:31:40 volumio go-librespot[14044]: time="2026-02-09T22:31:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 22:31:40 volumio go-librespot[14044]: time="2026-02-09T22:31:40+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 09 22:31:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 22:31:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 22:31:41 volumio volumio[14008]: info: Loading plugin "network"... Feb 09 22:31:41 volumio volumio[14008]: info: Refreshing Cached IP Addresses Feb 09 22:31:41 volumio sudo[14053]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 22:31:41 volumio sudo[14053]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:31:41 volumio sudo[14055]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 22:31:41 volumio sudo[14053]: pam_unix(sudo:session): session closed for user root Feb 09 22:31:41 volumio volumio[14008]: info: Loading plugin "services"... Feb 09 22:31:41 volumio sudo[14055]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:31:41 volumio volumio[14008]: info: Loading plugin "alsa_controller"... Feb 09 22:31:41 volumio sudo[14055]: pam_unix(sudo:session): session closed for user root Feb 09 22:31:41 volumio sudo[14063]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 09 22:31:41 volumio sudo[14063]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:31:41 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 22:31:41 volumio volumio[14008]: info: Loading plugin "wizard"... Feb 09 22:31:41 volumio volumio[14008]: info: Loading plugin "networkfs"... Feb 09 22:31:42 volumio volumio[14008]: info: Starting Udev Watcher for removable devices Feb 09 22:31:42 volumio volumio[14008]: info: Ignoring mount for partition: boot Feb 09 22:31:42 volumio volumio[14008]: info: Ignoring mount for partition: volumio Feb 09 22:31:42 volumio volumio[14008]: info: Ignoring mount for partition: volumio_data Feb 09 22:31:42 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 22:31:42 volumio volumio[14008]: info: Loading plugin "volumio_command_line_client"... Feb 09 22:31:42 volumio volumio[14008]: info: Loading plugin "upnp"... Feb 09 22:31:42 volumio volumio[14008]: info: [1770651102115] Starting Upmpd Daemon Feb 09 22:31:42 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 22:31:42 volumio volumio[14008]: info: Loading plugin "my_music"... Feb 09 22:31:42 volumio volumio[14008]: info: Loading plugin "mpd"... Feb 09 22:31:42 volumio volumio[14008]: info: Loading plugin "upnp_browser"... Feb 09 22:31:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 45. Feb 09 22:31:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:31:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:31:44 volumio go-librespot[14088]: go-librespot daemon starting... Feb 09 22:31:44 volumio go-librespot[14089]: time="2026-02-09T22:31:44+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 22:31:44 volumio go-librespot[14089]: time="2026-02-09T22:31:44+07:00" level=debug msg="app state loaded" Feb 09 22:31:44 volumio go-librespot[14089]: time="2026-02-09T22:31:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 22:31:44 volumio sudo[14063]: pam_unix(sudo:session): session closed for user root Feb 09 22:31:44 volumio go-librespot[14089]: time="2026-02-09T22:31:44+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 09 22:31:44 volumio go-librespot[14089]: time="2026-02-09T22:31:44+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 09 22:31:44 volumio go-librespot[14089]: time="2026-02-09T22:31:44+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 09 22:31:44 volumio go-librespot[14089]: time="2026-02-09T22:31:44+07:00" level=info msg="zeroconf server listening on port 42743" Feb 09 22:31:44 volumio go-librespot[14089]: time="2026-02-09T22:31:44+07:00" level=debug msg="obtained new client token: AAC0nynFhh2eojkVcI6gmLXxXXCIl/pHA/jOldWjXhTo/7ZgpvUccDLNUyFPqSDqto8mn8Ql2tLieAYkySxpBwNUv0nBKq+boUyUTZ+qK1Gf6uY5SbMH/NLnBRTfczr8T+AaUt7ILC3tUqydpXJtFW6wQl0Smntf8ORg3BJcx1Ou3JVtFt8ILd6LECi3ZLp104AqC18HPsJ0fdiD49Zj8GB0ispT6fwIkXdIdEr0qZ9ow9NldpD4gbTKng==" Feb 09 22:31:45 volumio go-librespot[14089]: time="2026-02-09T22:31:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 22:31:45 volumio go-librespot[14089]: time="2026-02-09T22:31:45+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 09 22:31:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 22:31:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 22:31:45 volumio volumio[14008]: info: Starting UPNP Browser Feb 09 22:31:45 volumio volumio[14008]: info: Loading plugin "alarm-clock"... Feb 09 22:31:46 volumio volumio[14008]: info: Loading plugin "airplay_emulation"... Feb 09 22:31:46 volumio volumio[14008]: info: Starting Shairport Sync Feb 09 22:31:46 volumio volumio[14008]: info: Loading plugin "last_100"... Feb 09 22:31:46 volumio volumio[14008]: info: Loading plugin "webradio"... Feb 09 22:31:46 volumio volumio[14008]: info: Loading plugin "i2s_dacs"... Feb 09 22:31:46 volumio volumio[14008]: info: Loading plugin "volumiodiscovery"... Feb 09 22:31:46 volumio volumio[14008]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 22:31:46 volumio volumio[14008]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 22:31:46 volumio volumio[14008]: *** WARNING *** For more information see Feb 09 22:31:46 volumio volumio[14008]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 22:31:46 volumio volumio[14008]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 22:31:46 volumio volumio[14008]: *** WARNING *** For more information see Feb 09 22:31:46 volumio node[14008]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 22:31:46 volumio node[14008]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 22:31:46 volumio node[14008]: *** WARNING *** For more information see Feb 09 22:31:46 volumio node[14008]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 22:31:46 volumio node[14008]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 22:31:46 volumio node[14008]: *** WARNING *** For more information see Feb 09 22:31:46 volumio volumio[14008]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 09 22:31:46 volumio volumio[14008]: info: Discovery: Started advertising with name: Volumio Feb 09 22:31:46 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 22:31:46 volumio volumio[14008]: info: Loading plugin "spop"... Feb 09 22:31:48 volumio volumio[14008]: info: Loading plugin "ytcr"... Feb 09 22:31:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 46. Feb 09 22:31:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:31:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:31:48 volumio go-librespot[14098]: go-librespot daemon starting... Feb 09 22:31:48 volumio go-librespot[14099]: time="2026-02-09T22:31:48+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 22:31:48 volumio go-librespot[14099]: time="2026-02-09T22:31:48+07:00" level=debug msg="app state loaded" Feb 09 22:31:48 volumio go-librespot[14099]: time="2026-02-09T22:31:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 22:31:48 volumio go-librespot[14099]: time="2026-02-09T22:31:48+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 22:31:48 volumio go-librespot[14099]: time="2026-02-09T22:31:48+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 22:31:48 volumio go-librespot[14099]: time="2026-02-09T22:31:48+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 22:31:48 volumio go-librespot[14099]: time="2026-02-09T22:31:48+07:00" level=info msg="zeroconf server listening on port 32891" Feb 09 22:31:49 volumio go-librespot[14099]: time="2026-02-09T22:31:49+07:00" level=debug msg="obtained new client token: AADNgUtDevx/6LASZBjUmGWNr903nwWZV7FPmStndNz9hH7496EE78vqpQE17/K0Vd3YTquZQnBKdwe/RSu6t9OpISCj8IPSu/P1tJLyoLfbqy0wvZEOQDvm6STmyLXMed93krqSOq+CbzM8xMq85Aq51uZvqSibihv/RExGR0f3RD9WQKJ3Bqp1yeWo3TJRWvTndQbXpvoCrnv5/1e39FRgKYUaCY/flazZpKIklIo9PzMVQpZDd4I=" Feb 09 22:31:49 volumio go-librespot[14099]: time="2026-02-09T22:31:49+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 09 22:31:49 volumio go-librespot[14099]: time="2026-02-09T22:31:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 09 22:31:49 volumio go-librespot[14099]: time="2026-02-09T22:31:49+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 09 22:31:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 22:31:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 22:31:50 volumio volumio[14008]: info: Loading plugin "ytmusic"... Feb 09 22:31:51 volumio volumio[14008]: info: Loading plugin "outputs"... Feb 09 22:31:51 volumio volumio[14008]: info: Loading plugin "albumart"... Feb 09 22:31:51 volumio volumio-remote-updater[643]: [2026-02-09 22:31:51] [connect] Successful connection Feb 09 22:31:51 volumio volumio[14008]: info: Plugin example_plugin is not enabled Feb 09 22:31:51 volumio volumio[14008]: info: Loading plugin "inputs"... Feb 09 22:31:51 volumio volumio[14008]: info: Loading plugin "updater_comm"... Feb 09 22:31:52 volumio volumio[14008]: info: Plugin mpdemulation is not enabled Feb 09 22:31:52 volumio volumio[14008]: info: Loading plugin "rest_api"... Feb 09 22:31:52 volumio volumio[14008]: info: Loading plugin "websocket"... Feb 09 22:31:52 volumio volumio[14008]: info: Starting Socket.io Server version 1.7.4 Feb 09 22:31:52 volumio volumio[14008]: info: Loading plugin "RoonBridge"... Feb 09 22:31:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 47. Feb 09 22:31:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:31:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:31:52 volumio go-librespot[14130]: go-librespot daemon starting... Feb 09 22:31:52 volumio volumio[14008]: info: Applying required configuration parameters for plugin RoonBridge Feb 09 22:31:52 volumio go-librespot[14131]: time="2026-02-09T22:31:52+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 22:31:52 volumio go-librespot[14131]: time="2026-02-09T22:31:52+07:00" level=debug msg="app state loaded" Feb 09 22:31:52 volumio go-librespot[14131]: time="2026-02-09T22:31:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 22:31:52 volumio volumio[14008]: info: Loading i18n strings for locale en Feb 09 22:31:52 volumio volumio[14008]: Updating browse sources language Feb 09 22:31:52 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 22:31:53 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 22:31:53 volumio volumio[14008]: info: CoreCommandRouter::initPlayerControls Feb 09 22:31:53 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:53 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:53 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:53 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:53 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:53 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:53 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:53 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:53 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 22:31:53 volumio volumio[14008]: Express server listening on port 3000 Feb 09 22:31:53 volumio volumio[14008]: [Metrics] WebUI: 15s 832.16ms Feb 09 22:31:53 volumio volumio[14008]: info: CoreStateMachine::resetVolumioState Feb 09 22:31:53 volumio volumio[14008]: info: CoreStateMachine::getcurrentVolume Feb 09 22:31:53 volumio volumio[14008]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 22:31:53 volumio volumio[14107]: Forking 3 albumart workers Feb 09 22:31:53 volumio sudo[14143]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 22:31:53 volumio sudo[14143]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:31:53 volumio go-librespot[14131]: time="2026-02-09T22:31:53+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 22:31:53 volumio go-librespot[14131]: time="2026-02-09T22:31:53+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 09 22:31:53 volumio go-librespot[14131]: time="2026-02-09T22:31:53+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 09 22:31:53 volumio sudo[14143]: pam_unix(sudo:session): session closed for user root Feb 09 22:31:53 volumio sudo[14146]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 22:31:53 volumio sudo[14146]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:31:53 volumio go-librespot[14131]: time="2026-02-09T22:31:53+07:00" level=info msg="zeroconf server listening on port 42597" Feb 09 22:31:53 volumio sudo[14146]: pam_unix(sudo:session): session closed for user root Feb 09 22:31:53 volumio volumio[14008]: info: Volumio Network Manager: Network status updated: 1 Feb 09 22:31:53 volumio go-librespot[14131]: time="2026-02-09T22:31:53+07:00" level=debug msg="obtained new client token: AAAk46Yrnli2vAn/wXZ15sd1sxgSekcPdlvV6V9/U5mUpmod7aeS9ZjnY8I6nEtEGX3lQp1icUT3yjuI0DEuwSpBsO67iS5YAXlLWTjWa50HNxT1ZDUqcERKnAeZLRN9QaZTRYjXDbnOXmu0ebd+SUQItNgO75eqWrgSA60rUTtMnCLEO98O6ytuc00hT1AoEkZFgwfvqx8gj+Vo8UOMgh8wsNIXKGr/l7+u1zr7eIKNe/eD6lUGmgRWRQ==" Feb 09 22:31:53 volumio go-librespot[14131]: time="2026-02-09T22:31:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 22:31:53 volumio go-librespot[14131]: time="2026-02-09T22:31:53+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 09 22:31:53 volumio volumio-remote-updater[643]: [2026-02-09 22:31:53] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770651111 101 Feb 09 22:31:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 22:31:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 22:31:53 volumio volumio[14008]: 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 09 22:31:53 volumio volumio[14008]: info: VolumeController:: Volume=100 Mute =false Feb 09 22:31:53 volumio volumio[14008]: info: CoreStateMachine::pushState Feb 09 22:31:53 volumio volumio[14008]: info: CorePlayQueue::getTrack 0 Feb 09 22:31:53 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 22:31:53 volumio volumio[14008]: info: CoreCommandRouter::volumioPushState Feb 09 22:31:53 volumio volumio[14008]: info: CoreStateMachine::updateTrackBlock Feb 09 22:31:53 volumio volumio[14008]: info: CorePlayQueue::getTrackBlock Feb 09 22:31:53 volumio volumio[14008]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 22:31:53 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 22:31:53 volumio volumio[14008]: info: Reloading queue from file Feb 09 22:31:53 volumio volumio[14008]: info: CoreStateMachine::setRepeat null single undefined Feb 09 22:31:53 volumio volumio[14008]: info: CoreStateMachine::pushState Feb 09 22:31:53 volumio volumio[14008]: info: CorePlayQueue::getTrack 0 Feb 09 22:31:54 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 22:31:54 volumio volumio[14008]: info: CoreCommandRouter::volumioPushState Feb 09 22:31:54 volumio volumio[14008]: info: CoreStateMachine::setRandom null Feb 09 22:31:54 volumio volumio[14008]: info: CoreStateMachine::pushState Feb 09 22:31:54 volumio volumio[14008]: info: CorePlayQueue::getTrack 0 Feb 09 22:31:54 volumio volumio[14008]: info: CoreCommandRouter::volumioPushState Feb 09 22:31:54 volumio volumio[14008]: info: Setting Device type: Raspberry PI Feb 09 22:31:54 volumio volumio[14008]: info: Completed loading Core Plugins Feb 09 22:31:54 volumio volumio[14008]: info: Preparing to generate the ALSA configuration file Feb 09 22:31:54 volumio volumio[14008]: info: VolumeController:: Volume=100 Mute =false Feb 09 22:31:54 volumio volumio[14008]: info: CoreStateMachine::pushState Feb 09 22:31:54 volumio volumio[14008]: info: CorePlayQueue::getTrack 0 Feb 09 22:31:54 volumio volumio[14008]: info: CoreCommandRouter::volumioPushState Feb 09 22:31:54 volumio sudo[14188]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 09 22:31:54 volumio sudo[14188]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:31:54 volumio volumio[14008]: info: Asound.conf file unchanged, so no further update is needed Feb 09 22:31:54 volumio volumio[14008]: info: Output device has changed, restarting MPD Feb 09 22:31:54 volumio volumio[14008]: info: Output device has changed, restarting Shairport Sync Feb 09 22:31:54 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:54 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 22:31:54 volumio sudo[14188]: pam_unix(sudo:session): session closed for user root Feb 09 22:31:54 volumio sudo[14191]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 22:31:54 volumio sudo[14191]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:31:54 volumio sudo[14191]: pam_unix(sudo:session): session closed for user root Feb 09 22:31:54 volumio sudo[14193]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 22:31:54 volumio sudo[14193]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:31:54 volumio volumio[14008]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 22:31:54 volumio volumio[14008]: info: ___________ START PLUGINS ___________ Feb 09 22:31:54 volumio volumio[14008]: info: ControllerMpd::onStart: Initializing MPD Feb 09 22:31:54 volumio volumio[14008]: info: Creating MPD Configuration file Feb 09 22:31:54 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 09 22:31:54 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 22:31:54 volumio volumio[14008]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 22:31:54 volumio volumio[14008]: info: [1770651114775] CoreMusicLibrary::Adding element Media Servers Feb 09 22:31:54 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 22:31:54 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 09 22:31:54 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 22:31:54 volumio systemd[1]: mpd.service: Consumed 7.120s CPU time. Feb 09 22:31:54 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 09 22:31:54 volumio sudo[14203]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 22:31:54 volumio sudo[14203]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:31:54 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 22:31:54 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 22:31:54 volumio sudo[14201]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 22:31:54 volumio sudo[14201]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:31:54 volumio sudo[14201]: pam_unix(sudo:session): session closed for user root Feb 09 22:31:54 volumio volumio[14008]: info: UPNP Browser: Client initialized successfully Feb 09 22:31:54 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 22:31:54 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:54 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 22:31:54 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 22:31:54 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 09 22:31:54 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 22:31:54 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 09 22:31:55 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 22:31:55 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 22:31:55 volumio volumio[14008]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 22:31:55 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:55 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 22:31:55 volumio volumio[14008]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 22:31:55 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 22:31:55 volumio volumio[14008]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 22:31:55 volumio volumio[14008]: info: [1770651115080] CoreMusicLibrary::Adding element Last_100 Feb 09 22:31:55 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 22:31:55 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 22:31:55 volumio volumio[14008]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 22:31:55 volumio volumio[14008]: info: [1770651115102] CoreMusicLibrary::Adding element Webradio Feb 09 22:31:55 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 22:31:55 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 22:31:55 volumio volumio[14008]: info: Initializing BBC Radios Feb 09 22:31:55 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 22:31:55 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 22:31:55 volumio volumio[14008]: info: Creating Spotify config file Feb 09 22:31:55 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:55 volumio sudo[14217]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 09 22:31:55 volumio sudo[14217]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 09 22:31:55 volumio sudo[14217]: pam_unix(sudo:session): session closed for user root Feb 09 22:31:56 volumio volumio[14147]: Starting albumart workers Feb 09 22:31:56 volumio volumio[14145]: Starting albumart workers Feb 09 22:31:56 volumio volumio[14148]: Starting albumart workers Feb 09 22:31:56 volumio volumio[14008]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 22:31:56 volumio volumio[14008]: info: [1770651116671] CoreMusicLibrary::Adding element YouTube Music Feb 09 22:31:56 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 22:31:56 volumio volumio[14008]: Cannot find translation for source YouTube Music Feb 09 22:31:56 volumio volumio[14008]: info: Volumio Calling Home Feb 09 22:31:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 48. Feb 09 22:31:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:31:56 volumio sudo[14234]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 09 22:31:56 volumio sudo[14234]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:31:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:31:56 volumio go-librespot[14236]: go-librespot daemon starting... Feb 09 22:31:56 volumio go-librespot[14239]: time="2026-02-09T22:31:56+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 22:31:57 volumio sudo[14234]: pam_unix(sudo:session): session closed for user root Feb 09 22:31:57 volumio go-librespot[14239]: time="2026-02-09T22:31:57+07:00" level=info msg="zeroconf server listening on port 40491" Feb 09 22:31:58 volumio volumio[14008]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 09 22:31:58 volumio volumio[14008]: info: Discovery: Found device Volumio Feb 09 22:31:58 volumio volumio[14008]: info: CoreCommandRouter::volumioGetState Feb 09 22:31:58 volumio volumio[14008]: info: CorePlayQueue::getTrack 0 Feb 09 22:31:58 volumio volumio[14008]: info: MPD Permissions set Feb 09 22:31:58 volumio volumio[14008]: info: MPD Permissions set Feb 09 22:31:58 volumio volumio[14008]: info: Upmpdcli Daemon Started Feb 09 22:31:58 volumio volumio[14008]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 09 22:31:58 volumio volumio[14008]: info: Discovery: Found device Volumio Feb 09 22:31:58 volumio volumio[14008]: info: CoreCommandRouter::volumioGetState Feb 09 22:31:58 volumio volumio[14008]: info: CorePlayQueue::getTrack 0 Feb 09 22:31:58 volumio volumio[14008]: info: Volumio called home Feb 09 22:31:58 volumio volumio[14008]: info: Spotify config file written Feb 09 22:31:58 volumio sudo[14260]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 09 22:31:58 volumio sudo[14260]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:31:58 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 09 22:31:58 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 09 22:31:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:31:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:31:58 volumio go-librespot[14268]: go-librespot daemon starting... Feb 09 22:31:58 volumio sudo[14260]: pam_unix(sudo:session): session closed for user root Feb 09 22:31:58 volumio go-librespot[14269]: time="2026-02-09T22:31:58+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 22:31:58 volumio go-librespot[14269]: time="2026-02-09T22:31:58+07:00" level=debug msg="app state loaded" Feb 09 22:31:58 volumio go-librespot[14269]: time="2026-02-09T22:31:58+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 22:31:58 volumio volumio[14008]: 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 09 22:31:58 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:58 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:58 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:58 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:58 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:58 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:58 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:58 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:58 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 22:31:58 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:58 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:58 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:58 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:58 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:58 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:58 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:58 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:58 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:58 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 22:31:58 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:31:58 volumio volumio[14008]: info: No need to fix Spotify hosts Feb 09 22:31:59 volumio go-librespot[14269]: time="2026-02-09T22:31:59+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 09 22:31:59 volumio go-librespot[14269]: time="2026-02-09T22:31:59+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 09 22:31:59 volumio go-librespot[14269]: time="2026-02-09T22:31:59+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 09 22:31:59 volumio go-librespot[14269]: time="2026-02-09T22:31:59+07:00" level=info msg="zeroconf server listening on port 42783" Feb 09 22:31:59 volumio volumio[14008]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 09 22:31:59 volumio volumio[14008]: SPOTIFY: BQB-XksqZfa65aSthwjQSbl3dVOkvRONgowdu68dLualhlRhxYd1xZEUstlWrQzH72Pm6Xpe6fJb0UdS6xoYHzQvao8vio6X4y0rkIDNgW1p9496sSDb-nxgKdLLr7f_aYHDTwkF9QdkJMW-_mzUJjrgstE5gzECWcwU34JHZ3-yrTY0ZuZtyLiiotEJk_qh2PvuV1jsKBYReVJxJnna9Zj547yzwLoTJ47ZKyW07WKxnX3SxjHtZugRSG-tymO9fif0KcMbxf5bNOkVYoLpPWNRxWPT-2XGZ5NfUA73C9q1dKl8F1zdSeh1 Feb 09 22:31:59 volumio volumio[14008]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 09 22:31:59 volumio volumio[14008]: info: New Spotify access token = BQB-XksqZfa65aSthwjQSbl3dVOkvRONgowdu68dLualhlRhxYd1xZEUstlWrQzH72Pm6Xpe6fJb0UdS6xoYHzQvao8vio6X4y0rkIDNgW1p9496sSDb-nxgKdLLr7f_aYHDTwkF9QdkJMW-_mzUJjrgstE5gzECWcwU34JHZ3-yrTY0ZuZtyLiiotEJk_qh2PvuV1jsKBYReVJxJnna9Zj547yzwLoTJ47ZKyW07WKxnX3SxjHtZugRSG-tymO9fif0KcMbxf5bNOkVYoLpPWNRxWPT-2XGZ5NfUA73C9q1dKl8F1zdSeh1 Feb 09 22:31:59 volumio volumio[14008]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 09 22:31:59 volumio volumio[14008]: info: Starting Shairport Sync Feb 09 22:31:59 volumio volumio[14008]: info: Starting Shairport Sync Feb 09 22:31:59 volumio volumio[14008]: info: Starting Shairport Sync Feb 09 22:31:59 volumio sudo[14287]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 22:31:59 volumio sudo[14287]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:31:59 volumio go-librespot[14269]: time="2026-02-09T22:31:59+07:00" level=debug msg="obtained new client token: AADfSX6MbmFcp3HY4zQXe9ZLAj2xUrlX9YOiu3dE0UOVO3i/qK3Vxmr2XT82U1bEZopnVeUc0Zva4k7Fla2Gc8uaprGUnkk8S8rVPVK+Bosq/WtmYN6Ics8TWPgStK1Plq43VTnMGEmrLsu3d0sknxcXJVkjrO8+umjHImkDjT8wv4viKXmm6IJFf9FPlUJST4bUiS+zK3FbqliCYA1ECqObNzJleSINuBQw3+04M06t4CAL/VUH7d0YZw==" Feb 09 22:31:59 volumio sudo[14289]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 22:31:59 volumio sudo[14291]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 22:31:59 volumio sudo[14291]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:31:59 volumio sudo[14289]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:31:59 volumio go-librespot[14269]: time="2026-02-09T22:31:59+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 22:31:59 volumio go-librespot[14269]: time="2026-02-09T22:31:59+07:00" level=debug msg="completed keyexchange" Feb 09 22:31:59 volumio go-librespot[14269]: time="2026-02-09T22:31:59+07:00" level=debug msg="completed challenge" Feb 09 22:31:59 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 09 22:31:59 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 09 22:31:59 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 22:31:59 volumio systemd[1]: shairport-sync.service: Consumed 2.270s CPU time. Feb 09 22:31:59 volumio go-librespot[14269]: time="2026-02-09T22:31:59+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 22:31:59 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 22:32:00 volumio sudo[14289]: pam_unix(sudo:session): session closed for user root Feb 09 22:32:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 22:32:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 22:32:00 volumio sudo[14287]: pam_unix(sudo:session): session closed for user root Feb 09 22:32:00 volumio sudo[14291]: pam_unix(sudo:session): session closed for user root Feb 09 22:32:00 volumio volumio[14008]: info: CoreCommandRouter::volumioGetState Feb 09 22:32:00 volumio volumio[14008]: info: CorePlayQueue::getTrack 0 Feb 09 22:32:00 volumio volumio[14008]: info: Shairport-Sync Started Feb 09 22:32:00 volumio volumio[14008]: Error adding Membership: Error: addMembership EINVAL Feb 09 22:32:00 volumio volumio[14008]: info: Shairport-Sync Started Feb 09 22:32:00 volumio volumio[14008]: info: Shairport-Sync Started Feb 09 22:32:00 volumio volumio[14008]: 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 09 22:32:00 volumio volumio[14008]: info: Spotify Successfully logged in Feb 09 22:32:00 volumio volumio[14008]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 22:32:00 volumio volumio[14008]: info: [1770651120347] CoreMusicLibrary::Adding element Spotify Feb 09 22:32:00 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 22:32:00 volumio volumio[14008]: Cannot find translation for source YouTube Music Feb 09 22:32:00 volumio volumio[14008]: Cannot find translation for source Spotify Feb 09 22:32:01 volumio volumio[14008]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 09 22:32:01 volumio volumio[14008]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 22:32:01 volumio volumio[14008]: info: VolumeController:: Volume=100 Mute =false Feb 09 22:32:01 volumio volumio[14008]: info: CoreCommandRouter::volumioGetState Feb 09 22:32:01 volumio volumio[14008]: info: CorePlayQueue::getTrack 0 Feb 09 22:32:01 volumio volumio[14008]: info: CoreStateMachine::pushState Feb 09 22:32:01 volumio volumio[14008]: info: CorePlayQueue::getTrack 0 Feb 09 22:32:01 volumio volumio[14008]: info: CoreCommandRouter::volumioPushState Feb 09 22:32:02 volumio volumio[14008]: info: go-librespot daemon successfully initialized Feb 09 22:32:02 volumio mpd[14232]: 2026-02-09T22:32:02 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 09 22:32:02 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 09 22:32:02 volumio sudo[14193]: pam_unix(sudo:session): session closed for user root Feb 09 22:32:02 volumio sudo[14203]: pam_unix(sudo:session): session closed for user root Feb 09 22:32:02 volumio volumio[14008]: error: MPD error: The expression evaluated to a falsy value: Feb 09 22:32:02 volumio volumio[14008]: assert.ok(self.idling) Feb 09 22:32:02 volumio volumio[14008]: error: The expression evaluated to a falsy value: Feb 09 22:32:02 volumio volumio[14008]: assert.ok(self.idling) Feb 09 22:32:02 volumio volumio[14008]: error: updateQueue error: null Feb 09 22:32:02 volumio volumio[14008]: info: MPD running with PID14232 Feb 09 22:32:02 volumio volumio[14008]: ,establishing connection Feb 09 22:32:02 volumio volumio[14008]: info: Completed starting Core Plugins Feb 09 22:32:02 volumio volumio[14008]: info: ------------------------------------------- Feb 09 22:32:02 volumio volumio[14008]: info: ----- MyVolumio plugins startup ---- Feb 09 22:32:02 volumio volumio[14008]: info: ------------------------------------------- Feb 09 22:32:02 volumio volumio[14008]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 09 22:32:02 volumio volumio[14008]: error: updateQueue error: null Feb 09 22:32:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 09 22:32:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:32:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:32:03 volumio go-librespot[14334]: go-librespot daemon starting... Feb 09 22:32:03 volumio go-librespot[14335]: time="2026-02-09T22:32:03+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 22:32:03 volumio go-librespot[14335]: time="2026-02-09T22:32:03+07:00" level=debug msg="app state loaded" Feb 09 22:32:03 volumio go-librespot[14335]: time="2026-02-09T22:32:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 22:32:03 volumio go-librespot[14335]: time="2026-02-09T22:32:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 22:32:03 volumio go-librespot[14335]: time="2026-02-09T22:32:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 22:32:03 volumio go-librespot[14335]: time="2026-02-09T22:32:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 22:32:03 volumio go-librespot[14335]: time="2026-02-09T22:32:03+07:00" level=info msg="zeroconf server listening on port 45009" Feb 09 22:32:03 volumio go-librespot[14335]: time="2026-02-09T22:32:03+07:00" level=debug msg="obtained new client token: AACAR150vUqNQaWshitJ4LlLb1T963a2l7i4/jtwa5vZPsbl6b+/cH20vfIYSjuAnWhS7Wzyuvw7si9ZaLN+yXgf4ifZoDmcRFC65iUC6N6fQLVq7PvZN7/tm7SF71GNy7/Q+OsP0EFrIBn7c6RehDd1ILXql7rhBkd4CEhlbZR5sSD92KIE1BlxB4Gxevv9mhkZN+ZVn7/CFcBIB1p22bkxf7g0hLBJwkcFUUMEBqKQEi3Nj3R6QURdgw==" Feb 09 22:32:03 volumio go-librespot[14335]: time="2026-02-09T22:32:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 22:32:04 volumio go-librespot[14335]: time="2026-02-09T22:32:04+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 09 22:32:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 22:32:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 22:32:05 volumio volumio[14008]: info: Initializing connection to go-librespot Websocket Feb 09 22:32:05 volumio volumio[14008]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 22:32:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 09 22:32:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:32:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:32:07 volumio go-librespot[14342]: go-librespot daemon starting... Feb 09 22:32:07 volumio go-librespot[14343]: time="2026-02-09T22:32:07+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 22:32:07 volumio go-librespot[14343]: time="2026-02-09T22:32:07+07:00" level=debug msg="app state loaded" Feb 09 22:32:07 volumio go-librespot[14343]: time="2026-02-09T22:32:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 22:32:07 volumio go-librespot[14343]: time="2026-02-09T22:32: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 09 22:32:07 volumio go-librespot[14343]: time="2026-02-09T22:32: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 09 22:32:07 volumio go-librespot[14343]: time="2026-02-09T22:32: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 09 22:32:07 volumio volumio[14008]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 09 22:32:07 volumio go-librespot[14343]: time="2026-02-09T22:32:07+07:00" level=info msg="zeroconf server listening on port 39863" Feb 09 22:32:07 volumio go-librespot[14343]: time="2026-02-09T22:32:07+07:00" level=debug msg="obtained new client token: AABGcg+YlpPbvS30r6g76S1xkz89YWti2F38KuZx0G9tXtyA4g86niTLcEIcWGHpR7pbFcWDM5hdf6TSNG/EZO9x4WdSwJxcbRHx7FrtF6eZocG9WIhGBUHAFm3hYAYzGfWb5+uU4GpMXKfIQfDquk841ZWi7IfMB1zbrb3RLTNAbMvOq6WaHqJEs1Lfc38TIxsn2zTGR2AsRopUX41aB481keJ4OlRevSx+gFCqPO0baPVTboD8yIQSrQ==" Feb 09 22:32:08 volumio go-librespot[14343]: time="2026-02-09T22:32:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 22:32:08 volumio go-librespot[14343]: time="2026-02-09T22:32:08+07:00" level=debug msg="completed keyexchange" Feb 09 22:32:08 volumio go-librespot[14343]: time="2026-02-09T22:32:08+07:00" level=debug msg="completed challenge" Feb 09 22:32:08 volumio go-librespot[14343]: time="2026-02-09T22:32:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 22:32:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 22:32:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 22:32:08 volumio volumio[14008]: info: Initializing connection to go-librespot Websocket Feb 09 22:32:08 volumio volumio[14008]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 22:32:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 09 22:32:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:32:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:32:11 volumio go-librespot[14350]: go-librespot daemon starting... Feb 09 22:32:11 volumio go-librespot[14351]: time="2026-02-09T22:32:11+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 22:32:11 volumio go-librespot[14351]: time="2026-02-09T22:32:11+07:00" level=debug msg="app state loaded" Feb 09 22:32:11 volumio go-librespot[14351]: time="2026-02-09T22:32:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 22:32:11 volumio volumio[14008]: info: Initializing connection to go-librespot Websocket Feb 09 22:32:11 volumio go-librespot[14351]: time="2026-02-09T22:32:11+07:00" level=debug msg="new websocket client" Feb 09 22:32:11 volumio volumio[14008]: info: Connection to go-librespot Websocket established Feb 09 22:32:11 volumio go-librespot[14351]: time="2026-02-09T22:32:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 22:32:11 volumio go-librespot[14351]: time="2026-02-09T22:32:11+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 22:32:11 volumio go-librespot[14351]: time="2026-02-09T22:32:11+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 22:32:11 volumio volumio[14008]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 09 22:32:11 volumio volumio[14008]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 09 22:32:11 volumio volumio[14008]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 09 22:32:11 volumio volumio[14008]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 09 22:32:11 volumio volumio[14008]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 09 22:32:11 volumio volumio[14008]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 09 22:32:11 volumio volumio[14008]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 09 22:32:11 volumio volumio[14008]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 09 22:32:11 volumio volumio[14008]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 09 22:32:11 volumio volumio[14008]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 09 22:32:11 volumio volumio[14008]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 09 22:32:11 volumio volumio[14008]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 09 22:32:11 volumio volumio[14008]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 09 22:32:11 volumio volumio[14008]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 09 22:32:11 volumio volumio[14008]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 09 22:32:11 volumio volumio[14008]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 09 22:32:11 volumio volumio[14008]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 09 22:32:11 volumio volumio[14008]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 09 22:32:11 volumio volumio[14008]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 09 22:32:11 volumio volumio[14008]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 09 22:32:11 volumio volumio[14008]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 09 22:32:11 volumio volumio[14008]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 09 22:32:11 volumio volumio[14008]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 09 22:32:11 volumio volumio[14008]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 09 22:32:11 volumio volumio[14008]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 09 22:32:11 volumio volumio[14008]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 09 22:32:11 volumio volumio[14008]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 09 22:32:11 volumio volumio[14008]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 09 22:32:11 volumio volumio[14008]: info: Adding plugin bluetooth to MyMusic Plugins Feb 09 22:32:11 volumio volumio[14008]: info: Adding plugin multiroom to MyMusic Plugins Feb 09 22:32:11 volumio volumio[14008]: info: Adding plugin metavolumio to MyMusic Plugins Feb 09 22:32:11 volumio volumio[14008]: info: Adding plugin cd_controller to MyMusic Plugins Feb 09 22:32:11 volumio go-librespot[14351]: time="2026-02-09T22:32:11+07:00" level=info msg="zeroconf server listening on port 32967" Feb 09 22:32:11 volumio volumio[14008]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 09 22:32:11 volumio volumio[14008]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 09 22:32:11 volumio volumio[14008]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 09 22:32:11 volumio volumio[14008]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 09 22:32:12 volumio go-librespot[14351]: time="2026-02-09T22:32:12+07:00" level=debug msg="obtained new client token: AABtY/X5iFMDW4yrEsrIEFenrvNjC5i5diIfECJ7toNUDCIgKVipahQstnBib5hykrQoP7acfxsJf3wsuiYmpbKh0n9nPH1kfSmu9XZFSUEgbDWkhAVToh4TC4lOuDxBgUnDMVErcnin9RTEROlg1XGMKBHe4PXIDs4m16LOCk0rKbi1ikSmd2jimwlzaAHNeEe4zLY5M6ldT+EgBw/DKLNm++9c4LrXoX2pPNsUL3nMxAxKSeVHp6c=" Feb 09 22:32:12 volumio go-librespot[14351]: time="2026-02-09T22:32:12+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 09 22:32:12 volumio go-librespot[14351]: time="2026-02-09T22:32:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 09 22:32:12 volumio go-librespot[14351]: time="2026-02-09T22:32:12+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 09 22:32:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 22:32:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 22:32:13 volumio volumio[14008]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 09 22:32:13 volumio volumio[14008]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 09 22:32:13 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 22:32:13 volumio volumio[14008]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 22:32:13 volumio volumio[14008]: info: Starting MyVolumio Remote Streaming Endpoints Feb 09 22:32:13 volumio volumio[14008]: info: MyVolumio login type: Token Feb 09 22:32:13 volumio volumio[14008]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 09 22:32:13 volumio volumio[14008]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 09 22:32:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 09 22:32:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:32:15 volumio volumio[14008]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 09 22:32:15 volumio volumio[14008]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 09 22:32:15 volumio volumio[14008]: info: Streaming services startup Feb 09 22:32:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:32:15 volumio volumio[14008]: info: Starting Streaming Daemon Feb 09 22:32:15 volumio go-librespot[14373]: go-librespot daemon starting... Feb 09 22:32:15 volumio go-librespot[14374]: time="2026-02-09T22:32:15+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 22:32:15 volumio go-librespot[14374]: time="2026-02-09T22:32:15+07:00" level=debug msg="app state loaded" Feb 09 22:32:15 volumio sudo[14376]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 09 22:32:15 volumio sudo[14376]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:32:15 volumio go-librespot[14374]: time="2026-02-09T22:32:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 22:32:15 volumio volumio[14008]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 09 22:32:15 volumio sudo[14376]: pam_unix(sudo:session): session closed for user root Feb 09 22:32:15 volumio volumio[14008]: info: Getting Spotify volume Feb 09 22:32:15 volumio volumio[14008]: info: Connection to go-librespot Websocket closed Feb 09 22:32:15 volumio volumio[14008]: error: Cannot start Volumio Streaming Daemon Feb 09 22:32:15 volumio volumio[14008]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 09 22:32:15 volumio volumio[14008]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 09 22:32:15 volumio volumio[14008]: 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 09 22:32:16 volumio volumio[14008]: info: CoreCommandRouter::volumioGetState Feb 09 22:32:16 volumio volumio[14008]: info: CorePlayQueue::getTrack 0 Feb 09 22:32:16 volumio volumio[14008]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 09 22:32:16 volumio volumio[14008]: SPOTIFY: SPOTIFY VOLUME undefined Feb 09 22:32:16 volumio volumio[14008]: SPOTIFY: VOLUMIO VOLUME 100 Feb 09 22:32:16 volumio volumio[14008]: info: Aligning Spotify Volume to Volumio Volume Feb 09 22:32:16 volumio volumio[14008]: info: CoreCommandRouter::volumioGetState Feb 09 22:32:16 volumio volumio[14008]: info: CorePlayQueue::getTrack 0 Feb 09 22:32:16 volumio volumio[14008]: info: Setting Spotify Volume from Volumio: 100 Feb 09 22:32:16 volumio go-librespot[14374]: time="2026-02-09T22:32:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 09 22:32:16 volumio go-librespot[14374]: time="2026-02-09T22:32:16+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 09 22:32:16 volumio go-librespot[14374]: time="2026-02-09T22:32:16+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 09 22:32:16 volumio go-librespot[14374]: time="2026-02-09T22:32:16+07:00" level=info msg="zeroconf server listening on port 46053" Feb 09 22:32:16 volumio go-librespot[14374]: time="2026-02-09T22:32:16+07:00" level=debug msg="obtained new client token: AABkPfukKSZx8HH2qw9Gny+ZPyUbpB+4RopAfxyEWFDwJeU1LVgkRnjJCh/dhYT56JayAtRnLgTBZSFsum2vKNUMx2hEwdp3eVUy0iQ6RB2C7+Uj7zXjrJGdxscNK4IojhJsUDElh2MQ2E1Ll7KKl5A9IlEJbVdt0QoVfeba+FApBuTdPXvViOO3oiqbNrCA58phrGt6LypmGLHvq/rbQRP8t4mzHekZyiOYZxASFJ132bedvjcXA+xf+w==" Feb 09 22:32:16 volumio go-librespot[14374]: time="2026-02-09T22:32:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 22:32:16 volumio go-librespot[14374]: time="2026-02-09T22:32:16+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 09 22:32:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 22:32:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 22:32:16 volumio volumio[14008]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 22:32:16 volumio volumio[14008]: Error: socket hang up Feb 09 22:32:16 volumio volumio[14008]: at connResetException (node:internal/errors:720:14) Feb 09 22:32:16 volumio volumio[14008]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 09 22:32:16 volumio volumio[14008]: at Socket.emit (node:events:526:35) Feb 09 22:32:16 volumio volumio[14008]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 09 22:32:16 volumio volumio[14008]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 09 22:32:16 volumio volumio[14008]: code: 'ECONNRESET', Feb 09 22:32:16 volumio volumio[14008]: response: undefined Feb 09 22:32:16 volumio volumio[14008]: } Feb 09 22:32:16 volumio volumio[14008]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 22:32:18 volumio sudo[14402]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-09 22:31' Feb 09 22:32:18 volumio sudo[14402]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:32:18 volumio sudo[14402]: pam_unix(sudo:session): session closed for user root Feb 09 22:32:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 09 22:32:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:32:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:32:19 volumio go-librespot[14410]: go-librespot daemon starting... Feb 09 22:32:19 volumio go-librespot[14412]: time="2026-02-09T22:32:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 22:32:19 volumio go-librespot[14412]: time="2026-02-09T22:32:19+07:00" level=debug msg="app state loaded" Feb 09 22:32:19 volumio go-librespot[14412]: time="2026-02-09T22:32:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 22:32:19 volumio volumio-remote-updater[643]: [2026-02-09 22:32:19] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Feb 09 22:32:19 volumio volumio-remote-updater[643]: [2026-02-09 22:32:19] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Feb 09 22:32:19 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 09 22:32:19 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 09 22:32:19 volumio systemd[1]: volumio.service: Consumed 55.728s CPU time. Feb 09 22:32:20 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 22:32:20 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 22:32:20 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 9334. Feb 09 22:32:20 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 22:32:20 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 09 22:32:20 volumio systemd[1]: volumio.service: Consumed 55.728s CPU time. Feb 09 22:32:20 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 09 22:32:20 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 22:32:20 volumio go-librespot[14412]: time="2026-02-09T22:32:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 22:32:20 volumio go-librespot[14412]: time="2026-02-09T22:32:20+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 09 22:32:20 volumio go-librespot[14412]: time="2026-02-09T22:32:20+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 09 22:32:20 volumio go-librespot[14412]: time="2026-02-09T22:32:20+07:00" level=info msg="zeroconf server listening on port 33825" Feb 09 22:32:20 volumio go-librespot[14412]: time="2026-02-09T22:32:20+07:00" level=debug msg="obtained new client token: AACQvfPcPUN/wtbjRXNWxViqEFn7XAJB/uV5yZ7bBsBiqHg9PZl7tJDSVEjikbZEooz8I2l6H+dGPuW1kzejY6Iz6dS9h+b3sUhHmAJi/DADKkEg5cYfTYT6qTfpooOGuljFWU5wehSatpMqWLaBg/SxD0H859+OtKZ+bE1k3Lgj7p13meZpvkAYA979IqwT2ju6hg30fz3z/EtkxodJNF/96BZwkI3GlGLR0BFk/yQBMF1bnfBXduzpAA==" Feb 09 22:32:20 volumio go-librespot[14412]: time="2026-02-09T22:32:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 22:32:21 volumio go-librespot[14412]: time="2026-02-09T22:32:21+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.23:51616->104.199.241.202:4070: read: connection reset by peer" Feb 09 22:32:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 22:32:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 22:32:23 volumio volumio[14426]: info: ------------------------------------------- Feb 09 22:32:23 volumio volumio[14426]: info: ----- Volumio3 ---- Feb 09 22:32:23 volumio volumio[14426]: info: ------------------------------------------- Feb 09 22:32:23 volumio volumio[14426]: info: ----- System startup ---- Feb 09 22:32:23 volumio volumio[14426]: info: ------------------------------------------- Feb 09 22:32:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 09 22:32:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:32:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:32:24 volumio go-librespot[14449]: go-librespot daemon starting... Feb 09 22:32:24 volumio go-librespot[14450]: time="2026-02-09T22:32:24+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 22:32:24 volumio go-librespot[14450]: time="2026-02-09T22:32:24+07:00" level=debug msg="app state loaded" Feb 09 22:32:24 volumio go-librespot[14450]: time="2026-02-09T22:32:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 22:32:24 volumio volumio-remote-updater[643]: [2026-02-09 22:32:24] [connect] Successful connection Feb 09 22:32:25 volumio volumio[14426]: info: MYVOLUMIO Environment detected Feb 09 22:32:25 volumio go-librespot[14450]: time="2026-02-09T22:32:25+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 09 22:32:25 volumio go-librespot[14450]: time="2026-02-09T22:32:25+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 09 22:32:25 volumio go-librespot[14450]: time="2026-02-09T22:32:25+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 09 22:32:25 volumio go-librespot[14450]: time="2026-02-09T22:32:25+07:00" level=info msg="zeroconf server listening on port 35049" Feb 09 22:32:25 volumio volumio[14426]: info: Plugin folders cleanup Feb 09 22:32:25 volumio volumio[14426]: info: Scanning into folder /volumio/app/plugins/ Feb 09 22:32:25 volumio volumio[14426]: info: Scanning category audio_interface Feb 09 22:32:25 volumio volumio[14426]: info: Scanning category miscellanea Feb 09 22:32:25 volumio volumio[14426]: info: Scanning category music_service Feb 09 22:32:25 volumio volumio[14426]: info: Scanning category plugins.json Feb 09 22:32:25 volumio volumio[14426]: info: Scanning category system_controller Feb 09 22:32:25 volumio volumio[14426]: info: Scanning category user_interface Feb 09 22:32:25 volumio volumio[14426]: info: Scanning into folder /data/plugins/ Feb 09 22:32:25 volumio volumio[14426]: info: Scanning category music_service Feb 09 22:32:25 volumio volumio[14426]: info: Plugin folders cleanup completed Feb 09 22:32:25 volumio volumio[14426]: info: ------------------------------------------- Feb 09 22:32:25 volumio volumio[14426]: info: ----- Core plugins startup ---- Feb 09 22:32:25 volumio volumio[14426]: info: ------------------------------------------- Feb 09 22:32:25 volumio volumio[14426]: info: Loading plugins from folder /volumio/app/plugins/ Feb 09 22:32:25 volumio volumio[14426]: info: Adding plugin upnp to MyMusic Plugins Feb 09 22:32:25 volumio volumio[14426]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 09 22:32:25 volumio volumio[14426]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 09 22:32:25 volumio volumio[14426]: info: Loading plugins from folder /data/plugins/ Feb 09 22:32:25 volumio volumio[14426]: info: Loading plugin "system"... Feb 09 22:32:25 volumio volumio[14426]: info: Loading plugin "appearance"... Feb 09 22:32:25 volumio go-librespot[14450]: time="2026-02-09T22:32:25+07:00" level=debug msg="obtained new client token: AAAPl0uML+agEqZ1AHDGdy1ZJLShvbSX/T9V/jKcllV51q0KlYH2bh4SlYjlshMIwqIel9lds5IMhH5JcmL78E+/jrNYN+KK12EWrnJbVehMfbgVxnNvdGmFYBATkiBUGg54yeF0bI9gVpc5hSJ8GyNgqNyEa08sfna1HQf6YUusC6BHGsgHsDQvHG6AFnPTfgGNBAP4WpgszKZoUE7hgZRjqTCQNa4HztbgHhs9nUnHfoB1p08w84Tqlg==" Feb 09 22:32:25 volumio go-librespot[14450]: time="2026-02-09T22:32:25+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 09 22:32:25 volumio go-librespot[14450]: time="2026-02-09T22:32:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 09 22:32:25 volumio go-librespot[14450]: time="2026-02-09T22:32:25+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 09 22:32:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 22:32:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 22:32:27 volumio volumio[14426]: info: Loading plugin "network"... Feb 09 22:32:27 volumio volumio[14426]: info: Refreshing Cached IP Addresses Feb 09 22:32:27 volumio sudo[14465]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 22:32:27 volumio sudo[14465]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:32:27 volumio sudo[14467]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 22:32:27 volumio sudo[14467]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:32:27 volumio volumio[14426]: info: Loading plugin "services"... Feb 09 22:32:27 volumio sudo[14467]: pam_unix(sudo:session): session closed for user root Feb 09 22:32:27 volumio sudo[14465]: pam_unix(sudo:session): session closed for user root Feb 09 22:32:27 volumio volumio[14426]: info: Loading plugin "alsa_controller"... Feb 09 22:32:27 volumio sudo[14474]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 09 22:32:27 volumio sudo[14474]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:32:27 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 22:32:27 volumio volumio[14426]: info: Loading plugin "wizard"... Feb 09 22:32:27 volumio volumio[14426]: info: Loading plugin "networkfs"... Feb 09 22:32:27 volumio volumio[14426]: info: Starting Udev Watcher for removable devices Feb 09 22:32:27 volumio volumio[14426]: info: Ignoring mount for partition: boot Feb 09 22:32:27 volumio volumio[14426]: info: Ignoring mount for partition: volumio Feb 09 22:32:27 volumio volumio[14426]: info: Ignoring mount for partition: volumio_data Feb 09 22:32:27 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 22:32:27 volumio volumio[14426]: info: Loading plugin "volumio_command_line_client"... Feb 09 22:32:27 volumio volumio[14426]: info: Loading plugin "upnp"... Feb 09 22:32:27 volumio volumio[14426]: info: [1770651147735] Starting Upmpd Daemon Feb 09 22:32:27 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 22:32:27 volumio volumio[14426]: info: Loading plugin "my_music"... Feb 09 22:32:27 volumio volumio[14426]: info: Loading plugin "mpd"... Feb 09 22:32:28 volumio volumio[14426]: info: Loading plugin "upnp_browser"... Feb 09 22:32:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 09 22:32:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:32:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:32:28 volumio go-librespot[14498]: go-librespot daemon starting... Feb 09 22:32:28 volumio go-librespot[14499]: time="2026-02-09T22:32:28+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 22:32:28 volumio go-librespot[14499]: time="2026-02-09T22:32:28+07:00" level=debug msg="app state loaded" Feb 09 22:32:28 volumio go-librespot[14499]: time="2026-02-09T22:32:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 22:32:29 volumio go-librespot[14499]: time="2026-02-09T22:32:29+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 09 22:32:29 volumio go-librespot[14499]: time="2026-02-09T22:32:29+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 09 22:32:29 volumio go-librespot[14499]: time="2026-02-09T22:32:29+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 09 22:32:29 volumio go-librespot[14499]: time="2026-02-09T22:32:29+07:00" level=info msg="zeroconf server listening on port 37355" Feb 09 22:32:29 volumio go-librespot[14499]: time="2026-02-09T22:32:29+07:00" level=debug msg="obtained new client token: AAAPpFlB471OstZGhzzi45jOwscEUwIdDoyg/xP800YQKpjIattKq3HYw5Z/DSOvLy+0lXl5n+CA37oZIOkR4VlesmUbCIdBfocMVJ2bWVRIyA7kDSZDnwYq4KheOFVL+e4AO7vovZ/gW7FodoGzA9rXV203Rbb0NO93s+SPrbT/6RmA2Eb3rhjf+hCOTCE7DO6CIkGYnjCbCq7Dt1nzvhEr1E6D1+oCSiuWQ2dtF4WAz9b0QgsUjq6eCg==" Feb 09 22:32:29 volumio go-librespot[14499]: time="2026-02-09T22:32:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 22:32:29 volumio go-librespot[14499]: time="2026-02-09T22:32:29+07:00" level=debug msg="completed keyexchange" Feb 09 22:32:29 volumio go-librespot[14499]: time="2026-02-09T22:32:29+07:00" level=debug msg="completed challenge" Feb 09 22:32:30 volumio go-librespot[14499]: time="2026-02-09T22:32:30+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 22:32:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 22:32:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 22:32:30 volumio sudo[14474]: pam_unix(sudo:session): session closed for user root Feb 09 22:32:31 volumio volumio[14426]: info: Starting UPNP Browser Feb 09 22:32:31 volumio volumio[14426]: info: Loading plugin "alarm-clock"... Feb 09 22:32:31 volumio volumio[14426]: info: Loading plugin "airplay_emulation"... Feb 09 22:32:31 volumio volumio[14426]: info: Starting Shairport Sync Feb 09 22:32:31 volumio volumio[14426]: info: Loading plugin "last_100"... Feb 09 22:32:31 volumio volumio[14426]: info: Loading plugin "webradio"... Feb 09 22:32:31 volumio volumio[14426]: info: Loading plugin "i2s_dacs"... Feb 09 22:32:31 volumio volumio[14426]: info: Loading plugin "volumiodiscovery"... Feb 09 22:32:31 volumio volumio[14426]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 22:32:31 volumio volumio[14426]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 22:32:31 volumio node[14426]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 22:32:31 volumio volumio[14426]: *** WARNING *** For more information see Feb 09 22:32:31 volumio volumio[14426]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 22:32:31 volumio volumio[14426]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 22:32:31 volumio volumio[14426]: *** WARNING *** For more information see Feb 09 22:32:31 volumio node[14426]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 22:32:31 volumio node[14426]: *** WARNING *** For more information see Feb 09 22:32:31 volumio node[14426]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 22:32:31 volumio node[14426]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 22:32:31 volumio node[14426]: *** WARNING *** For more information see Feb 09 22:32:32 volumio volumio[14426]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 09 22:32:32 volumio volumio[14426]: info: Discovery: Started advertising with name: Volumio Feb 09 22:32:32 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 22:32:32 volumio volumio[14426]: info: Loading plugin "spop"... Feb 09 22:32:32 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Feb 09 22:32:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 09 22:32:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:32:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:32:33 volumio go-librespot[14521]: go-librespot daemon starting... Feb 09 22:32:33 volumio go-librespot[14522]: time="2026-02-09T22:32:33+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 22:32:33 volumio go-librespot[14522]: time="2026-02-09T22:32:33+07:00" level=debug msg="app state loaded" Feb 09 22:32:33 volumio go-librespot[14522]: time="2026-02-09T22:32:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 22:32:33 volumio go-librespot[14522]: time="2026-02-09T22:32:33+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 09 22:32:33 volumio go-librespot[14522]: time="2026-02-09T22:32:33+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 09 22:32:33 volumio go-librespot[14522]: time="2026-02-09T22:32:33+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 09 22:32:33 volumio go-librespot[14522]: time="2026-02-09T22:32:33+07:00" level=info msg="zeroconf server listening on port 41849" Feb 09 22:32:34 volumio volumio[14426]: info: Loading plugin "ytcr"... Feb 09 22:32:34 volumio go-librespot[14522]: time="2026-02-09T22:32:34+07:00" level=debug msg="obtained new client token: AAAD90phPf+JbkVQGzksEuPxlsfjx9Sqg7/5Lm8xumJf1O/igbpjSa9BfNOHW8QXFH6SPuYhItynwfiZ5yMVmoy9z3lu19NlHfV4ACzw/LMARHw6QgyY6Wj8kv58BfsNMHmipVhsdlARryGOXJEpxvjs70a3821lO97EuPMpcQCYzpfJlYUMzSzrnt2lyKKxUNYaKuaTx8pMdD0JND29/ahVXt9H6qymE8IyqFNfhJMKoYBt2s4q8bw=" Feb 09 22:32:34 volumio go-librespot[14522]: time="2026-02-09T22:32:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 22:32:34 volumio go-librespot[14522]: time="2026-02-09T22:32:34+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 09 22:32:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 22:32:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 22:32:35 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Feb 09 22:32:35 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Feb 09 22:32:35 volumio systemd[1]: setdatetime-helper.service: Consumed 1.935s CPU time. Feb 09 22:32:36 volumio volumio[14426]: info: Loading plugin "ytmusic"... Feb 09 22:32:37 volumio volumio-remote-updater[643]: [2026-02-09 22:32:37] [connect] Successful connection Feb 09 22:32:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 09 22:32:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:32:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:32:37 volumio go-librespot[14556]: go-librespot daemon starting... Feb 09 22:32:37 volumio go-librespot[14557]: time="2026-02-09T22:32:37+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 22:32:37 volumio go-librespot[14557]: time="2026-02-09T22:32:37+07:00" level=debug msg="app state loaded" Feb 09 22:32:37 volumio go-librespot[14557]: time="2026-02-09T22:32:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 22:32:37 volumio volumio[14426]: info: Loading plugin "outputs"... Feb 09 22:32:37 volumio volumio[14426]: info: Loading plugin "albumart"... Feb 09 22:32:37 volumio volumio[14426]: info: Plugin example_plugin is not enabled Feb 09 22:32:37 volumio volumio[14426]: info: Loading plugin "inputs"... Feb 09 22:32:37 volumio volumio[14426]: info: Loading plugin "updater_comm"... Feb 09 22:32:38 volumio volumio[14426]: info: Plugin mpdemulation is not enabled Feb 09 22:32:38 volumio volumio[14426]: info: Loading plugin "rest_api"... Feb 09 22:32:38 volumio volumio[14426]: info: Loading plugin "websocket"... Feb 09 22:32:38 volumio go-librespot[14557]: time="2026-02-09T22:32:38+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 22:32:38 volumio go-librespot[14557]: time="2026-02-09T22:32:38+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 22:32:38 volumio go-librespot[14557]: time="2026-02-09T22:32:38+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 22:32:38 volumio volumio[14426]: info: Starting Socket.io Server version 1.7.4 Feb 09 22:32:38 volumio volumio[14426]: info: Loading plugin "RoonBridge"... Feb 09 22:32:38 volumio go-librespot[14557]: time="2026-02-09T22:32:38+07:00" level=info msg="zeroconf server listening on port 35955" Feb 09 22:32:38 volumio go-librespot[14557]: time="2026-02-09T22:32:38+07:00" level=debug msg="obtained new client token: AABiKuRbQ2nnNHIl6gd1Whu/+GCCwIltzRBwD3dG8E5wQjNKLt34IQ+Kfx8Bm5S+ljCrVhidT9Hv8bMzGrcmxrGi/MEl2VO8tj0IE4NmiDC5OX8ixZ/A049+GGkb4FiMjWOzHTFyQ6BJyLFr00ydgjo0Jsl2op9BijBZmDfi8hu3swtirlwGC70cUBkAwmqDDoZLUEnpj3sbrw6vgwkJUowQWucxHuh/hhrq7ps2vP99sq9vTQq2t4zwGA==" Feb 09 22:32:38 volumio go-librespot[14557]: time="2026-02-09T22:32:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 22:32:38 volumio go-librespot[14557]: time="2026-02-09T22:32:38+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 09 22:32:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 22:32:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 22:32:38 volumio volumio[14426]: info: Applying required configuration parameters for plugin RoonBridge Feb 09 22:32:38 volumio volumio[14426]: info: Loading i18n strings for locale en Feb 09 22:32:38 volumio volumio[14426]: Updating browse sources language Feb 09 22:32:38 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 22:32:39 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 22:32:39 volumio volumio[14426]: info: CoreCommandRouter::initPlayerControls Feb 09 22:32:39 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:32:39 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:32:39 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:32:39 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:32:39 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:32:39 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:32:39 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:32:39 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:32:39 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 22:32:39 volumio volumio[14426]: Express server listening on port 3000 Feb 09 22:32:39 volumio volumio[14426]: [Metrics] WebUI: 16s 266.58ms Feb 09 22:32:39 volumio volumio[14426]: info: CoreStateMachine::resetVolumioState Feb 09 22:32:39 volumio volumio[14426]: info: CoreStateMachine::getcurrentVolume Feb 09 22:32:39 volumio volumio[14426]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 22:32:39 volumio volumio[14563]: Forking 3 albumart workers Feb 09 22:32:39 volumio sudo[14582]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 22:32:39 volumio sudo[14582]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:32:39 volumio sudo[14582]: pam_unix(sudo:session): session closed for user root Feb 09 22:32:39 volumio sudo[14584]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 22:32:39 volumio sudo[14584]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:32:39 volumio sudo[14584]: pam_unix(sudo:session): session closed for user root Feb 09 22:32:39 volumio volumio[14426]: info: Volumio Network Manager: Network status updated: 1 Feb 09 22:32:39 volumio volumio[14426]: info: VolumeController:: Volume=100 Mute =false Feb 09 22:32:39 volumio volumio[14426]: info: CoreStateMachine::pushState Feb 09 22:32:39 volumio volumio[14426]: info: CorePlayQueue::getTrack 0 Feb 09 22:32:39 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 22:32:39 volumio volumio[14426]: info: CoreCommandRouter::volumioPushState Feb 09 22:32:39 volumio volumio[14426]: info: CoreStateMachine::updateTrackBlock Feb 09 22:32:39 volumio volumio[14426]: info: CorePlayQueue::getTrackBlock Feb 09 22:32:39 volumio volumio[14426]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 22:32:39 volumio volumio-remote-updater[643]: [2026-02-09 22:32:39] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770651157 101 Feb 09 22:32:39 volumio volumio[14426]: 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 09 22:32:39 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 22:32:39 volumio volumio[14426]: info: Reloading queue from file Feb 09 22:32:39 volumio volumio[14426]: info: CoreStateMachine::setRepeat null single undefined Feb 09 22:32:39 volumio volumio[14426]: info: CoreStateMachine::pushState Feb 09 22:32:39 volumio volumio[14426]: info: CorePlayQueue::getTrack 0 Feb 09 22:32:39 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 22:32:39 volumio volumio[14426]: info: CoreCommandRouter::volumioPushState Feb 09 22:32:39 volumio volumio[14426]: info: CoreStateMachine::setRandom null Feb 09 22:32:39 volumio volumio[14426]: info: CoreStateMachine::pushState Feb 09 22:32:39 volumio volumio[14426]: info: CorePlayQueue::getTrack 0 Feb 09 22:32:39 volumio volumio[14426]: info: CoreCommandRouter::volumioPushState Feb 09 22:32:39 volumio volumio[14426]: info: Setting Device type: Raspberry PI Feb 09 22:32:40 volumio volumio[14426]: info: Completed loading Core Plugins Feb 09 22:32:40 volumio volumio[14426]: info: Preparing to generate the ALSA configuration file Feb 09 22:32:40 volumio volumio[14426]: info: VolumeController:: Volume=100 Mute =false Feb 09 22:32:40 volumio volumio[14426]: info: CoreStateMachine::pushState Feb 09 22:32:40 volumio volumio[14426]: info: CorePlayQueue::getTrack 0 Feb 09 22:32:40 volumio volumio[14426]: info: CoreCommandRouter::volumioPushState Feb 09 22:32:40 volumio volumio[14426]: info: Asound.conf file unchanged, so no further update is needed Feb 09 22:32:40 volumio volumio[14426]: info: Output device has changed, restarting MPD Feb 09 22:32:40 volumio volumio[14426]: info: Output device has changed, restarting Shairport Sync Feb 09 22:32:40 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:32:40 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 22:32:40 volumio sudo[14624]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 09 22:32:40 volumio sudo[14624]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:32:40 volumio sudo[14626]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 22:32:40 volumio sudo[14626]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:32:40 volumio volumio[14426]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 22:32:40 volumio sudo[14626]: pam_unix(sudo:session): session closed for user root Feb 09 22:32:40 volumio sudo[14628]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 22:32:40 volumio volumio[14426]: info: ___________ START PLUGINS ___________ Feb 09 22:32:40 volumio sudo[14628]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:32:40 volumio volumio[14426]: info: ControllerMpd::onStart: Initializing MPD Feb 09 22:32:40 volumio volumio[14426]: info: Creating MPD Configuration file Feb 09 22:32:40 volumio sudo[14624]: pam_unix(sudo:session): session closed for user root Feb 09 22:32:40 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 22:32:40 volumio volumio[14426]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 22:32:40 volumio volumio[14426]: info: [1770651160423] CoreMusicLibrary::Adding element Media Servers Feb 09 22:32:40 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 22:32:40 volumio volumio[14426]: info: UPNP Browser: Client initialized successfully Feb 09 22:32:40 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 09 22:32:40 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:32:40 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 22:32:40 volumio sudo[14638]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 22:32:40 volumio sudo[14640]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 22:32:40 volumio sudo[14638]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:32:40 volumio sudo[14640]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:32:40 volumio sudo[14638]: pam_unix(sudo:session): session closed for user root Feb 09 22:32:40 volumio volumio[14426]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 22:32:40 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 09 22:32:40 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 22:32:40 volumio systemd[1]: mpd.service: Consumed 7.188s CPU time. Feb 09 22:32:40 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:32:40 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 22:32:40 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 09 22:32:40 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 22:32:40 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 22:32:40 volumio volumio[14426]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 22:32:40 volumio volumio[14426]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 22:32:40 volumio volumio[14426]: info: [1770651160684] CoreMusicLibrary::Adding element Last_100 Feb 09 22:32:40 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 22:32:40 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 22:32:40 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 22:32:40 volumio volumio[14426]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 22:32:40 volumio volumio[14426]: info: [1770651160714] CoreMusicLibrary::Adding element Webradio Feb 09 22:32:40 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 22:32:40 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 22:32:40 volumio volumio[14426]: info: Initializing BBC Radios Feb 09 22:32:40 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 09 22:32:40 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 22:32:40 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 09 22:32:40 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 22:32:40 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 22:32:40 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 22:32:40 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 22:32:40 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 22:32:40 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 22:32:41 volumio volumio[14426]: info: Creating Spotify config file Feb 09 22:32:41 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:32:41 volumio sudo[14668]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 09 22:32:41 volumio sudo[14668]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 09 22:32:41 volumio sudo[14668]: pam_unix(sudo:session): session closed for user root Feb 09 22:32:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 09 22:32:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:32:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:32:41 volumio go-librespot[14671]: go-librespot daemon starting... Feb 09 22:32:42 volumio go-librespot[14672]: time="2026-02-09T22:32:42+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 22:32:42 volumio volumio[14426]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 22:32:42 volumio volumio[14426]: info: [1770651162125] CoreMusicLibrary::Adding element YouTube Music Feb 09 22:32:42 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 22:32:42 volumio volumio[14426]: Cannot find translation for source YouTube Music Feb 09 22:32:42 volumio volumio[14426]: info: Volumio Calling Home Feb 09 22:32:42 volumio sudo[14679]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 09 22:32:42 volumio sudo[14679]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:32:42 volumio sudo[14679]: pam_unix(sudo:session): session closed for user root Feb 09 22:32:42 volumio go-librespot[14672]: time="2026-02-09T22:32:42+07:00" level=info msg="zeroconf server listening on port 39035" Feb 09 22:32:42 volumio volumio[14581]: Starting albumart workers Feb 09 22:32:42 volumio volumio[14580]: Starting albumart workers Feb 09 22:32:43 volumio volumio[14578]: Starting albumart workers Feb 09 22:32:43 volumio volumio[14426]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 09 22:32:43 volumio volumio[14426]: info: Discovery: Found device Volumio Feb 09 22:32:43 volumio volumio[14426]: info: CoreCommandRouter::volumioGetState Feb 09 22:32:43 volumio volumio[14426]: info: CorePlayQueue::getTrack 0 Feb 09 22:32:43 volumio volumio[14426]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 09 22:32:43 volumio volumio[14426]: info: Discovery: Found device Volumio Feb 09 22:32:43 volumio volumio[14426]: info: CoreCommandRouter::volumioGetState Feb 09 22:32:43 volumio volumio[14426]: info: CorePlayQueue::getTrack 0 Feb 09 22:32:43 volumio volumio[14426]: info: MPD Permissions set Feb 09 22:32:43 volumio volumio[14426]: info: MPD Permissions set Feb 09 22:32:43 volumio volumio[14426]: info: Upmpdcli Daemon Started Feb 09 22:32:43 volumio volumio[14426]: info: Spotify config file written Feb 09 22:32:43 volumio sudo[14688]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 09 22:32:43 volumio sudo[14688]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:32:43 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 09 22:32:43 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 09 22:32:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:32:43 volumio volumio[14426]: 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 09 22:32:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:32:43 volumio go-librespot[14690]: go-librespot daemon starting... Feb 09 22:32:43 volumio sudo[14688]: pam_unix(sudo:session): session closed for user root Feb 09 22:32:43 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:32:43 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:32:43 volumio go-librespot[14691]: time="2026-02-09T22:32:43+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 22:32:43 volumio go-librespot[14691]: time="2026-02-09T22:32:43+07:00" level=debug msg="app state loaded" Feb 09 22:32:43 volumio go-librespot[14691]: time="2026-02-09T22:32:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 22:32:43 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:32:43 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:32:43 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:32:43 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:32:43 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:32:43 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:32:43 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 22:32:43 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:32:43 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:32:43 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:32:43 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:32:43 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:32:43 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:32:43 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:32:43 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:32:43 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:32:44 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 22:32:44 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 22:32:44 volumio volumio[14426]: info: No need to fix Spotify hosts Feb 09 22:32:44 volumio go-librespot[14691]: time="2026-02-09T22:32:44+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 22:32:44 volumio go-librespot[14691]: time="2026-02-09T22:32:44+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 22:32:44 volumio go-librespot[14691]: time="2026-02-09T22:32:44+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 22:32:44 volumio go-librespot[14691]: time="2026-02-09T22:32:44+07:00" level=info msg="zeroconf server listening on port 42409" Feb 09 22:32:44 volumio go-librespot[14691]: time="2026-02-09T22:32:44+07:00" level=debug msg="obtained new client token: AABTHLhjypGn4WFomlMxvGYScr4bQABv88m4+gsAq8HWS6r3b/IKY87IdN2W3qDrSBpFDKXCIlDR1TMkrAM/h86wWTaRQFP/Vr0HeTznqaZyi5Zmm8hwy54nLTCM0pcrvI0JdP7wWSb4rIAmXVwqJMZPCnfgRI34O78EyERY5VuS5xAK66hiLJGkYMFuRyCiG+x8/+hip3O/W3+TswGE/VqrK+vfI4FyD5WCkXC5rmGwGjGCEKX86NYS+g==" Feb 09 22:32:44 volumio go-librespot[14691]: time="2026-02-09T22:32:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 22:32:44 volumio go-librespot[14691]: time="2026-02-09T22:32:44+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 09 22:32:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 22:32:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 22:32:44 volumio volumio[14426]: info: Volumio called home Feb 09 22:32:45 volumio volumio[14426]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 09 22:32:45 volumio volumio[14426]: SPOTIFY: BQAcxzoZv9vqaQiiSwclDv9O8VTDHINBSS5TbnEByXPGOxA7pA4Z3svoybqLOhOe2DuSUtZNukhwdR97W4wXsCT_ZH2YQJ_pUk3etWeG0dSuvUJxMRYWDwNF_xWD9P0p-ZxEB-pO-pAy-Feav7NEKc0OuzFN9bKrnlQKEz40Bg7zc8MDoNoIcYcZ6JbpNjacMoLsTzSpabJ3Xek312gFSBOYDfAG74W2jVBufYgtW4pWdh2_s0e_WGRKCxv59Bjl4s0GFRNYRreV3EmZKKztzIPCHzvrqyY-kOWSnH90PaUhmPJiZgYJ698Q Feb 09 22:32:45 volumio volumio[14426]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 09 22:32:45 volumio volumio[14426]: info: New Spotify access token = BQAcxzoZv9vqaQiiSwclDv9O8VTDHINBSS5TbnEByXPGOxA7pA4Z3svoybqLOhOe2DuSUtZNukhwdR97W4wXsCT_ZH2YQJ_pUk3etWeG0dSuvUJxMRYWDwNF_xWD9P0p-ZxEB-pO-pAy-Feav7NEKc0OuzFN9bKrnlQKEz40Bg7zc8MDoNoIcYcZ6JbpNjacMoLsTzSpabJ3Xek312gFSBOYDfAG74W2jVBufYgtW4pWdh2_s0e_WGRKCxv59Bjl4s0GFRNYRreV3EmZKKztzIPCHzvrqyY-kOWSnH90PaUhmPJiZgYJ698Q Feb 09 22:32:45 volumio volumio[14426]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 09 22:32:45 volumio volumio[14426]: info: Starting Shairport Sync Feb 09 22:32:45 volumio volumio[14426]: info: Starting Shairport Sync Feb 09 22:32:45 volumio volumio[14426]: info: Starting Shairport Sync Feb 09 22:32:45 volumio sudo[14727]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 22:32:45 volumio sudo[14727]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:32:45 volumio sudo[14732]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 22:32:45 volumio sudo[14732]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:32:45 volumio sudo[14729]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 22:32:45 volumio sudo[14729]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 22:32:45 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 09 22:32:45 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 09 22:32:45 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 22:32:45 volumio systemd[1]: shairport-sync.service: Consumed 2.335s CPU time. Feb 09 22:32:45 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 22:32:45 volumio sudo[14732]: pam_unix(sudo:session): session closed for user root Feb 09 22:32:45 volumio sudo[14727]: pam_unix(sudo:session): session closed for user root Feb 09 22:32:45 volumio sudo[14729]: pam_unix(sudo:session): session closed for user root Feb 09 22:32:45 volumio volumio[14426]: info: Shairport-Sync Started Feb 09 22:32:45 volumio volumio[14426]: Error adding Membership: Error: addMembership EINVAL Feb 09 22:32:45 volumio volumio[14426]: info: Shairport-Sync Started Feb 09 22:32:45 volumio volumio[14426]: info: Shairport-Sync Started Feb 09 22:32:45 volumio volumio[14426]: info: CoreCommandRouter::volumioGetState Feb 09 22:32:46 volumio volumio[14426]: info: CorePlayQueue::getTrack 0 Feb 09 22:32:46 volumio volumio[14426]: 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 09 22:32:46 volumio volumio[14426]: info: Spotify Successfully logged in Feb 09 22:32:46 volumio volumio[14426]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 22:32:46 volumio volumio[14426]: info: [1770651166161] CoreMusicLibrary::Adding element Spotify Feb 09 22:32:46 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 22:32:46 volumio volumio[14426]: Cannot find translation for source YouTube Music Feb 09 22:32:46 volumio volumio[14426]: Cannot find translation for source Spotify Feb 09 22:32:46 volumio volumio[14426]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 09 22:32:46 volumio volumio[14426]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 22:32:47 volumio volumio[14426]: info: VolumeController:: Volume=100 Mute =false Feb 09 22:32:47 volumio volumio[14426]: info: CoreCommandRouter::volumioGetState Feb 09 22:32:47 volumio volumio[14426]: info: CorePlayQueue::getTrack 0 Feb 09 22:32:47 volumio volumio[14426]: info: CoreStateMachine::pushState Feb 09 22:32:47 volumio volumio[14426]: info: CorePlayQueue::getTrack 0 Feb 09 22:32:47 volumio volumio[14426]: info: CoreCommandRouter::volumioPushState Feb 09 22:32:47 volumio volumio[14426]: info: go-librespot daemon successfully initialized Feb 09 22:32:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 09 22:32:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:32:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:32:48 volumio go-librespot[14767]: go-librespot daemon starting... Feb 09 22:32:48 volumio go-librespot[14768]: time="2026-02-09T22:32:48+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 22:32:48 volumio go-librespot[14768]: time="2026-02-09T22:32:48+07:00" level=debug msg="app state loaded" Feb 09 22:32:48 volumio go-librespot[14768]: time="2026-02-09T22:32:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 22:32:48 volumio go-librespot[14768]: time="2026-02-09T22:32:48+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 22:32:48 volumio go-librespot[14768]: time="2026-02-09T22:32:48+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 22:32:48 volumio go-librespot[14768]: time="2026-02-09T22:32:48+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 22:32:48 volumio go-librespot[14768]: time="2026-02-09T22:32:48+07:00" level=info msg="zeroconf server listening on port 46157" Feb 09 22:32:48 volumio mpd[14670]: 2026-02-09T22:32:48 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 09 22:32:48 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 09 22:32:48 volumio sudo[14628]: pam_unix(sudo:session): session closed for user root Feb 09 22:32:48 volumio sudo[14640]: pam_unix(sudo:session): session closed for user root Feb 09 22:32:48 volumio volumio[14426]: error: updateQueue error: null Feb 09 22:32:48 volumio volumio[14426]: error: updateQueue error: null Feb 09 22:32:48 volumio volumio[14426]: info: MPD running with PID14670 Feb 09 22:32:48 volumio volumio[14426]: ,establishing connection Feb 09 22:32:48 volumio go-librespot[14768]: time="2026-02-09T22:32:48+07:00" level=debug msg="obtained new client token: AADi9jlaJxxyCUpm82ECPWdjpQybymJA0cR1aVtBsMPqgfkXIE7GFGVAue2XpPsdmCQ0BnM+AS17Sa+WYqO1yOe7edwV5kMokdWzkKoJygCgweDOFT7XA/ODm/gOHOD5ufrYKIrBRf+lVdNFJeuYEu8M8QoUacUIVtXiSo0MBXTzXdEj/xsVeX1pUoWrmyTKZ8Y3pHHDwgrDgwzYFZG3dle/UxKMO4GHZmElciJ7wccFCigKX88KnjK5uQ==" Feb 09 22:32:48 volumio volumio[14426]: info: Completed starting Core Plugins Feb 09 22:32:48 volumio volumio[14426]: info: ------------------------------------------- Feb 09 22:32:48 volumio volumio[14426]: info: ----- MyVolumio plugins startup ---- Feb 09 22:32:48 volumio volumio[14426]: info: ------------------------------------------- Feb 09 22:32:48 volumio volumio[14426]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 09 22:32:48 volumio volumio[14426]: error: updateQueue error: null Feb 09 22:32:48 volumio go-librespot[14768]: time="2026-02-09T22:32:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 22:32:49 volumio go-librespot[14768]: time="2026-02-09T22:32:49+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.23:57764->104.199.241.202:4070: read: connection reset by peer" Feb 09 22:32:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 22:32:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 22:32:50 volumio volumio[14426]: info: Initializing connection to go-librespot Websocket Feb 09 22:32:50 volumio volumio[14426]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 22:32:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 09 22:32:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:32:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:32:53 volumio go-librespot[14779]: go-librespot daemon starting... Feb 09 22:32:53 volumio go-librespot[14780]: time="2026-02-09T22:32:53+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 22:32:53 volumio go-librespot[14780]: time="2026-02-09T22:32:53+07:00" level=debug msg="app state loaded" Feb 09 22:32:53 volumio go-librespot[14780]: time="2026-02-09T22:32:53+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 22:32:53 volumio go-librespot[14780]: time="2026-02-09T22:32:53+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 22:32:53 volumio go-librespot[14780]: time="2026-02-09T22:32:53+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 09 22:32:53 volumio go-librespot[14780]: time="2026-02-09T22:32:53+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 09 22:32:53 volumio go-librespot[14780]: time="2026-02-09T22:32:53+07:00" level=info msg="zeroconf server listening on port 42211" Feb 09 22:32:53 volumio volumio[14426]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 09 22:32:53 volumio go-librespot[14780]: time="2026-02-09T22:32:53+07:00" level=debug msg="obtained new client token: AAC7GUaqzb68I443HpuqsCFIywNzQM/ui3UvQB0BawM4mCss1stYt+WYPFRfRR9dMlFZEn6/Gr8OGQ1rWNTWyqAM4N4dLKUupjNGUSzR5YvhZXnYPAfj7sDP1nVI6rYzh6V86jAaIBJjdcQfwBt48S4DwbIUZcKE2IV18JNWTgabt6l8depslQIeVHYTPkeO8U8Itx0IgNa7PRNG6/UAnEQLEQORBSEq6uNbAx41W2dwAXDGeoNl/3RPEA==" Feb 09 22:32:53 volumio volumio[14426]: info: Initializing connection to go-librespot Websocket Feb 09 22:32:53 volumio go-librespot[14780]: time="2026-02-09T22:32:53+07:00" level=debug msg="new websocket client" Feb 09 22:32:53 volumio volumio[14426]: info: Connection to go-librespot Websocket established Feb 09 22:32:54 volumio go-librespot[14780]: time="2026-02-09T22:32:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 22:32:54 volumio go-librespot[14780]: time="2026-02-09T22:32:54+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 09 22:32:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 22:32:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 22:32:54 volumio volumio[14426]: info: Connection to go-librespot Websocket closed Feb 09 22:32:57 volumio volumio[14426]: info: Getting Spotify volume Feb 09 22:32:57 volumio volumio[14426]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 22:32:57 volumio volumio[14426]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 22:32:57 volumio volumio[14426]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 09 22:32:57 volumio volumio[14426]: errno: -111, Feb 09 22:32:57 volumio volumio[14426]: code: 'ECONNREFUSED', Feb 09 22:32:57 volumio volumio[14426]: syscall: 'connect', Feb 09 22:32:57 volumio volumio[14426]: address: '127.0.0.1', Feb 09 22:32:57 volumio volumio[14426]: port: 9879, Feb 09 22:32:57 volumio volumio[14426]: response: undefined Feb 09 22:32:57 volumio volumio[14426]: } Feb 09 22:32:57 volumio volumio[14426]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 22:32:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 09 22:32:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:32:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 22:32:57 volumio go-librespot[14800]: go-librespot daemon starting... Feb 09 22:32:57 volumio go-librespot[14801]: time="2026-02-09T22:32:57+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 22:32:57 volumio go-librespot[14801]: time="2026-02-09T22:32:57+07:00" level=debug msg="app state loaded" Feb 09 22:32:57 volumio go-librespot[14801]: time="2026-02-09T22:32:57+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 22:32:58 volumio go-librespot[14801]: time="2026-02-09T22:32:58+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 22:32:58 volumio go-librespot[14801]: time="2026-02-09T22:32:58+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 09 22:32:58 volumio go-librespot[14801]: time="2026-02-09T22:32:58+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 09 22:32:58 volumio go-librespot[14801]: time="2026-02-09T22:32:58+07:00" level=info msg="zeroconf server listening on port 38183" Feb 09 22:32:58 volumio go-librespot[14801]: time="2026-02-09T22:32:58+07:00" level=debug msg="obtained new client token: AABDaD79mAbqFkV8kwSCOoqQXhEJiFVFsjH+1dbnIPdkVBzIo891qREC0pXAeWILAv4nUMd944c2tQAjuLvGQ8qiUudWvh+FLmKp2Eni4S8nQHLyFsNrBrFc24DhjFGng18FO+LuGu+gy6+wmByhuipVXp7TmIZ1iXuadb9G8EkwXtFldsTtWyPFXYHL9kmMkljHrjrRpJDdQG6Lb6/GGJBtmWlcRdI/ZSLTiNao9dpowQ9K8FZ1XBHWZA==" Feb 09 22:32:58 volumio go-librespot[14801]: time="2026-02-09T22:32:58+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 22:32:58 volumio go-librespot[14801]: time="2026-02-09T22:32:58+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 09 22:32:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 22:32:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 22:32:58 volumio sudo[14824]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-09 22:31' Feb 09 22:32:58 volumio sudo[14824]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"