Feb 08 19:35:00 volumio go-librespot[3149]: time="2026-02-08T19:35:00+07:00" level=debug msg="completed keyexchange" Feb 08 19:35:00 volumio go-librespot[3149]: time="2026-02-08T19:35:00+07:00" level=debug msg="completed challenge" Feb 08 19:35:00 volumio go-librespot[3149]: time="2026-02-08T19:35:00+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 08 19:35:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 19:35:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 19:35:00 volumio volumio[3059]: info: Loading plugin "ytmusic"... Feb 08 19:35:01 volumio volumio-remote-updater[643]: [2026-02-08 19:35:01] [connect] Successful connection Feb 08 19:35:01 volumio volumio[3059]: info: Loading plugin "outputs"... Feb 08 19:35:01 volumio volumio[3059]: info: Loading plugin "albumart"... Feb 08 19:35:01 volumio volumio[3059]: info: Plugin example_plugin is not enabled Feb 08 19:35:01 volumio volumio[3059]: info: Loading plugin "inputs"... Feb 08 19:35:01 volumio volumio[3059]: info: Loading plugin "updater_comm"... Feb 08 19:35:01 volumio volumio[3059]: info: Plugin mpdemulation is not enabled Feb 08 19:35:01 volumio volumio[3059]: info: Loading plugin "rest_api"... Feb 08 19:35:01 volumio volumio[3059]: info: Loading plugin "websocket"... Feb 08 19:35:01 volumio volumio[3059]: info: Starting Socket.io Server version 1.7.4 Feb 08 19:35:01 volumio volumio[3059]: info: Loading plugin "RoonBridge"... Feb 08 19:35:02 volumio volumio[3059]: info: Applying required configuration parameters for plugin RoonBridge Feb 08 19:35:02 volumio volumio[3059]: info: Loading i18n strings for locale en Feb 08 19:35:02 volumio volumio[3059]: Updating browse sources language Feb 08 19:35:02 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 19:35:02 volumio volumio[3171]: Forking 3 albumart workers Feb 08 19:35:02 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 19:35:02 volumio volumio[3059]: info: CoreCommandRouter::initPlayerControls Feb 08 19:35:02 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:02 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:02 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:02 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:02 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:02 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:02 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:02 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:02 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 19:35:02 volumio volumio[3059]: Express server listening on port 3000 Feb 08 19:35:02 volumio volumio[3059]: [Metrics] WebUI: 15s 990.90ms Feb 08 19:35:02 volumio volumio[3059]: info: CoreStateMachine::resetVolumioState Feb 08 19:35:02 volumio volumio[3059]: info: CoreStateMachine::getcurrentVolume Feb 08 19:35:02 volumio volumio[3059]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 19:35:03 volumio sudo[3215]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 08 19:35:03 volumio sudo[3215]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 19:35:03 volumio volumio[3059]: info: Volumio Network Manager: Network status updated: 1 Feb 08 19:35:03 volumio sudo[3215]: pam_unix(sudo:session): session closed for user root Feb 08 19:35:03 volumio sudo[3218]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 08 19:35:03 volumio sudo[3218]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 19:35:03 volumio sudo[3218]: pam_unix(sudo:session): session closed for user root Feb 08 19:35:03 volumio volumio[3059]: info: VolumeController:: Volume=100 Mute =false Feb 08 19:35:03 volumio volumio[3059]: info: CoreStateMachine::pushState Feb 08 19:35:03 volumio volumio[3059]: info: CorePlayQueue::getTrack 0 Feb 08 19:35:03 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 08 19:35:03 volumio volumio[3059]: info: CoreCommandRouter::volumioPushState Feb 08 19:35:03 volumio volumio[3059]: info: CoreStateMachine::updateTrackBlock Feb 08 19:35:03 volumio volumio[3059]: info: CorePlayQueue::getTrackBlock Feb 08 19:35:03 volumio volumio[3059]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 19:35:03 volumio volumio-remote-updater[643]: [2026-02-08 19:35:03] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770554101 101 Feb 08 19:35:03 volumio volumio[3059]: 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 08 19:35:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 08 19:35:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 19:35:03 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 19:35:03 volumio volumio[3059]: info: Reloading queue from file Feb 08 19:35:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 19:35:03 volumio go-librespot[3225]: go-librespot daemon starting... Feb 08 19:35:03 volumio volumio[3059]: info: CoreStateMachine::setRepeat null single undefined Feb 08 19:35:03 volumio volumio[3059]: info: CoreStateMachine::pushState Feb 08 19:35:03 volumio volumio[3059]: info: CorePlayQueue::getTrack 0 Feb 08 19:35:03 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 08 19:35:03 volumio volumio[3059]: info: CoreCommandRouter::volumioPushState Feb 08 19:35:03 volumio go-librespot[3229]: time="2026-02-08T19:35:03+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 19:35:03 volumio go-librespot[3229]: time="2026-02-08T19:35:03+07:00" level=debug msg="app state loaded" Feb 08 19:35:03 volumio go-librespot[3229]: time="2026-02-08T19:35:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 19:35:03 volumio volumio[3059]: info: CoreStateMachine::setRandom null Feb 08 19:35:03 volumio volumio[3059]: info: CoreStateMachine::pushState Feb 08 19:35:03 volumio volumio[3059]: info: CorePlayQueue::getTrack 0 Feb 08 19:35:03 volumio volumio[3059]: info: CoreCommandRouter::volumioPushState Feb 08 19:35:03 volumio volumio[3059]: info: Setting Device type: Raspberry PI Feb 08 19:35:03 volumio volumio[3059]: info: Completed loading Core Plugins Feb 08 19:35:03 volumio volumio[3059]: info: Preparing to generate the ALSA configuration file Feb 08 19:35:03 volumio volumio[3059]: info: VolumeController:: Volume=100 Mute =false Feb 08 19:35:03 volumio volumio[3059]: info: CoreStateMachine::pushState Feb 08 19:35:03 volumio volumio[3059]: info: CorePlayQueue::getTrack 0 Feb 08 19:35:03 volumio volumio[3059]: info: CoreCommandRouter::volumioPushState Feb 08 19:35:03 volumio volumio[3059]: info: Asound.conf file unchanged, so no further update is needed Feb 08 19:35:03 volumio volumio[3059]: info: Output device has changed, restarting MPD Feb 08 19:35:04 volumio volumio[3059]: info: Output device has changed, restarting Shairport Sync Feb 08 19:35:04 volumio sudo[3239]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 08 19:35:04 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:04 volumio sudo[3239]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 19:35:04 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 19:35:04 volumio sudo[3241]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 19:35:04 volumio sudo[3241]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 19:35:04 volumio sudo[3241]: pam_unix(sudo:session): session closed for user root Feb 08 19:35:04 volumio sudo[3243]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 19:35:04 volumio sudo[3243]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 19:35:04 volumio volumio[3059]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 19:35:04 volumio volumio[3059]: info: ___________ START PLUGINS ___________ Feb 08 19:35:04 volumio volumio[3059]: info: ControllerMpd::onStart: Initializing MPD Feb 08 19:35:04 volumio volumio[3059]: info: Creating MPD Configuration file Feb 08 19:35:04 volumio sudo[3239]: pam_unix(sudo:session): session closed for user root Feb 08 19:35:04 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 19:35:04 volumio volumio[3059]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 19:35:04 volumio volumio[3059]: info: [1770554104280] CoreMusicLibrary::Adding element Media Servers Feb 08 19:35:04 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 19:35:04 volumio volumio[3059]: info: UPNP Browser: Client initialized successfully Feb 08 19:35:04 volumio sudo[3255]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 19:35:04 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 08 19:35:04 volumio sudo[3255]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 19:35:04 volumio sudo[3256]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 19:35:04 volumio sudo[3256]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 19:35:04 volumio sudo[3255]: pam_unix(sudo:session): session closed for user root Feb 08 19:35:04 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:04 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 19:35:04 volumio go-librespot[3229]: time="2026-02-08T19:35:04+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 08 19:35:04 volumio go-librespot[3229]: time="2026-02-08T19:35:04+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 08 19:35:04 volumio go-librespot[3229]: time="2026-02-08T19:35:04+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 08 19:35:04 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 08 19:35:04 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 08 19:35:04 volumio systemd[1]: mpd.service: Consumed 7.160s CPU time. Feb 08 19:35:04 volumio volumio[3059]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 19:35:04 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:04 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 19:35:04 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 08 19:35:04 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 08 19:35:04 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 08 19:35:04 volumio go-librespot[3229]: time="2026-02-08T19:35:04+07:00" level=info msg="zeroconf server listening on port 42099" Feb 08 19:35:04 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 08 19:35:04 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 08 19:35:04 volumio volumio[3059]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 19:35:04 volumio volumio[3059]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 19:35:04 volumio volumio[3059]: info: [1770554104618] CoreMusicLibrary::Adding element Last_100 Feb 08 19:35:04 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 19:35:04 volumio volumio[3059]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 19:35:04 volumio volumio[3059]: info: [1770554104638] CoreMusicLibrary::Adding element Webradio Feb 08 19:35:04 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 19:35:04 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 19:35:04 volumio volumio[3059]: info: Initializing BBC Radios Feb 08 19:35:04 volumio go-librespot[3229]: time="2026-02-08T19:35:04+07:00" level=debug msg="obtained new client token: AADDS3WhWc/wRJBuZbL0pwhcVnTNJKRKrsj+EGr+qsgDlFHIaeWsQtDOMawNRcjfdAxfo4sD+eq2DbeAhejZcv/3RhplLFeUp+2qO2UQ+e8MtGkjzILTU0a+ef3071EaKDNiUJ40B+JGm4cefaYoB3iuHqcYOCL73pit0f7y+uMKM578kheoNep8FTqnnGag0pI8kZI9Vjgckp7IvTdvjFx0uk8Qus8/Mo6xsCwsT7Vb8T/I9DWoqYvDwg==" Feb 08 19:35:04 volumio go-librespot[3229]: time="2026-02-08T19:35:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 19:35:04 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 19:35:04 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 19:35:04 volumio go-librespot[3229]: time="2026-02-08T19:35: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 08 19:35:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 19:35:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 19:35:05 volumio volumio[3059]: info: Creating Spotify config file Feb 08 19:35:05 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:05 volumio sudo[3268]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 08 19:35:05 volumio sudo[3268]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 08 19:35:05 volumio sudo[3268]: pam_unix(sudo:session): session closed for user root Feb 08 19:35:06 volumio volumio[3183]: Starting albumart workers Feb 08 19:35:06 volumio volumio[3182]: Starting albumart workers Feb 08 19:35:06 volumio volumio[3181]: Starting albumart workers Feb 08 19:35:06 volumio volumio[3059]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 19:35:06 volumio volumio[3059]: info: [1770554106296] CoreMusicLibrary::Adding element YouTube Music Feb 08 19:35:06 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 19:35:06 volumio volumio[3059]: Cannot find translation for source YouTube Music Feb 08 19:35:06 volumio volumio[3059]: info: Volumio Calling Home Feb 08 19:35:06 volumio sudo[3285]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 08 19:35:06 volumio sudo[3285]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 19:35:06 volumio sudo[3285]: pam_unix(sudo:session): session closed for user root Feb 08 19:35:07 volumio volumio[3059]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 08 19:35:07 volumio volumio[3059]: info: Discovery: Found device Volumio Feb 08 19:35:07 volumio volumio[3059]: info: CoreCommandRouter::volumioGetState Feb 08 19:35:07 volumio volumio[3059]: info: CorePlayQueue::getTrack 0 Feb 08 19:35:07 volumio volumio[3059]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 08 19:35:07 volumio volumio[3059]: info: Discovery: Found device Volumio Feb 08 19:35:07 volumio volumio[3059]: info: CoreCommandRouter::volumioGetState Feb 08 19:35:07 volumio volumio[3059]: info: CorePlayQueue::getTrack 0 Feb 08 19:35:07 volumio volumio[3059]: info: MPD Permissions set Feb 08 19:35:07 volumio volumio[3059]: info: MPD Permissions set Feb 08 19:35:07 volumio volumio[3059]: info: Upmpdcli Daemon Started Feb 08 19:35:07 volumio volumio[3059]: info: Spotify config file written Feb 08 19:35:07 volumio volumio[3059]: 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 08 19:35:07 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:07 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:07 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:07 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:07 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:07 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:07 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:07 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:07 volumio sudo[3291]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 08 19:35:07 volumio sudo[3291]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 19:35:07 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 19:35:07 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:07 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:07 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:07 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:07 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:07 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:07 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:07 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:07 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:07 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 19:35:07 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:07 volumio volumio[3059]: info: No need to fix Spotify hosts Feb 08 19:35:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 19:35:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 19:35:07 volumio go-librespot[3303]: go-librespot daemon starting... Feb 08 19:35:07 volumio sudo[3291]: pam_unix(sudo:session): session closed for user root Feb 08 19:35:08 volumio go-librespot[3307]: time="2026-02-08T19:35:08+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 19:35:08 volumio go-librespot[3307]: time="2026-02-08T19:35:08+07:00" level=debug msg="app state loaded" Feb 08 19:35:08 volumio go-librespot[3307]: time="2026-02-08T19:35:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 19:35:08 volumio go-librespot[3307]: time="2026-02-08T19:35:08+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 08 19:35:08 volumio go-librespot[3307]: time="2026-02-08T19:35:08+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 08 19:35:08 volumio go-librespot[3307]: time="2026-02-08T19:35:08+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 08 19:35:08 volumio go-librespot[3307]: time="2026-02-08T19:35:08+07:00" level=info msg="zeroconf server listening on port 34499" Feb 08 19:35:08 volumio volumio[3059]: info: Volumio called home Feb 08 19:35:08 volumio volumio[3059]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 08 19:35:08 volumio volumio[3059]: SPOTIFY: BQChfJdCWEmGjWuBbrYZiqpwy_UUp3qQqjNp8sNgITff9aQ8jPy_kkXwm_xgMENuQ5L947upXMfjtSl-7qLUZYjtIw7NVieBWyhrixX4aOBsiunwWGieXJTQdeWRJ-0diGevxiI5vZ1KoMLNO-kI09UEWH2Jm3dbtxmQTqZr1inzPjh7JXy6meFZd8-uEmDUU8Cmjp9NPI2DvjqA24Qk1xjQnZZRdic7puEo1HVIU7BTHlJixJweQOhMuLPXLYG7dd3d2XfGYC3Q9Q0fl2pN4ihOfo36z9zWs2JTatNxHrNydfOZyN7n_PlG Feb 08 19:35:08 volumio volumio[3059]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 08 19:35:08 volumio volumio[3059]: info: New Spotify access token = BQChfJdCWEmGjWuBbrYZiqpwy_UUp3qQqjNp8sNgITff9aQ8jPy_kkXwm_xgMENuQ5L947upXMfjtSl-7qLUZYjtIw7NVieBWyhrixX4aOBsiunwWGieXJTQdeWRJ-0diGevxiI5vZ1KoMLNO-kI09UEWH2Jm3dbtxmQTqZr1inzPjh7JXy6meFZd8-uEmDUU8Cmjp9NPI2DvjqA24Qk1xjQnZZRdic7puEo1HVIU7BTHlJixJweQOhMuLPXLYG7dd3d2XfGYC3Q9Q0fl2pN4ihOfo36z9zWs2JTatNxHrNydfOZyN7n_PlG Feb 08 19:35:08 volumio volumio[3059]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 08 19:35:08 volumio go-librespot[3307]: time="2026-02-08T19:35:08+07:00" level=debug msg="obtained new client token: AACBQ+Sg7GhHSpb1cGrQ6R9SNQDZcOZspRa9NoTPQ1ATCMzCG5VTJfYk/c0EgEpctQfl+ZP9jWG3k5qOmJkRzqsCfWMt+HqpWq2WKXpD3epPFdi2TBvUz+NNq8J1b39rUzKfiTz9ZC2JZZfbydEhkB5EfxrJn9a+2A5NFEN2hmac7AztfW5ZFnrwEiDVM4Oigm/kCQ+qP1ol8/nhqYcxuvDB4CByanZwHu/xTxE/BVkmt6Zdlh0xTUU0Ww==" Feb 08 19:35:08 volumio volumio[3059]: info: Starting Shairport Sync Feb 08 19:35:09 volumio volumio[3059]: info: Starting Shairport Sync Feb 08 19:35:09 volumio volumio[3059]: info: Starting Shairport Sync Feb 08 19:35:09 volumio go-librespot[3307]: time="2026-02-08T19:35:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 19:35:09 volumio sudo[3332]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 19:35:09 volumio sudo[3332]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 19:35:09 volumio sudo[3334]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 19:35:09 volumio sudo[3334]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 19:35:09 volumio sudo[3336]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 19:35:09 volumio sudo[3336]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 19:35:09 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 08 19:35:09 volumio go-librespot[3307]: time="2026-02-08T19:35:09+07:00" level=debug msg="completed keyexchange" Feb 08 19:35:09 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 08 19:35:09 volumio go-librespot[3307]: time="2026-02-08T19:35:09+07:00" level=debug msg="completed challenge" Feb 08 19:35:09 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 19:35:09 volumio systemd[1]: shairport-sync.service: Consumed 2.378s CPU time. Feb 08 19:35:09 volumio go-librespot[3307]: time="2026-02-08T19:35:09+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 08 19:35:09 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 19:35:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 19:35:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 19:35:09 volumio sudo[3332]: pam_unix(sudo:session): session closed for user root Feb 08 19:35:09 volumio volumio[3059]: info: Shairport-Sync Started Feb 08 19:35:09 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 08 19:35:09 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 08 19:35:09 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 19:35:09 volumio volumio[3059]: Error adding Membership: Error: addMembership EINVAL Feb 08 19:35:09 volumio volumio[3059]: info: CoreCommandRouter::volumioGetState Feb 08 19:35:09 volumio volumio[3059]: info: CorePlayQueue::getTrack 0 Feb 08 19:35:09 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 19:35:09 volumio sudo[3334]: pam_unix(sudo:session): session closed for user root Feb 08 19:35:09 volumio sudo[3336]: pam_unix(sudo:session): session closed for user root Feb 08 19:35:09 volumio volumio[3059]: info: Shairport-Sync Started Feb 08 19:35:09 volumio volumio[3059]: info: Shairport-Sync Started Feb 08 19:35:09 volumio volumio[3059]: 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 08 19:35:09 volumio volumio[3059]: info: Spotify Successfully logged in Feb 08 19:35:09 volumio volumio[3059]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 19:35:09 volumio volumio[3059]: info: [1770554109874] CoreMusicLibrary::Adding element Spotify Feb 08 19:35:09 volumio volumio[3059]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 19:35:09 volumio volumio[3059]: Cannot find translation for source YouTube Music Feb 08 19:35:09 volumio volumio[3059]: Cannot find translation for source Spotify Feb 08 19:35:10 volumio volumio[3059]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 08 19:35:10 volumio volumio[3059]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 19:35:10 volumio volumio[3059]: info: VolumeController:: Volume=100 Mute =false Feb 08 19:35:10 volumio volumio[3059]: info: CoreCommandRouter::volumioGetState Feb 08 19:35:10 volumio volumio[3059]: info: CorePlayQueue::getTrack 0 Feb 08 19:35:10 volumio volumio[3059]: info: CoreStateMachine::pushState Feb 08 19:35:10 volumio volumio[3059]: info: CorePlayQueue::getTrack 0 Feb 08 19:35:10 volumio volumio[3059]: info: CoreCommandRouter::volumioPushState Feb 08 19:35:11 volumio volumio[3059]: info: go-librespot daemon successfully initialized Feb 08 19:35:12 volumio mpd[3283]: 2026-02-08T19:35:12 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 08 19:35:12 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 08 19:35:12 volumio sudo[3243]: pam_unix(sudo:session): session closed for user root Feb 08 19:35:12 volumio sudo[3256]: pam_unix(sudo:session): session closed for user root Feb 08 19:35:12 volumio volumio[3059]: error: MPD error: The expression evaluated to a falsy value: Feb 08 19:35:12 volumio volumio[3059]: assert.ok(self.idling) Feb 08 19:35:12 volumio volumio[3059]: error: The expression evaluated to a falsy value: Feb 08 19:35:12 volumio volumio[3059]: assert.ok(self.idling) Feb 08 19:35:12 volumio volumio[3059]: info: MPD running with PID3283 Feb 08 19:35:12 volumio volumio[3059]: ,establishing connection Feb 08 19:35:12 volumio volumio[3059]: error: updateQueue error: null Feb 08 19:35:12 volumio volumio[3059]: info: Completed starting Core Plugins Feb 08 19:35:12 volumio volumio[3059]: info: ------------------------------------------- Feb 08 19:35:12 volumio volumio[3059]: info: ----- MyVolumio plugins startup ---- Feb 08 19:35:12 volumio volumio[3059]: info: ------------------------------------------- Feb 08 19:35:12 volumio volumio[3059]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 08 19:35:12 volumio volumio[3059]: error: updateQueue error: null Feb 08 19:35:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 08 19:35:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 19:35:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 19:35:12 volumio go-librespot[3391]: go-librespot daemon starting... Feb 08 19:35:12 volumio go-librespot[3392]: time="2026-02-08T19:35:12+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 19:35:12 volumio go-librespot[3392]: time="2026-02-08T19:35:12+07:00" level=debug msg="app state loaded" Feb 08 19:35:12 volumio go-librespot[3392]: time="2026-02-08T19:35:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 19:35:13 volumio go-librespot[3392]: time="2026-02-08T19:35:13+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 08 19:35:13 volumio go-librespot[3392]: time="2026-02-08T19:35:13+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 08 19:35:13 volumio go-librespot[3392]: time="2026-02-08T19:35:13+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 08 19:35:13 volumio go-librespot[3392]: time="2026-02-08T19:35:13+07:00" level=info msg="zeroconf server listening on port 43223" Feb 08 19:35:13 volumio go-librespot[3392]: time="2026-02-08T19:35:13+07:00" level=debug msg="obtained new client token: AAAvftcCadTyvTccuwrSx5GfWywc+PHkNY+O8LrsSO3CwMP7n6tFxjoMfKvHj4NRZhidGQqI10EwHpjTJUZ0HY6H6VaQoo4P36T8WEvNDw93IITwykEFYbe6uSxbEtLmYAUxjhGv8qvC2o2VrTrxLMGXFXeqaZLoyRr86AikeGQVtQ6REUeSr10k//AWD2qtTfkrAnJ4M+wU7kU85VuoKdgEpSgxgUSzY5nlDMHIUDexs6McgsxHUW3Ygw==" Feb 08 19:35:13 volumio go-librespot[3392]: time="2026-02-08T19:35:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 19:35:13 volumio go-librespot[3392]: time="2026-02-08T19:35:13+07:00" level=debug msg="completed keyexchange" Feb 08 19:35:13 volumio go-librespot[3392]: time="2026-02-08T19:35:13+07:00" level=debug msg="completed challenge" Feb 08 19:35:13 volumio go-librespot[3392]: time="2026-02-08T19:35:13+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 08 19:35:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 19:35:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 19:35:14 volumio volumio[3059]: info: Initializing connection to go-librespot Websocket Feb 08 19:35:14 volumio volumio[3059]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 19:35:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 08 19:35:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 19:35:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 19:35:16 volumio go-librespot[3399]: go-librespot daemon starting... Feb 08 19:35:16 volumio go-librespot[3400]: time="2026-02-08T19:35:16+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 19:35:16 volumio go-librespot[3400]: time="2026-02-08T19:35:16+07:00" level=debug msg="app state loaded" Feb 08 19:35:16 volumio go-librespot[3400]: time="2026-02-08T19:35:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 19:35:17 volumio volumio[3059]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 08 19:35:17 volumio go-librespot[3400]: time="2026-02-08T19:35:17+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 19:35:17 volumio go-librespot[3400]: time="2026-02-08T19:35:17+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 08 19:35:17 volumio go-librespot[3400]: time="2026-02-08T19:35:17+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 08 19:35:17 volumio go-librespot[3400]: time="2026-02-08T19:35:17+07:00" level=info msg="zeroconf server listening on port 36845" Feb 08 19:35:17 volumio go-librespot[3400]: time="2026-02-08T19:35:17+07:00" level=debug msg="obtained new client token: AACEKq9RudAayrAw9Ztr72WJp0kiBYaRY1NQEVE2e1ANvHd8AxyxOneHmaKliPxuerDHL2wUgbgtDMHN5hh53tM+zqJ5BS7h6CCanBjz2g/036Q8mg9fP+SDK4zRx5FAblaV+1iaxhvGajlC4zNv/NqgYfytDUk1lWVNPO1pKq0puNY3qwPcW/juZQMsNLwgh664tTVic1Uv/wilrdlZ+aoSjhiCSTW6XlSBwPoyU8IDX8HXQY049+pf8Q==" Feb 08 19:35:17 volumio go-librespot[3400]: time="2026-02-08T19:35:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 19:35:17 volumio go-librespot[3400]: time="2026-02-08T19:35:17+07:00" level=debug msg="completed keyexchange" Feb 08 19:35:17 volumio go-librespot[3400]: time="2026-02-08T19:35:17+07:00" level=debug msg="completed challenge" Feb 08 19:35:17 volumio volumio[3059]: info: Initializing connection to go-librespot Websocket Feb 08 19:35:17 volumio go-librespot[3400]: time="2026-02-08T19:35:17+07:00" level=debug msg="new websocket client" Feb 08 19:35:17 volumio volumio[3059]: info: Connection to go-librespot Websocket established Feb 08 19:35:17 volumio go-librespot[3400]: time="2026-02-08T19:35:17+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 08 19:35:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 19:35:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 19:35:17 volumio volumio[3059]: info: Connection to go-librespot Websocket closed Feb 08 19:35:20 volumio volumio[3059]: info: Getting Spotify volume Feb 08 19:35:20 volumio volumio[3059]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 19:35:20 volumio volumio[3059]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 19:35:20 volumio volumio[3059]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 08 19:35:20 volumio volumio[3059]: errno: -111, Feb 08 19:35:20 volumio volumio[3059]: code: 'ECONNREFUSED', Feb 08 19:35:20 volumio volumio[3059]: syscall: 'connect', Feb 08 19:35:20 volumio volumio[3059]: address: '127.0.0.1', Feb 08 19:35:20 volumio volumio[3059]: port: 9879, Feb 08 19:35:20 volumio volumio[3059]: response: undefined Feb 08 19:35:20 volumio volumio[3059]: } Feb 08 19:35:20 volumio volumio[3059]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 19:35:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 08 19:35:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 19:35:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 19:35:21 volumio go-librespot[3419]: go-librespot daemon starting... Feb 08 19:35:21 volumio go-librespot[3420]: time="2026-02-08T19:35:21+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 19:35:21 volumio go-librespot[3420]: time="2026-02-08T19:35:21+07:00" level=debug msg="app state loaded" Feb 08 19:35:21 volumio go-librespot[3420]: time="2026-02-08T19:35:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 19:35:21 volumio go-librespot[3420]: time="2026-02-08T19:35:21+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 08 19:35:21 volumio go-librespot[3420]: time="2026-02-08T19:35:21+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 08 19:35:21 volumio go-librespot[3420]: time="2026-02-08T19:35:21+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 08 19:35:21 volumio go-librespot[3420]: time="2026-02-08T19:35:21+07:00" level=info msg="zeroconf server listening on port 46201" Feb 08 19:35:21 volumio go-librespot[3420]: time="2026-02-08T19:35:21+07:00" level=debug msg="obtained new client token: AADkWxAWH32BhIffPdLEKX+DCcUDxDxG/ZLumqqujCaVVU2KWBabpSpDTXlFmydKgmqnjOq68XV8/SaLqCOE6aagpxoPKgQ+1BeKhtk0IYTob3QGhK+3NgF2ItpwWVZ2WCBYSB670N3OEP+avcKhAuGbxG8giyPHgso2sDWavCPv/3fCePaDgCVwP8Xj12kBKK7rpyixIbHuCxsxcMYO0yN2iec2xA2moT+iRmAaVmqPGpZTo1/SYLdexg==" Feb 08 19:35:22 volumio go-librespot[3420]: time="2026-02-08T19:35:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 19:35:22 volumio go-librespot[3420]: time="2026-02-08T19:35:22+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 08 19:35:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 19:35:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 19:35:22 volumio sudo[3444]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-08 19:34' Feb 08 19:35:22 volumio sudo[3444]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 19:35:22 volumio sudo[3444]: pam_unix(sudo:session): session closed for user root Feb 08 19:35:22 volumio volumio-remote-updater[643]: [2026-02-08 19:35:22] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 08 19:35:22 volumio volumio-remote-updater[643]: [2026-02-08 19:35:22] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 08 19:35:22 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 08 19:35:22 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 08 19:35:22 volumio systemd[1]: volumio.service: Consumed 49.179s CPU time. Feb 08 19:35:23 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 08 19:35:23 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 7683. Feb 08 19:35:23 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 08 19:35:23 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 08 19:35:23 volumio systemd[1]: volumio.service: Consumed 49.179s CPU time. Feb 08 19:35:23 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 08 19:35:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 08 19:35:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 19:35:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 19:35:25 volumio go-librespot[3465]: go-librespot daemon starting... Feb 08 19:35:25 volumio go-librespot[3466]: time="2026-02-08T19:35:25+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 19:35:25 volumio go-librespot[3466]: time="2026-02-08T19:35:25+07:00" level=debug msg="app state loaded" Feb 08 19:35:25 volumio go-librespot[3466]: time="2026-02-08T19:35:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 19:35:25 volumio go-librespot[3466]: time="2026-02-08T19:35: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 19:35:25 volumio go-librespot[3466]: time="2026-02-08T19:35:25+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 08 19:35:25 volumio go-librespot[3466]: time="2026-02-08T19:35:25+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 08 19:35:26 volumio go-librespot[3466]: time="2026-02-08T19:35:26+07:00" level=info msg="zeroconf server listening on port 46337" Feb 08 19:35:26 volumio go-librespot[3466]: time="2026-02-08T19:35:26+07:00" level=debug msg="obtained new client token: AABv2cqDQaBtibGDIZQV2ez2Hyt1UWocTpY9WK6J50Ik+Ps32oRzkKNskNyJV2K0ilqRfeQQA1VYm/x5ODKhovUAuZsZI0OWFFfPX0g0sMLSPUYxFB+Q6tRYas1sHNAW5hbKGUf3T5ydWZ9pquPX9LamnjdQ9wZb7XSYIE3cn7CHViOCLj0kXK6rY3plxQRG/y+4zP4uVmrBnc/g1299sexd+4t1MJM3JWGfWJmBkXJIZvqSmytWNCc=" Feb 08 19:35:26 volumio go-librespot[3466]: time="2026-02-08T19:35:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 19:35:26 volumio go-librespot[3466]: time="2026-02-08T19:35:26+07:00" level=debug msg="completed keyexchange" Feb 08 19:35:26 volumio go-librespot[3466]: time="2026-02-08T19:35:26+07:00" level=debug msg="completed challenge" Feb 08 19:35:26 volumio go-librespot[3466]: time="2026-02-08T19:35:26+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 19:35:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 19:35:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 19:35:26 volumio volumio[3455]: info: ------------------------------------------- Feb 08 19:35:26 volumio volumio[3455]: info: ----- Volumio3 ---- Feb 08 19:35:26 volumio volumio[3455]: info: ------------------------------------------- Feb 08 19:35:26 volumio volumio[3455]: info: ----- System startup ---- Feb 08 19:35:26 volumio volumio[3455]: info: ------------------------------------------- Feb 08 19:35:27 volumio volumio-remote-updater[643]: [2026-02-08 19:35:27] [connect] Successful connection Feb 08 19:35:28 volumio volumio[3455]: info: MYVOLUMIO Environment detected Feb 08 19:35:28 volumio volumio[3455]: info: Plugin folders cleanup Feb 08 19:35:28 volumio volumio[3455]: info: Scanning into folder /volumio/app/plugins/ Feb 08 19:35:28 volumio volumio[3455]: info: Scanning category audio_interface Feb 08 19:35:28 volumio volumio[3455]: info: Scanning category miscellanea Feb 08 19:35:28 volumio volumio[3455]: info: Scanning category music_service Feb 08 19:35:28 volumio volumio[3455]: info: Scanning category plugins.json Feb 08 19:35:28 volumio volumio[3455]: info: Scanning category system_controller Feb 08 19:35:28 volumio volumio[3455]: info: Scanning category user_interface Feb 08 19:35:28 volumio volumio[3455]: info: Scanning into folder /data/plugins/ Feb 08 19:35:28 volumio volumio[3455]: info: Scanning category music_service Feb 08 19:35:28 volumio volumio[3455]: info: Plugin folders cleanup completed Feb 08 19:35:28 volumio volumio[3455]: info: ------------------------------------------- Feb 08 19:35:28 volumio volumio[3455]: info: ----- Core plugins startup ---- Feb 08 19:35:28 volumio volumio[3455]: info: ------------------------------------------- Feb 08 19:35:28 volumio volumio[3455]: info: Loading plugins from folder /volumio/app/plugins/ Feb 08 19:35:28 volumio volumio[3455]: info: Adding plugin upnp to MyMusic Plugins Feb 08 19:35:28 volumio volumio[3455]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 08 19:35:28 volumio volumio[3455]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 08 19:35:28 volumio volumio[3455]: info: Loading plugins from folder /data/plugins/ Feb 08 19:35:28 volumio volumio[3455]: info: Loading plugin "system"... Feb 08 19:35:28 volumio volumio[3455]: info: Loading plugin "appearance"... Feb 08 19:35:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 08 19:35:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 19:35:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 19:35:29 volumio go-librespot[3486]: go-librespot daemon starting... Feb 08 19:35:29 volumio go-librespot[3487]: time="2026-02-08T19:35:29+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 19:35:29 volumio go-librespot[3487]: time="2026-02-08T19:35:29+07:00" level=debug msg="app state loaded" Feb 08 19:35:29 volumio go-librespot[3487]: time="2026-02-08T19:35:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 19:35:30 volumio volumio[3455]: info: Loading plugin "network"... Feb 08 19:35:30 volumio volumio[3455]: info: Refreshing Cached IP Addresses Feb 08 19:35:30 volumio go-librespot[3487]: time="2026-02-08T19:35:30+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 08 19:35:30 volumio go-librespot[3487]: time="2026-02-08T19:35:30+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 08 19:35:30 volumio go-librespot[3487]: time="2026-02-08T19:35:30+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 08 19:35:30 volumio sudo[3495]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 08 19:35:30 volumio sudo[3495]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 19:35:30 volumio go-librespot[3487]: time="2026-02-08T19:35:30+07:00" level=info msg="zeroconf server listening on port 34857" Feb 08 19:35:30 volumio sudo[3497]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 08 19:35:30 volumio sudo[3497]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 19:35:30 volumio sudo[3495]: pam_unix(sudo:session): session closed for user root Feb 08 19:35:30 volumio sudo[3497]: pam_unix(sudo:session): session closed for user root Feb 08 19:35:30 volumio volumio[3455]: info: Loading plugin "services"... Feb 08 19:35:30 volumio volumio[3455]: info: Loading plugin "alsa_controller"... Feb 08 19:35:30 volumio sudo[3509]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 08 19:35:30 volumio sudo[3509]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 19:35:30 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 19:35:30 volumio volumio[3455]: info: Loading plugin "wizard"... Feb 08 19:35:30 volumio volumio[3455]: info: Loading plugin "networkfs"... Feb 08 19:35:30 volumio go-librespot[3487]: time="2026-02-08T19:35:30+07:00" level=debug msg="obtained new client token: AADUnEJmjsIuBqFWigAmRGcGNNggwkLJeDDB8ej5+i3ZQm/kI/VwA5JS9cMslAPTh0UKEku780RwqaBo1v/zcvUC0saGMHpktSrq/vYoLzVQ1jiO2wTI9LFwvd6Fh7BCQHSAoKacu8cu4SwQq5fP4RVdCJbatDVMgHaDti16BU8l0cptkw890m1nxxm33JGCC7bzHAyYfsvdNCV7+I4+UyTgCyg4g1kgY/MUdHNuVjW4tqeOun7TpkDuhw==" Feb 08 19:35:30 volumio volumio[3455]: info: Starting Udev Watcher for removable devices Feb 08 19:35:30 volumio go-librespot[3487]: time="2026-02-08T19:35:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 19:35:30 volumio volumio[3455]: info: Ignoring mount for partition: boot Feb 08 19:35:30 volumio volumio[3455]: info: Ignoring mount for partition: volumio Feb 08 19:35:30 volumio volumio[3455]: info: Ignoring mount for partition: volumio_data Feb 08 19:35:30 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 19:35:30 volumio volumio[3455]: info: Loading plugin "volumio_command_line_client"... Feb 08 19:35:30 volumio volumio[3455]: info: Loading plugin "upnp"... Feb 08 19:35:30 volumio volumio[3455]: info: [1770554130600] Starting Upmpd Daemon Feb 08 19:35:30 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 19:35:30 volumio volumio[3455]: info: Loading plugin "my_music"... Feb 08 19:35:30 volumio volumio[3455]: info: Loading plugin "mpd"... Feb 08 19:35:30 volumio go-librespot[3487]: time="2026-02-08T19:35:30+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 08 19:35:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 19:35:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 19:35:31 volumio volumio[3455]: info: Loading plugin "upnp_browser"... Feb 08 19:35:33 volumio sudo[3509]: pam_unix(sudo:session): session closed for user root Feb 08 19:35:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 08 19:35:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 19:35:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 19:35:33 volumio go-librespot[3529]: go-librespot daemon starting... Feb 08 19:35:33 volumio go-librespot[3530]: time="2026-02-08T19:35:33+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 19:35:33 volumio go-librespot[3530]: time="2026-02-08T19:35:33+07:00" level=debug msg="app state loaded" Feb 08 19:35:33 volumio go-librespot[3530]: time="2026-02-08T19:35:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 19:35:34 volumio volumio[3455]: info: Starting UPNP Browser Feb 08 19:35:34 volumio volumio[3455]: info: Loading plugin "alarm-clock"... Feb 08 19:35:34 volumio go-librespot[3530]: time="2026-02-08T19:35:34+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 08 19:35:34 volumio go-librespot[3530]: time="2026-02-08T19:35:34+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 08 19:35:34 volumio go-librespot[3530]: time="2026-02-08T19:35:34+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 08 19:35:34 volumio go-librespot[3530]: time="2026-02-08T19:35:34+07:00" level=info msg="zeroconf server listening on port 46611" Feb 08 19:35:34 volumio volumio[3455]: info: Loading plugin "airplay_emulation"... Feb 08 19:35:34 volumio volumio[3455]: info: Starting Shairport Sync Feb 08 19:35:34 volumio volumio[3455]: info: Loading plugin "last_100"... Feb 08 19:35:34 volumio volumio[3455]: info: Loading plugin "webradio"... Feb 08 19:35:34 volumio go-librespot[3530]: time="2026-02-08T19:35:34+07:00" level=debug msg="obtained new client token: AAB+Z5UE6ZccYsrr0CR+YmBLF5/gEh4goUGJB8YLEl18AeWiir4aiXi6N8eFE8tOxfwHNdvbs/7DNkcpC2qYYNqB/Qrkwi3XQLWHzN9G4kxk1ZyWoZ8NvRwI4WWR85lbYxE9RE1M7XqpcmDkUpvza4Pn9k8ZAwZOGJx2E+m96QvW4e0A6ofeDjuIqMJG+PpVbw3uyrAZ/FRMe2d11KBG3mZV6RVLDK7jNhFMGCjpKHBrzggQRMNsajakKQ==" Feb 08 19:35:34 volumio volumio[3455]: info: Loading plugin "i2s_dacs"... Feb 08 19:35:34 volumio volumio[3455]: info: Loading plugin "volumiodiscovery"... Feb 08 19:35:34 volumio go-librespot[3530]: time="2026-02-08T19:35:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 19:35:34 volumio volumio[3455]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 08 19:35:34 volumio volumio[3455]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 19:35:34 volumio volumio[3455]: *** WARNING *** For more information see Feb 08 19:35:34 volumio volumio[3455]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 08 19:35:34 volumio volumio[3455]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 19:35:34 volumio volumio[3455]: *** WARNING *** For more information see Feb 08 19:35:34 volumio node[3455]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 08 19:35:34 volumio node[3455]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 19:35:34 volumio node[3455]: *** WARNING *** For more information see Feb 08 19:35:34 volumio node[3455]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 08 19:35:34 volumio node[3455]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 19:35:34 volumio node[3455]: *** WARNING *** For more information see Feb 08 19:35:34 volumio volumio[3455]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 08 19:35:34 volumio volumio[3455]: info: Discovery: Started advertising with name: Volumio Feb 08 19:35:34 volumio go-librespot[3530]: time="2026-02-08T19:35:34+07:00" level=debug msg="completed keyexchange" Feb 08 19:35:34 volumio go-librespot[3530]: time="2026-02-08T19:35:34+07:00" level=debug msg="completed challenge" Feb 08 19:35:34 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 19:35:34 volumio volumio[3455]: info: Loading plugin "spop"... Feb 08 19:35:34 volumio go-librespot[3530]: time="2026-02-08T19:35:34+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 08 19:35:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 19:35:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 19:35:36 volumio volumio[3455]: info: Loading plugin "ytcr"... Feb 08 19:35:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Feb 08 19:35:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 19:35:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 19:35:38 volumio go-librespot[3539]: go-librespot daemon starting... Feb 08 19:35:38 volumio go-librespot[3540]: time="2026-02-08T19:35:38+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 19:35:38 volumio go-librespot[3540]: time="2026-02-08T19:35:38+07:00" level=debug msg="app state loaded" Feb 08 19:35:38 volumio go-librespot[3540]: time="2026-02-08T19:35:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 19:35:38 volumio go-librespot[3540]: time="2026-02-08T19:35: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 08 19:35:38 volumio go-librespot[3540]: time="2026-02-08T19:35: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 08 19:35:38 volumio go-librespot[3540]: time="2026-02-08T19:35: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 08 19:35:38 volumio go-librespot[3540]: time="2026-02-08T19:35:38+07:00" level=info msg="zeroconf server listening on port 33215" Feb 08 19:35:38 volumio go-librespot[3540]: time="2026-02-08T19:35:38+07:00" level=debug msg="obtained new client token: AADHjZGXnZCQr+jdffMhNvSLKlu74t+wuRXLJ2HzeCthTNsDQ2sX2cNGKfNl2ymhhepmi1jUmtS+vC32bGrS1p53WE1OqYN7PPndvPHFB6QCWcTarRDy3TNksqU2UmMsuGMcfW61+MTHo5VB768I3WBTfI3yLt2XhR+VjnZ0/6wJK5St2YPFPwqCMqMUq1qwC+tylBnkfq98UvBqYF6J1phXDpewpdbKGmgO/ElvScgmgwXcIMbWHOEBKw==" Feb 08 19:35:39 volumio go-librespot[3540]: time="2026-02-08T19:35:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 19:35:39 volumio go-librespot[3540]: time="2026-02-08T19:35:39+07:00" level=debug msg="completed keyexchange" Feb 08 19:35:39 volumio go-librespot[3540]: time="2026-02-08T19:35:39+07:00" level=debug msg="completed challenge" Feb 08 19:35:39 volumio go-librespot[3540]: time="2026-02-08T19:35:39+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 19:35:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 19:35:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 19:35:39 volumio volumio[3455]: info: Loading plugin "ytmusic"... Feb 08 19:35:40 volumio volumio-remote-updater[643]: [2026-02-08 19:35:40] [connect] Successful connection Feb 08 19:35:40 volumio volumio[3455]: info: Loading plugin "outputs"... Feb 08 19:35:40 volumio volumio[3455]: info: Loading plugin "albumart"... Feb 08 19:35:40 volumio volumio[3455]: info: Plugin example_plugin is not enabled Feb 08 19:35:40 volumio volumio[3455]: info: Loading plugin "inputs"... Feb 08 19:35:40 volumio volumio[3455]: info: Loading plugin "updater_comm"... Feb 08 19:35:40 volumio volumio[3455]: info: Plugin mpdemulation is not enabled Feb 08 19:35:40 volumio volumio[3455]: info: Loading plugin "rest_api"... Feb 08 19:35:40 volumio volumio[3455]: info: Loading plugin "websocket"... Feb 08 19:35:40 volumio volumio[3455]: info: Starting Socket.io Server version 1.7.4 Feb 08 19:35:40 volumio volumio[3455]: info: Loading plugin "RoonBridge"... Feb 08 19:35:41 volumio volumio[3455]: info: Applying required configuration parameters for plugin RoonBridge Feb 08 19:35:41 volumio volumio[3455]: info: Loading i18n strings for locale en Feb 08 19:35:41 volumio volumio[3455]: Updating browse sources language Feb 08 19:35:41 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 19:35:41 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 19:35:41 volumio volumio[3455]: info: CoreCommandRouter::initPlayerControls Feb 08 19:35:41 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:41 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:41 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:41 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:41 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:41 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:41 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:41 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:41 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 19:35:41 volumio volumio[3455]: Express server listening on port 3000 Feb 08 19:35:41 volumio volumio[3455]: [Metrics] WebUI: 15s 895.10ms Feb 08 19:35:41 volumio volumio[3455]: info: CoreStateMachine::resetVolumioState Feb 08 19:35:41 volumio volumio[3455]: info: CoreStateMachine::getcurrentVolume Feb 08 19:35:41 volumio volumio[3455]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 19:35:41 volumio volumio[3561]: Forking 3 albumart workers Feb 08 19:35:41 volumio sudo[3577]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 08 19:35:41 volumio sudo[3577]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 19:35:41 volumio sudo[3577]: pam_unix(sudo:session): session closed for user root Feb 08 19:35:41 volumio sudo[3580]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 08 19:35:41 volumio sudo[3580]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 19:35:41 volumio sudo[3580]: pam_unix(sudo:session): session closed for user root Feb 08 19:35:41 volumio volumio[3455]: info: Volumio Network Manager: Network status updated: 1 Feb 08 19:35:42 volumio volumio-remote-updater[643]: [2026-02-08 19:35:42] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770554140 101 Feb 08 19:35:42 volumio volumio[3455]: 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 08 19:35:42 volumio volumio[3455]: info: VolumeController:: Volume=100 Mute =false Feb 08 19:35:42 volumio volumio[3455]: info: CoreStateMachine::pushState Feb 08 19:35:42 volumio volumio[3455]: info: CorePlayQueue::getTrack 0 Feb 08 19:35:42 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 08 19:35:42 volumio volumio[3455]: info: CoreCommandRouter::volumioPushState Feb 08 19:35:42 volumio volumio[3455]: info: CoreStateMachine::updateTrackBlock Feb 08 19:35:42 volumio volumio[3455]: info: CorePlayQueue::getTrackBlock Feb 08 19:35:42 volumio volumio[3455]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 19:35:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Feb 08 19:35:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 19:35:42 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 19:35:42 volumio volumio[3455]: info: Reloading queue from file Feb 08 19:35:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 19:35:42 volumio volumio[3455]: info: CoreStateMachine::setRepeat null single undefined Feb 08 19:35:42 volumio volumio[3455]: info: CoreStateMachine::pushState Feb 08 19:35:42 volumio volumio[3455]: info: CorePlayQueue::getTrack 0 Feb 08 19:35:42 volumio go-librespot[3616]: go-librespot daemon starting... Feb 08 19:35:42 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 08 19:35:42 volumio volumio[3455]: info: CoreCommandRouter::volumioPushState Feb 08 19:35:42 volumio volumio[3455]: info: CoreStateMachine::setRandom null Feb 08 19:35:42 volumio volumio[3455]: info: CoreStateMachine::pushState Feb 08 19:35:42 volumio volumio[3455]: info: CorePlayQueue::getTrack 0 Feb 08 19:35:42 volumio volumio[3455]: info: CoreCommandRouter::volumioPushState Feb 08 19:35:42 volumio go-librespot[3619]: time="2026-02-08T19:35:42+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 19:35:42 volumio go-librespot[3619]: time="2026-02-08T19:35:42+07:00" level=debug msg="app state loaded" Feb 08 19:35:42 volumio go-librespot[3619]: time="2026-02-08T19:35:42+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 19:35:42 volumio volumio[3455]: info: Setting Device type: Raspberry PI Feb 08 19:35:42 volumio volumio[3455]: info: Completed loading Core Plugins Feb 08 19:35:42 volumio volumio[3455]: info: Preparing to generate the ALSA configuration file Feb 08 19:35:42 volumio volumio[3455]: info: VolumeController:: Volume=100 Mute =false Feb 08 19:35:42 volumio volumio[3455]: info: CoreStateMachine::pushState Feb 08 19:35:42 volumio volumio[3455]: info: CorePlayQueue::getTrack 0 Feb 08 19:35:42 volumio volumio[3455]: info: CoreCommandRouter::volumioPushState Feb 08 19:35:42 volumio volumio[3455]: info: Asound.conf file unchanged, so no further update is needed Feb 08 19:35:42 volumio volumio[3455]: info: Output device has changed, restarting MPD Feb 08 19:35:42 volumio sudo[3628]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 08 19:35:42 volumio sudo[3628]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 19:35:43 volumio volumio[3455]: info: Output device has changed, restarting Shairport Sync Feb 08 19:35:43 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:43 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 19:35:43 volumio sudo[3628]: pam_unix(sudo:session): session closed for user root Feb 08 19:35:43 volumio sudo[3633]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 19:35:43 volumio sudo[3633]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 19:35:43 volumio sudo[3635]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 19:35:43 volumio sudo[3635]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 19:35:43 volumio sudo[3633]: pam_unix(sudo:session): session closed for user root Feb 08 19:35:43 volumio go-librespot[3619]: time="2026-02-08T19:35:43+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 19:35:43 volumio go-librespot[3619]: time="2026-02-08T19:35:43+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 08 19:35:43 volumio go-librespot[3619]: time="2026-02-08T19:35:43+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 08 19:35:43 volumio volumio[3455]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 19:35:43 volumio volumio[3455]: info: ___________ START PLUGINS ___________ Feb 08 19:35:43 volumio go-librespot[3619]: time="2026-02-08T19:35:43+07:00" level=info msg="zeroconf server listening on port 42883" Feb 08 19:35:43 volumio volumio[3455]: info: ControllerMpd::onStart: Initializing MPD Feb 08 19:35:43 volumio volumio[3455]: info: Creating MPD Configuration file Feb 08 19:35:43 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 08 19:35:43 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 19:35:43 volumio volumio[3455]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 19:35:43 volumio volumio[3455]: info: [1770554143291] CoreMusicLibrary::Adding element Media Servers Feb 08 19:35:43 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 19:35:43 volumio go-librespot[3619]: time="2026-02-08T19:35:43+07:00" level=debug msg="obtained new client token: AAAvi1X63OmUByGyl0LRUY8PJY90eln2UCkWlY4ndyLl9oO4MiqGDfvNlqXAWMXmqxjqHU24Vr1T292PaFPgYv1U0q/eUYjC2AbmuOU+2RmTJmpEbNc6uqK62zDkgWKc8yo9UMcgkpyUXNcRfnnCam0bALE09UCTn6SkjAfaZFbNrUDxb+4DQ6vbvp24KkSf4u4eCvRga/JLGenJESNhC/rYJGW5VglOF1QbpNjKIZT60xWOPfsWZenhqQ==" Feb 08 19:35:43 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 08 19:35:43 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 08 19:35:43 volumio systemd[1]: mpd.service: Consumed 7.122s CPU time. Feb 08 19:35:43 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 08 19:35:43 volumio sudo[3643]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 19:35:43 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 08 19:35:43 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 08 19:35:43 volumio sudo[3643]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 19:35:43 volumio sudo[3643]: pam_unix(sudo:session): session closed for user root Feb 08 19:35:43 volumio volumio[3455]: info: UPNP Browser: Client initialized successfully Feb 08 19:35:43 volumio sudo[3645]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 19:35:43 volumio sudo[3645]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 19:35:43 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 08 19:35:43 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 08 19:35:43 volumio go-librespot[3619]: time="2026-02-08T19:35:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 19:35:43 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:43 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 19:35:43 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 08 19:35:43 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 08 19:35:43 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 08 19:35:43 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 08 19:35:43 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 08 19:35:43 volumio go-librespot[3619]: time="2026-02-08T19:35:43+07:00" level=debug msg="completed keyexchange" Feb 08 19:35:43 volumio go-librespot[3619]: time="2026-02-08T19:35:43+07:00" level=debug msg="completed challenge" Feb 08 19:35:43 volumio volumio[3455]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 19:35:43 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:43 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 19:35:43 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 08 19:35:43 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 08 19:35:43 volumio go-librespot[3619]: time="2026-02-08T19:35:43+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 08 19:35:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 19:35:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 19:35:43 volumio volumio[3455]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 19:35:43 volumio volumio[3455]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 19:35:43 volumio volumio[3455]: info: [1770554143815] CoreMusicLibrary::Adding element Last_100 Feb 08 19:35:43 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 19:35:43 volumio volumio[3455]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 19:35:43 volumio volumio[3455]: info: [1770554143835] CoreMusicLibrary::Adding element Webradio Feb 08 19:35:43 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 19:35:43 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 19:35:43 volumio volumio[3455]: info: Initializing BBC Radios Feb 08 19:35:44 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 19:35:44 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 19:35:44 volumio volumio[3455]: info: Creating Spotify config file Feb 08 19:35:44 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:44 volumio sudo[3659]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 08 19:35:44 volumio sudo[3659]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 08 19:35:44 volumio sudo[3659]: pam_unix(sudo:session): session closed for user root Feb 08 19:35:44 volumio volumio[3581]: Starting albumart workers Feb 08 19:35:45 volumio volumio[3578]: Starting albumart workers Feb 08 19:35:45 volumio volumio[3455]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 19:35:45 volumio volumio[3455]: info: [1770554145174] CoreMusicLibrary::Adding element YouTube Music Feb 08 19:35:45 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 19:35:45 volumio volumio[3455]: Cannot find translation for source YouTube Music Feb 08 19:35:45 volumio volumio[3455]: info: Volumio Calling Home Feb 08 19:35:45 volumio sudo[3676]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 08 19:35:45 volumio sudo[3676]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 19:35:45 volumio volumio[3576]: Starting albumart workers Feb 08 19:35:45 volumio sudo[3676]: pam_unix(sudo:session): session closed for user root Feb 08 19:35:45 volumio volumio[3455]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 08 19:35:45 volumio volumio[3455]: info: Discovery: Found device Volumio Feb 08 19:35:45 volumio volumio[3455]: info: CoreCommandRouter::volumioGetState Feb 08 19:35:45 volumio volumio[3455]: info: CorePlayQueue::getTrack 0 Feb 08 19:35:45 volumio volumio[3455]: info: MPD Permissions set Feb 08 19:35:45 volumio volumio[3455]: info: MPD Permissions set Feb 08 19:35:45 volumio volumio[3455]: info: Upmpdcli Daemon Started Feb 08 19:35:45 volumio volumio[3455]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 08 19:35:45 volumio volumio[3455]: info: Discovery: Found device Volumio Feb 08 19:35:45 volumio volumio[3455]: info: CoreCommandRouter::volumioGetState Feb 08 19:35:45 volumio volumio[3455]: info: CorePlayQueue::getTrack 0 Feb 08 19:35:46 volumio volumio[3455]: info: Spotify config file written Feb 08 19:35:46 volumio sudo[3682]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 08 19:35:46 volumio sudo[3682]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 19:35:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 19:35:46 volumio volumio[3455]: 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 08 19:35:46 volumio volumio[3455]: info: Volumio called home Feb 08 19:35:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 19:35:46 volumio go-librespot[3684]: go-librespot daemon starting... Feb 08 19:35:46 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:46 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:46 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:46 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:46 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:46 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:46 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:46 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:46 volumio sudo[3682]: pam_unix(sudo:session): session closed for user root Feb 08 19:35:46 volumio go-librespot[3685]: time="2026-02-08T19:35:46+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 19:35:46 volumio go-librespot[3685]: time="2026-02-08T19:35:46+07:00" level=debug msg="app state loaded" Feb 08 19:35:46 volumio go-librespot[3685]: time="2026-02-08T19:35:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 19:35:46 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 19:35:46 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:46 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:46 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:46 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:46 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:46 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:46 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:46 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:46 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:46 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 19:35:46 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 19:35:46 volumio volumio[3455]: info: No need to fix Spotify hosts Feb 08 19:35:47 volumio go-librespot[3685]: time="2026-02-08T19:35:47+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 19:35:47 volumio go-librespot[3685]: time="2026-02-08T19:35:47+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 08 19:35:47 volumio go-librespot[3685]: time="2026-02-08T19:35:47+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 08 19:35:47 volumio go-librespot[3685]: time="2026-02-08T19:35:47+07:00" level=info msg="zeroconf server listening on port 38691" Feb 08 19:35:47 volumio go-librespot[3685]: time="2026-02-08T19:35:47+07:00" level=debug msg="obtained new client token: AADFwp6Y4b+W8QEbkKYBO1BEgqwhVQwDYQNn3gxbyYWx6hHAjBMAk9s9xEwIoUrMlysl7Hz3DENZ0+a/yMeNR78GWXfUTn42N8ivVsB+rQoZqaxnhkLuXtRvZYhGH3Ir8j2/1LAtN8v1EHK3i10Qm8iedwQ68IDElTsvIcAGeQkHCkE899pMlBFGDKrmvCJULNpyIW1mlP6l6kXWX0mYNigWT4IyD91WF2RaLOcmlZzM//A4riWwg97G0A==" Feb 08 19:35:47 volumio go-librespot[3685]: time="2026-02-08T19:35:47+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 19:35:47 volumio go-librespot[3685]: time="2026-02-08T19:35:47+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 08 19:35:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 19:35:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 19:35:47 volumio volumio[3455]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 08 19:35:47 volumio volumio[3455]: SPOTIFY: BQCXdrhfkvNda3uYnGaCmWqd8WsNS-skGs2Uvf7ZeKSqI_E36uvKnu7-chseovhdhSPlWa2xe3Xn_U_Jzg0kbWImVYIpipAyAaZVdnvdJ62oBgtbPmJmGI4i2dcjMXb6wBphx2dRfQXsgDAfmERt13ouVUt9byqWGO51FiZt_bfvYmox-s1I7KlItXSbSw0RLdwgTp6r-Boc8A8kOV0wle_ezWCD2PC-ESUkOtCWkBYniZBS6G3vTAHqhcRUDNeympkgNUGMInx1RZkg92c8EImsfYZc2V6pC5UFq_vZdlIlQot5i3s4gsSp Feb 08 19:35:47 volumio volumio[3455]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 08 19:35:47 volumio volumio[3455]: info: New Spotify access token = BQCXdrhfkvNda3uYnGaCmWqd8WsNS-skGs2Uvf7ZeKSqI_E36uvKnu7-chseovhdhSPlWa2xe3Xn_U_Jzg0kbWImVYIpipAyAaZVdnvdJ62oBgtbPmJmGI4i2dcjMXb6wBphx2dRfQXsgDAfmERt13ouVUt9byqWGO51FiZt_bfvYmox-s1I7KlItXSbSw0RLdwgTp6r-Boc8A8kOV0wle_ezWCD2PC-ESUkOtCWkBYniZBS6G3vTAHqhcRUDNeympkgNUGMInx1RZkg92c8EImsfYZc2V6pC5UFq_vZdlIlQot5i3s4gsSp Feb 08 19:35:47 volumio volumio[3455]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 08 19:35:47 volumio volumio[3455]: info: Starting Shairport Sync Feb 08 19:35:47 volumio volumio[3455]: info: Starting Shairport Sync Feb 08 19:35:47 volumio volumio[3455]: info: Starting Shairport Sync Feb 08 19:35:47 volumio sudo[3721]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 19:35:47 volumio sudo[3721]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 19:35:48 volumio sudo[3726]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 19:35:48 volumio sudo[3726]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 19:35:48 volumio sudo[3723]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 19:35:48 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 08 19:35:48 volumio sudo[3723]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 19:35:48 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 08 19:35:48 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 19:35:48 volumio systemd[1]: shairport-sync.service: Consumed 2.245s CPU time. Feb 08 19:35:48 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 19:35:48 volumio sudo[3721]: pam_unix(sudo:session): session closed for user root Feb 08 19:35:48 volumio volumio[3455]: info: Shairport-Sync Started Feb 08 19:35:48 volumio volumio[3455]: Error adding Membership: Error: addMembership EINVAL Feb 08 19:35:48 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 08 19:35:48 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 08 19:35:48 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 19:35:48 volumio volumio[3455]: info: CoreCommandRouter::volumioGetState Feb 08 19:35:48 volumio volumio[3455]: info: CorePlayQueue::getTrack 0 Feb 08 19:35:48 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 19:35:48 volumio volumio[3455]: 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 08 19:35:48 volumio volumio[3455]: info: Spotify Successfully logged in Feb 08 19:35:48 volumio volumio[3455]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 19:35:48 volumio volumio[3455]: info: [1770554148497] CoreMusicLibrary::Adding element Spotify Feb 08 19:35:48 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 19:35:48 volumio volumio[3455]: Cannot find translation for source YouTube Music Feb 08 19:35:48 volumio volumio[3455]: Cannot find translation for source Spotify Feb 08 19:35:48 volumio sudo[3726]: pam_unix(sudo:session): session closed for user root Feb 08 19:35:48 volumio sudo[3723]: pam_unix(sudo:session): session closed for user root Feb 08 19:35:48 volumio volumio[3455]: info: Shairport-Sync Started Feb 08 19:35:48 volumio volumio[3455]: info: Shairport-Sync Started Feb 08 19:35:49 volumio volumio[3455]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 08 19:35:49 volumio volumio[3455]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 19:35:49 volumio volumio[3455]: info: VolumeController:: Volume=100 Mute =false Feb 08 19:35:49 volumio volumio[3455]: info: CoreCommandRouter::volumioGetState Feb 08 19:35:49 volumio volumio[3455]: info: CorePlayQueue::getTrack 0 Feb 08 19:35:49 volumio volumio[3455]: info: CoreStateMachine::pushState Feb 08 19:35:49 volumio volumio[3455]: info: CorePlayQueue::getTrack 0 Feb 08 19:35:49 volumio volumio[3455]: info: CoreCommandRouter::volumioPushState Feb 08 19:35:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Feb 08 19:35:50 volumio volumio[3455]: info: go-librespot daemon successfully initialized Feb 08 19:35:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 19:35:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 19:35:50 volumio go-librespot[3763]: go-librespot daemon starting... Feb 08 19:35:50 volumio go-librespot[3764]: time="2026-02-08T19:35:50+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 19:35:50 volumio go-librespot[3764]: time="2026-02-08T19:35:50+07:00" level=debug msg="app state loaded" Feb 08 19:35:50 volumio go-librespot[3764]: time="2026-02-08T19:35:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 19:35:51 volumio mpd[3674]: 2026-02-08T19:35:51 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 08 19:35:51 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 08 19:35:51 volumio sudo[3645]: pam_unix(sudo:session): session closed for user root Feb 08 19:35:51 volumio sudo[3635]: pam_unix(sudo:session): session closed for user root Feb 08 19:35:51 volumio volumio[3455]: error: MPD error: The expression evaluated to a falsy value: Feb 08 19:35:51 volumio volumio[3455]: assert.ok(self.idling) Feb 08 19:35:51 volumio volumio[3455]: error: The expression evaluated to a falsy value: Feb 08 19:35:51 volumio volumio[3455]: assert.ok(self.idling) Feb 08 19:35:51 volumio volumio[3455]: info: MPD running with PID3674 Feb 08 19:35:51 volumio volumio[3455]: ,establishing connection Feb 08 19:35:51 volumio volumio[3455]: error: updateQueue error: null Feb 08 19:35:51 volumio go-librespot[3764]: time="2026-02-08T19:35:51+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 08 19:35:51 volumio go-librespot[3764]: time="2026-02-08T19:35:51+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 08 19:35:51 volumio go-librespot[3764]: time="2026-02-08T19:35:51+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 08 19:35:51 volumio go-librespot[3764]: time="2026-02-08T19:35:51+07:00" level=info msg="zeroconf server listening on port 40279" Feb 08 19:35:51 volumio volumio[3455]: info: Completed starting Core Plugins Feb 08 19:35:51 volumio volumio[3455]: info: ------------------------------------------- Feb 08 19:35:51 volumio volumio[3455]: info: ----- MyVolumio plugins startup ---- Feb 08 19:35:51 volumio volumio[3455]: info: ------------------------------------------- Feb 08 19:35:51 volumio volumio[3455]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 08 19:35:51 volumio volumio[3455]: error: updateQueue error: null Feb 08 19:35:51 volumio go-librespot[3764]: time="2026-02-08T19:35:51+07:00" level=debug msg="obtained new client token: AADd91JeMo1SHv6020uImNw+DLPJ5guSe86Q1Ahe60W7r8bVIQdjw9myZHzRh+18hgt4xyvTPA8Bb8LfvyvWFo31pHtkWIW3O37iWl5v6lYqiigKEdLgwB2UsrirNOFnwBbVf3RQwKN1SPr8Ja94PJHG5x3L4+6nh6ZvV0oely3RgepPRDGVlZAaOndpd/cfaKcsXBXPFbyKDzObaT+4ziTc3V1/dxZ7qgaYKHZltXcm938NwFl2oOdfig==" Feb 08 19:35:51 volumio go-librespot[3764]: time="2026-02-08T19:35:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 19:35:51 volumio go-librespot[3764]: time="2026-02-08T19:35:51+07:00" level=debug msg="completed keyexchange" Feb 08 19:35:51 volumio go-librespot[3764]: time="2026-02-08T19:35:51+07:00" level=debug msg="completed challenge" Feb 08 19:35:52 volumio go-librespot[3764]: time="2026-02-08T19:35:52+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 19:35:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 19:35:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 19:35:53 volumio volumio[3455]: info: Initializing connection to go-librespot Websocket Feb 08 19:35:53 volumio volumio[3455]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 19:35:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Feb 08 19:35:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 19:35:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 19:35:55 volumio go-librespot[3775]: go-librespot daemon starting... Feb 08 19:35:55 volumio go-librespot[3776]: time="2026-02-08T19:35:55+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 19:35:55 volumio go-librespot[3776]: time="2026-02-08T19:35:55+07:00" level=debug msg="app state loaded" Feb 08 19:35:55 volumio go-librespot[3776]: time="2026-02-08T19:35:55+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 19:35:55 volumio go-librespot[3776]: time="2026-02-08T19:35:55+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 08 19:35:55 volumio go-librespot[3776]: time="2026-02-08T19:35:55+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 08 19:35:55 volumio go-librespot[3776]: time="2026-02-08T19:35:55+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 08 19:35:55 volumio go-librespot[3776]: time="2026-02-08T19:35:55+07:00" level=info msg="zeroconf server listening on port 44927" Feb 08 19:35:55 volumio go-librespot[3776]: time="2026-02-08T19:35:55+07:00" level=debug msg="obtained new client token: AADfRVQYVwtP+1KUwKy8j6R1JhIy7jt7lQFb/49DhfTyiP36p+dSvCNpAoQRziYGbt/BNb/yvddM2hihcYZTP0mjq7KuK+FMaKRRIElcxrSiGsN9gcQO1tTjeBgmeuEb/86ipy0UVxpPVPD8ffZflm/y+Nvuc8QSxBIAvlSGtRL1npE0sVSmHpUY4fkmKV38QbxX6JQBq9lVuQmKEITg0KJ3+qF56esFxBBVRXajT6NdVOl7GKwbzRcVYQ==" Feb 08 19:35:56 volumio go-librespot[3776]: time="2026-02-08T19:35:56+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 19:35:56 volumio go-librespot[3776]: time="2026-02-08T19:35:56+07:00" level=debug msg="completed keyexchange" Feb 08 19:35:56 volumio go-librespot[3776]: time="2026-02-08T19:35:56+07:00" level=debug msg="completed challenge" Feb 08 19:35:56 volumio go-librespot[3776]: time="2026-02-08T19:35:56+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 08 19:35:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 19:35:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 19:35:56 volumio volumio[3455]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 08 19:35:56 volumio volumio[3455]: info: Initializing connection to go-librespot Websocket Feb 08 19:35:56 volumio volumio[3455]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 19:35:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Feb 08 19:35:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 19:35:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 19:35:59 volumio go-librespot[3783]: go-librespot daemon starting... Feb 08 19:35:59 volumio go-librespot[3784]: time="2026-02-08T19:35:59+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 19:35:59 volumio go-librespot[3784]: time="2026-02-08T19:35:59+07:00" level=debug msg="app state loaded" Feb 08 19:35:59 volumio go-librespot[3784]: time="2026-02-08T19:35:59+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 19:35:59 volumio volumio[3455]: info: Initializing connection to go-librespot Websocket Feb 08 19:35:59 volumio go-librespot[3784]: time="2026-02-08T19:35:59+07:00" level=debug msg="new websocket client" Feb 08 19:35:59 volumio go-librespot[3784]: time="2026-02-08T19:35: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 08 19:35:59 volumio go-librespot[3784]: time="2026-02-08T19:35:59+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 08 19:35:59 volumio go-librespot[3784]: time="2026-02-08T19:35:59+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 08 19:35:59 volumio volumio[3455]: info: Connection to go-librespot Websocket established Feb 08 19:35:59 volumio go-librespot[3784]: time="2026-02-08T19:35:59+07:00" level=info msg="zeroconf server listening on port 34431" Feb 08 19:36:00 volumio go-librespot[3784]: time="2026-02-08T19:36:00+07:00" level=debug msg="obtained new client token: AADvwTXSAcnWtsrXiPX2HkSX3aP2aLVDVCPe9T3L3ptoD3GUa7OjRUZG8CRe1yhdY9UncCbqVfIvcNc68dq+bJ1TQVHUyexh1KLgVFoKjd4pY8Rnce1AMwBuHWoZ+Q9c642K3/AAqrYFo4fYJWx3M3B6aVaGA3bKKUDTcqJBHn5uhidSupbJwkwGn6N50PO6DM2nyIlZdZhFSIgBAb2nTZL6jwkMEkc/LNRhqX1ywTDpLw6lYoFBURg=" Feb 08 19:36:00 volumio go-librespot[3784]: time="2026-02-08T19:36:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 19:36:00 volumio volumio[3455]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 08 19:36:00 volumio volumio[3455]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 08 19:36:00 volumio volumio[3455]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 08 19:36:00 volumio volumio[3455]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 08 19:36:00 volumio volumio[3455]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 08 19:36:00 volumio volumio[3455]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 08 19:36:00 volumio volumio[3455]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 08 19:36:00 volumio volumio[3455]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 08 19:36:00 volumio volumio[3455]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 08 19:36:00 volumio volumio[3455]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 08 19:36:00 volumio volumio[3455]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 08 19:36:00 volumio volumio[3455]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 08 19:36:00 volumio volumio[3455]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 08 19:36:00 volumio volumio[3455]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 08 19:36:00 volumio volumio[3455]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 08 19:36:00 volumio volumio[3455]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 08 19:36:00 volumio volumio[3455]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 08 19:36:00 volumio volumio[3455]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 08 19:36:00 volumio volumio[3455]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 08 19:36:00 volumio volumio[3455]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 08 19:36:00 volumio volumio[3455]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 08 19:36:00 volumio volumio[3455]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 08 19:36:00 volumio volumio[3455]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 08 19:36:00 volumio volumio[3455]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 08 19:36:00 volumio volumio[3455]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 08 19:36:00 volumio volumio[3455]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 08 19:36:00 volumio volumio[3455]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 08 19:36:00 volumio volumio[3455]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 08 19:36:00 volumio volumio[3455]: info: Adding plugin bluetooth to MyMusic Plugins Feb 08 19:36:00 volumio volumio[3455]: info: Adding plugin multiroom to MyMusic Plugins Feb 08 19:36:00 volumio volumio[3455]: info: Adding plugin metavolumio to MyMusic Plugins Feb 08 19:36:00 volumio volumio[3455]: info: Adding plugin cd_controller to MyMusic Plugins Feb 08 19:36:00 volumio volumio[3455]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 08 19:36:00 volumio volumio[3455]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 08 19:36:00 volumio volumio[3455]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 08 19:36:00 volumio go-librespot[3784]: time="2026-02-08T19:36:00+07:00" level=debug msg="completed keyexchange" Feb 08 19:36:00 volumio go-librespot[3784]: time="2026-02-08T19:36:00+07:00" level=debug msg="completed challenge" Feb 08 19:36:00 volumio volumio[3455]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 08 19:36:00 volumio go-librespot[3784]: time="2026-02-08T19:36:00+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 08 19:36:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 19:36:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 19:36:02 volumio volumio[3455]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 08 19:36:02 volumio volumio[3455]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 08 19:36:02 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 19:36:02 volumio volumio[3455]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 19:36:02 volumio volumio[3455]: info: Starting MyVolumio Remote Streaming Endpoints Feb 08 19:36:02 volumio volumio[3455]: info: MyVolumio login type: Token Feb 08 19:36:02 volumio volumio[3455]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 08 19:36:02 volumio volumio[3455]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 08 19:36:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Feb 08 19:36:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 19:36:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 19:36:03 volumio go-librespot[3805]: go-librespot daemon starting... Feb 08 19:36:03 volumio go-librespot[3806]: time="2026-02-08T19:36:03+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 19:36:03 volumio go-librespot[3806]: time="2026-02-08T19:36:03+07:00" level=debug msg="app state loaded" Feb 08 19:36:03 volumio go-librespot[3806]: time="2026-02-08T19:36:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 19:36:03 volumio volumio[3455]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 08 19:36:03 volumio volumio[3455]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 08 19:36:03 volumio volumio[3455]: info: Streaming services startup Feb 08 19:36:03 volumio volumio[3455]: info: Starting Streaming Daemon Feb 08 19:36:04 volumio sudo[3813]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 08 19:36:04 volumio sudo[3813]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 19:36:04 volumio volumio[3455]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 08 19:36:04 volumio sudo[3813]: pam_unix(sudo:session): session closed for user root Feb 08 19:36:04 volumio volumio[3455]: info: Getting Spotify volume Feb 08 19:36:04 volumio volumio[3455]: info: Connection to go-librespot Websocket closed Feb 08 19:36:04 volumio volumio[3455]: error: Cannot start Volumio Streaming Daemon Feb 08 19:36:04 volumio volumio[3455]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 08 19:36:04 volumio volumio[3455]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 08 19:36:04 volumio go-librespot[3806]: time="2026-02-08T19:36:04+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 08 19:36:04 volumio go-librespot[3806]: time="2026-02-08T19:36:04+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 08 19:36:04 volumio go-librespot[3806]: time="2026-02-08T19:36:04+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 08 19:36:04 volumio go-librespot[3806]: time="2026-02-08T19:36:04+07:00" level=info msg="zeroconf server listening on port 46113" Feb 08 19:36:04 volumio volumio[3455]: 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 08 19:36:04 volumio go-librespot[3806]: time="2026-02-08T19:36:04+07:00" level=debug msg="obtained new client token: AACUwtG+/DB26cq7xX5TmxgkLwLJJV69BD2f8PhNdQFPyeYNoSu+9tvDWbq7yF+EKh4dofHvZlkj3LLUuSghU15qA61zlIVkxEEdNWZlPYEFER7uqR9NTNC6qAyY4Y7T1skZIgWyyRJsO7acE/BVYDFzbnSHl3GK7EESiCfHAYI1Eq0QL//hRad3mOwJ6jwLk67ZCuUv8u/MIqi1jspKpR8LdG9Ad/Kgf95sNIlGWfIod+OHlfeE6IB1Pg==" Feb 08 19:36:04 volumio volumio[3455]: info: CoreCommandRouter::volumioGetState Feb 08 19:36:04 volumio volumio[3455]: info: CorePlayQueue::getTrack 0 Feb 08 19:36:04 volumio volumio[3455]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 08 19:36:04 volumio volumio[3455]: SPOTIFY: SPOTIFY VOLUME undefined Feb 08 19:36:04 volumio volumio[3455]: SPOTIFY: VOLUMIO VOLUME 100 Feb 08 19:36:04 volumio volumio[3455]: info: Aligning Spotify Volume to Volumio Volume Feb 08 19:36:04 volumio volumio[3455]: info: CoreCommandRouter::volumioGetState Feb 08 19:36:04 volumio volumio[3455]: info: CorePlayQueue::getTrack 0 Feb 08 19:36:04 volumio volumio[3455]: info: Setting Spotify Volume from Volumio: 100 Feb 08 19:36:04 volumio go-librespot[3806]: time="2026-02-08T19:36:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 19:36:04 volumio go-librespot[3806]: time="2026-02-08T19:36: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 08 19:36:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 19:36:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 19:36:04 volumio volumio[3455]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 19:36:04 volumio volumio[3455]: Error: socket hang up Feb 08 19:36:04 volumio volumio[3455]: at connResetException (node:internal/errors:720:14) Feb 08 19:36:04 volumio volumio[3455]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 08 19:36:04 volumio volumio[3455]: at Socket.emit (node:events:526:35) Feb 08 19:36:04 volumio volumio[3455]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 08 19:36:04 volumio volumio[3455]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 08 19:36:04 volumio volumio[3455]: code: 'ECONNRESET', Feb 08 19:36:04 volumio volumio[3455]: response: undefined Feb 08 19:36:04 volumio volumio[3455]: } Feb 08 19:36:04 volumio volumio[3455]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 19:36:06 volumio sudo[3835]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-08 19:35' Feb 08 19:36:06 volumio sudo[3835]: 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"