Feb 08 16:24:00 volumio volumio[3078]: info: Starting UPNP Browser Feb 08 16:24:00 volumio volumio[3078]: info: Loading plugin "alarm-clock"... Feb 08 16:24:00 volumio volumio[3078]: info: Loading plugin "airplay_emulation"... Feb 08 16:24:00 volumio volumio[3078]: info: Starting Shairport Sync Feb 08 16:24:00 volumio volumio[3078]: info: Loading plugin "last_100"... Feb 08 16:24:00 volumio volumio[3078]: info: Loading plugin "webradio"... Feb 08 16:24:00 volumio volumio[3078]: info: Loading plugin "i2s_dacs"... Feb 08 16:24:00 volumio volumio[3078]: info: Loading plugin "volumiodiscovery"... Feb 08 16:24:01 volumio volumio[3078]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 08 16:24:01 volumio volumio[3078]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 16:24:01 volumio node[3078]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 08 16:24:01 volumio volumio[3078]: *** WARNING *** For more information see Feb 08 16:24:01 volumio volumio[3078]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 08 16:24:01 volumio volumio[3078]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 16:24:01 volumio volumio[3078]: *** WARNING *** For more information see Feb 08 16:24:01 volumio node[3078]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 16:24:01 volumio node[3078]: *** WARNING *** For more information see Feb 08 16:24:01 volumio node[3078]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 08 16:24:01 volumio node[3078]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 16:24:01 volumio node[3078]: *** WARNING *** For more information see Feb 08 16:24:01 volumio volumio[3078]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 08 16:24:01 volumio volumio[3078]: info: Discovery: Started advertising with name: Volumio Feb 08 16:24:01 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 16:24:01 volumio volumio[3078]: info: Loading plugin "spop"... Feb 08 16:24:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 08 16:24:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:24:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:24:02 volumio go-librespot[3171]: go-librespot daemon starting... Feb 08 16:24:02 volumio volumio[3078]: info: Loading plugin "ytcr"... Feb 08 16:24:02 volumio go-librespot[3172]: time="2026-02-08T16:24:02+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 16:24:02 volumio go-librespot[3172]: time="2026-02-08T16:24:02+07:00" level=debug msg="app state loaded" Feb 08 16:24:02 volumio go-librespot[3172]: time="2026-02-08T16:24:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 16:24:03 volumio go-librespot[3172]: time="2026-02-08T16:24:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 16:24:03 volumio go-librespot[3172]: time="2026-02-08T16:24:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 08 16:24:03 volumio go-librespot[3172]: time="2026-02-08T16:24:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 08 16:24:03 volumio go-librespot[3172]: time="2026-02-08T16:24:03+07:00" level=info msg="zeroconf server listening on port 35833" Feb 08 16:24:03 volumio go-librespot[3172]: time="2026-02-08T16:24:03+07:00" level=debug msg="obtained new client token: AACmSpyTtmmFI4pbom+0pe9YckFsJ3ZGKgB0VFzhHNoSHjmo1VhEGLqtsygh6woaBBuaSClJVTkzvCkFPLCM7h29o8N26uq6KRdx6mfDtq4jYPoDPtMubVoKt+MFGO0Kxu4aCn8M7udYDhMe5xapqUJW92SJDD1ifJWwX2evbxWCNs21SOeXOS2VDfnd85NqDKsDFJczaNNG+orCFvg4CcB1031/1SmP1tjaXyhejwAiZ20ijsaBP4Tdng==" Feb 08 16:24:03 volumio go-librespot[3172]: time="2026-02-08T16:24:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 16:24:03 volumio go-librespot[3172]: time="2026-02-08T16:24:03+07:00" level=debug msg="completed keyexchange" Feb 08 16:24:03 volumio go-librespot[3172]: time="2026-02-08T16:24:03+07:00" level=debug msg="completed challenge" Feb 08 16:24:04 volumio go-librespot[3172]: time="2026-02-08T16:24:04+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 16:24:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 16:24:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 16:24:05 volumio volumio[3078]: info: Loading plugin "ytmusic"... Feb 08 16:24:06 volumio volumio-remote-updater[643]: [2026-02-08 16:24:06] [connect] Successful connection Feb 08 16:24:06 volumio volumio[3078]: info: Loading plugin "outputs"... Feb 08 16:24:06 volumio volumio[3078]: info: Loading plugin "albumart"... Feb 08 16:24:06 volumio volumio[3078]: info: Plugin example_plugin is not enabled Feb 08 16:24:06 volumio volumio[3078]: info: Loading plugin "inputs"... Feb 08 16:24:06 volumio volumio[3078]: info: Loading plugin "updater_comm"... Feb 08 16:24:06 volumio volumio[3078]: info: Plugin mpdemulation is not enabled Feb 08 16:24:06 volumio volumio[3078]: info: Loading plugin "rest_api"... Feb 08 16:24:06 volumio volumio[3078]: info: Loading plugin "websocket"... Feb 08 16:24:06 volumio volumio[3078]: info: Starting Socket.io Server version 1.7.4 Feb 08 16:24:07 volumio volumio[3078]: info: Loading plugin "RoonBridge"... Feb 08 16:24:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 08 16:24:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:24:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:24:07 volumio go-librespot[3203]: go-librespot daemon starting... Feb 08 16:24:07 volumio go-librespot[3204]: time="2026-02-08T16:24:07+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 16:24:07 volumio go-librespot[3204]: time="2026-02-08T16:24:07+07:00" level=debug msg="app state loaded" Feb 08 16:24:07 volumio go-librespot[3204]: time="2026-02-08T16:24:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 16:24:07 volumio volumio[3078]: info: Applying required configuration parameters for plugin RoonBridge Feb 08 16:24:07 volumio volumio[3078]: info: Loading i18n strings for locale en Feb 08 16:24:07 volumio volumio[3078]: Updating browse sources language Feb 08 16:24:07 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 16:24:07 volumio volumio[3193]: Forking 3 albumart workers Feb 08 16:24:07 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 16:24:07 volumio volumio[3078]: info: CoreCommandRouter::initPlayerControls Feb 08 16:24:07 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:07 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:07 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:07 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:07 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:07 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:07 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:07 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:07 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 16:24:07 volumio volumio[3078]: Express server listening on port 3000 Feb 08 16:24:07 volumio volumio[3078]: [Metrics] WebUI: 15s 981.72ms Feb 08 16:24:07 volumio volumio[3078]: info: CoreStateMachine::resetVolumioState Feb 08 16:24:07 volumio volumio[3078]: info: CoreStateMachine::getcurrentVolume Feb 08 16:24:07 volumio volumio[3078]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 16:24:08 volumio go-librespot[3204]: time="2026-02-08T16:24: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 16:24:08 volumio go-librespot[3204]: time="2026-02-08T16:24:08+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 16:24:08 volumio go-librespot[3204]: time="2026-02-08T16:24:08+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 16:24:08 volumio go-librespot[3204]: time="2026-02-08T16:24:08+07:00" level=info msg="zeroconf server listening on port 36643" Feb 08 16:24:08 volumio volumio[3078]: info: Volumio Network Manager: Network status updated: 1 Feb 08 16:24:08 volumio sudo[3247]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 08 16:24:08 volumio sudo[3247]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:24:08 volumio sudo[3245]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 08 16:24:08 volumio sudo[3245]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:24:08 volumio sudo[3247]: pam_unix(sudo:session): session closed for user root Feb 08 16:24:08 volumio sudo[3245]: pam_unix(sudo:session): session closed for user root Feb 08 16:24:08 volumio go-librespot[3204]: time="2026-02-08T16:24:08+07:00" level=debug msg="obtained new client token: AAAPJH9Ns3y52i0Cftvd+XtDsAaFI+ZxvNwAg3hw12aOu52C+wHkqMul9ezWY6/gljyfkojaUnfJs4cAddDWiZSdeujOAU/7SUfYMqTTWxToBG38T89AtRNspNP8I7dZo2fhC3apahEP4oSBbY1DgrfZQhq6W70VYN7rjMjwgrL04IOx3V3KiWrsQIi2zqGKNYeQCZKJ61j6kI4sWcMHWY8oECl6XyhSqMr9ugkiL6Dbs4ZI+4ZMhLU/tA==" Feb 08 16:24:08 volumio go-librespot[3204]: time="2026-02-08T16:24:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 16:24:08 volumio volumio[3078]: info: VolumeController:: Volume=100 Mute =false Feb 08 16:24:08 volumio volumio[3078]: info: CoreStateMachine::pushState Feb 08 16:24:08 volumio volumio[3078]: info: CorePlayQueue::getTrack 0 Feb 08 16:24:08 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 08 16:24:08 volumio volumio[3078]: info: CoreCommandRouter::volumioPushState Feb 08 16:24:08 volumio volumio[3078]: info: CoreStateMachine::updateTrackBlock Feb 08 16:24:08 volumio volumio[3078]: info: CorePlayQueue::getTrackBlock Feb 08 16:24:08 volumio volumio[3078]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 16:24:08 volumio go-librespot[3204]: time="2026-02-08T16:24:08+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 16:24:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 16:24:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 16:24:08 volumio volumio-remote-updater[643]: [2026-02-08 16:24:08] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770542646 101 Feb 08 16:24:08 volumio volumio[3078]: 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 16:24:08 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 16:24:08 volumio volumio[3078]: info: Reloading queue from file Feb 08 16:24:08 volumio volumio[3078]: info: CoreStateMachine::setRepeat null single undefined Feb 08 16:24:08 volumio volumio[3078]: info: CoreStateMachine::pushState Feb 08 16:24:08 volumio volumio[3078]: info: CorePlayQueue::getTrack 0 Feb 08 16:24:08 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 08 16:24:08 volumio volumio[3078]: info: CoreCommandRouter::volumioPushState Feb 08 16:24:08 volumio volumio[3078]: info: CoreStateMachine::setRandom null Feb 08 16:24:08 volumio volumio[3078]: info: CoreStateMachine::pushState Feb 08 16:24:08 volumio volumio[3078]: info: CorePlayQueue::getTrack 0 Feb 08 16:24:08 volumio volumio[3078]: info: CoreCommandRouter::volumioPushState Feb 08 16:24:08 volumio volumio[3078]: info: Setting Device type: Raspberry PI Feb 08 16:24:08 volumio volumio[3078]: info: Completed loading Core Plugins Feb 08 16:24:08 volumio volumio[3078]: info: Preparing to generate the ALSA configuration file Feb 08 16:24:08 volumio volumio[3078]: info: VolumeController:: Volume=100 Mute =false Feb 08 16:24:08 volumio volumio[3078]: info: CoreStateMachine::pushState Feb 08 16:24:08 volumio volumio[3078]: info: CorePlayQueue::getTrack 0 Feb 08 16:24:08 volumio volumio[3078]: info: CoreCommandRouter::volumioPushState Feb 08 16:24:08 volumio volumio[3078]: info: Asound.conf file unchanged, so no further update is needed Feb 08 16:24:08 volumio volumio[3078]: info: Output device has changed, restarting MPD Feb 08 16:24:09 volumio volumio[3078]: info: Output device has changed, restarting Shairport Sync Feb 08 16:24:09 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:09 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 16:24:09 volumio sudo[3264]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 08 16:24:09 volumio sudo[3264]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:24:09 volumio volumio[3078]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 16:24:09 volumio volumio[3078]: info: ___________ START PLUGINS ___________ Feb 08 16:24:09 volumio sudo[3266]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 16:24:09 volumio sudo[3266]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:24:09 volumio volumio[3078]: info: ControllerMpd::onStart: Initializing MPD Feb 08 16:24:09 volumio sudo[3268]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 16:24:09 volumio volumio[3078]: info: Creating MPD Configuration file Feb 08 16:24:09 volumio sudo[3268]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:24:09 volumio sudo[3266]: pam_unix(sudo:session): session closed for user root Feb 08 16:24:09 volumio sudo[3264]: pam_unix(sudo:session): session closed for user root Feb 08 16:24:09 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 16:24:09 volumio volumio[3078]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 16:24:09 volumio volumio[3078]: info: [1770542649236] CoreMusicLibrary::Adding element Media Servers Feb 08 16:24:09 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 16:24:09 volumio volumio[3078]: info: UPNP Browser: Client initialized successfully Feb 08 16:24:09 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 08 16:24:09 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:09 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 16:24:09 volumio sudo[3279]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 16:24:09 volumio sudo[3279]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:24:09 volumio sudo[3277]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 16:24:09 volumio sudo[3277]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:24:09 volumio sudo[3277]: pam_unix(sudo:session): session closed for user root Feb 08 16:24:09 volumio volumio[3078]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 16:24:09 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:09 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 16:24:09 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 08 16:24:09 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 08 16:24:09 volumio systemd[1]: mpd.service: Consumed 7.075s CPU time. Feb 08 16:24:09 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 08 16:24:09 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 08 16:24:09 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 08 16:24:09 volumio volumio[3078]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 16:24:09 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 08 16:24:09 volumio volumio[3078]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 16:24:09 volumio volumio[3078]: info: [1770542649565] CoreMusicLibrary::Adding element Last_100 Feb 08 16:24:09 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 16:24:09 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 08 16:24:09 volumio volumio[3078]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 16:24:09 volumio volumio[3078]: info: [1770542649589] CoreMusicLibrary::Adding element Webradio Feb 08 16:24:09 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 16:24:09 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 16:24:09 volumio volumio[3078]: info: Initializing BBC Radios Feb 08 16:24:09 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 08 16:24:09 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 08 16:24:09 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 08 16:24:09 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 08 16:24:09 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 08 16:24:09 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 08 16:24:09 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 08 16:24:09 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 16:24:09 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 16:24:09 volumio volumio[3078]: info: Creating Spotify config file Feb 08 16:24:09 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:10 volumio sudo[3303]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 08 16:24:10 volumio sudo[3303]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 08 16:24:10 volumio sudo[3303]: pam_unix(sudo:session): session closed for user root Feb 08 16:24:10 volumio volumio[3078]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 16:24:10 volumio volumio[3078]: info: [1770542650858] CoreMusicLibrary::Adding element YouTube Music Feb 08 16:24:10 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 16:24:10 volumio volumio[3078]: Cannot find translation for source YouTube Music Feb 08 16:24:10 volumio volumio[3078]: info: Volumio Calling Home Feb 08 16:24:10 volumio sudo[3310]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 08 16:24:10 volumio sudo[3310]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:24:11 volumio sudo[3310]: pam_unix(sudo:session): session closed for user root Feb 08 16:24:11 volumio volumio[3214]: Starting albumart workers Feb 08 16:24:11 volumio volumio[3215]: Starting albumart workers Feb 08 16:24:11 volumio volumio[3213]: Starting albumart workers Feb 08 16:24:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 08 16:24:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:24:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:24:11 volumio go-librespot[3315]: go-librespot daemon starting... Feb 08 16:24:11 volumio go-librespot[3316]: time="2026-02-08T16:24:11+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 16:24:11 volumio volumio[3078]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 08 16:24:11 volumio volumio[3078]: info: Discovery: Found device Volumio Feb 08 16:24:11 volumio volumio[3078]: info: CoreCommandRouter::volumioGetState Feb 08 16:24:11 volumio volumio[3078]: info: CorePlayQueue::getTrack 0 Feb 08 16:24:11 volumio volumio[3078]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 08 16:24:11 volumio volumio[3078]: info: Discovery: Found device Volumio Feb 08 16:24:11 volumio volumio[3078]: info: CoreCommandRouter::volumioGetState Feb 08 16:24:11 volumio volumio[3078]: info: CorePlayQueue::getTrack 0 Feb 08 16:24:11 volumio volumio[3078]: info: MPD Permissions set Feb 08 16:24:11 volumio volumio[3078]: info: MPD Permissions set Feb 08 16:24:11 volumio volumio[3078]: info: Upmpdcli Daemon Started Feb 08 16:24:11 volumio volumio[3078]: info: Volumio called home Feb 08 16:24:11 volumio volumio[3078]: info: Spotify config file written Feb 08 16:24:12 volumio volumio[3078]: 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 16:24:12 volumio sudo[3323]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 08 16:24:12 volumio sudo[3323]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:24:12 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:12 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:12 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:12 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:12 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:12 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:12 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:12 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:12 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 08 16:24:12 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 08 16:24:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:24:12 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 16:24:12 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:12 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:12 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:12 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:12 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:12 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:12 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:12 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:12 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:24:12 volumio go-librespot[3332]: go-librespot daemon starting... Feb 08 16:24:12 volumio sudo[3323]: pam_unix(sudo:session): session closed for user root Feb 08 16:24:12 volumio go-librespot[3333]: time="2026-02-08T16:24:12+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 16:24:12 volumio go-librespot[3333]: time="2026-02-08T16:24:12+07:00" level=debug msg="app state loaded" Feb 08 16:24:12 volumio go-librespot[3333]: time="2026-02-08T16:24:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 16:24:12 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 16:24:12 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:12 volumio volumio[3078]: info: No need to fix Spotify hosts Feb 08 16:24:13 volumio go-librespot[3333]: time="2026-02-08T16:24: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 16:24:13 volumio go-librespot[3333]: time="2026-02-08T16:24:13+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 16:24:13 volumio go-librespot[3333]: time="2026-02-08T16:24:13+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 16:24:13 volumio go-librespot[3333]: time="2026-02-08T16:24:13+07:00" level=info msg="zeroconf server listening on port 46513" Feb 08 16:24:13 volumio go-librespot[3333]: time="2026-02-08T16:24:13+07:00" level=debug msg="obtained new client token: AAALHC/HGxdGBQ9Jvs+nE1GXIl+8hu1qAFsUf6TwQXKXcVOu8nm1mHBy9YowiOhF8Ev638SPt05YTWFUx/E193QmbH+iEOfVfGTmDbqIXfhnBScg15bWY5o/vz9XChsEdsFlgDok6l+FjJ7g3eoaTTEo3io+InGvG0d760vnfm9kz/7sKccuTzoYerQ2S2qXkds046E4IC2dl2FDQASpv0bOstmBkOlo6pyJSZSPaf3nKTh+xYM7+/XOLA==" Feb 08 16:24:13 volumio go-librespot[3333]: time="2026-02-08T16:24:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 16:24:13 volumio go-librespot[3333]: time="2026-02-08T16:24:13+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 16:24:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 16:24:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 16:24:14 volumio volumio[3078]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 08 16:24:14 volumio volumio[3078]: SPOTIFY: BQBztlRXbrQDXp0oXfXt9VA5DAd4OpSX7WRPQXXVmNzwuaP9sjAw5rB39WECIliHVzOh8iGiasJbjtPFtq3Vn93mwfoeEK3FEtiLFSkp290RHUxvtD4y79pWHC2llo0PrbSpOflWZGdbdwBvlQ14nCTmRDgrRcqfkkxR_Dis6Oa5ZAJ_JxAkRSyyy9smUjTdJ1IiW1-vGzBUiIiMKpqDrf-a0eQ5DS09jjsluU3VLRftqmiDpPlW-9VID2P7f5c4pSgNJ0wykNBgzXtVgf2F64vxLHWEHYddvnJO2LyYZHggaMp88qw1GS-s Feb 08 16:24:14 volumio volumio[3078]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 08 16:24:14 volumio volumio[3078]: info: New Spotify access token = BQBztlRXbrQDXp0oXfXt9VA5DAd4OpSX7WRPQXXVmNzwuaP9sjAw5rB39WECIliHVzOh8iGiasJbjtPFtq3Vn93mwfoeEK3FEtiLFSkp290RHUxvtD4y79pWHC2llo0PrbSpOflWZGdbdwBvlQ14nCTmRDgrRcqfkkxR_Dis6Oa5ZAJ_JxAkRSyyy9smUjTdJ1IiW1-vGzBUiIiMKpqDrf-a0eQ5DS09jjsluU3VLRftqmiDpPlW-9VID2P7f5c4pSgNJ0wykNBgzXtVgf2F64vxLHWEHYddvnJO2LyYZHggaMp88qw1GS-s Feb 08 16:24:14 volumio volumio[3078]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 08 16:24:14 volumio volumio[3078]: info: Starting Shairport Sync Feb 08 16:24:14 volumio volumio[3078]: info: Starting Shairport Sync Feb 08 16:24:14 volumio volumio[3078]: info: Starting Shairport Sync Feb 08 16:24:14 volumio sudo[3365]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 16:24:14 volumio sudo[3365]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:24:14 volumio sudo[3369]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 16:24:14 volumio sudo[3369]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:24:14 volumio sudo[3367]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 16:24:14 volumio sudo[3367]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:24:14 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 08 16:24:14 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 08 16:24:14 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 16:24:14 volumio systemd[1]: shairport-sync.service: Consumed 2.248s CPU time. Feb 08 16:24:14 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 16:24:14 volumio sudo[3365]: pam_unix(sudo:session): session closed for user root Feb 08 16:24:14 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 08 16:24:14 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 08 16:24:14 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 16:24:14 volumio volumio[3078]: info: Shairport-Sync Started Feb 08 16:24:14 volumio volumio[3078]: Error adding Membership: Error: addMembership EINVAL Feb 08 16:24:14 volumio volumio[3078]: info: CoreCommandRouter::volumioGetState Feb 08 16:24:14 volumio volumio[3078]: info: CorePlayQueue::getTrack 0 Feb 08 16:24:14 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 16:24:14 volumio sudo[3367]: pam_unix(sudo:session): session closed for user root Feb 08 16:24:14 volumio sudo[3369]: pam_unix(sudo:session): session closed for user root Feb 08 16:24:14 volumio volumio[3078]: info: Shairport-Sync Started Feb 08 16:24:14 volumio volumio[3078]: info: Shairport-Sync Started Feb 08 16:24:14 volumio volumio[3078]: 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 16:24:14 volumio volumio[3078]: info: Spotify Successfully logged in Feb 08 16:24:14 volumio volumio[3078]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 16:24:14 volumio volumio[3078]: info: [1770542654841] CoreMusicLibrary::Adding element Spotify Feb 08 16:24:14 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 16:24:14 volumio volumio[3078]: Cannot find translation for source YouTube Music Feb 08 16:24:14 volumio volumio[3078]: Cannot find translation for source Spotify Feb 08 16:24:15 volumio volumio[3078]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 08 16:24:15 volumio volumio[3078]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 16:24:15 volumio volumio[3078]: info: VolumeController:: Volume=100 Mute =false Feb 08 16:24:15 volumio volumio[3078]: info: CoreCommandRouter::volumioGetState Feb 08 16:24:15 volumio volumio[3078]: info: CorePlayQueue::getTrack 0 Feb 08 16:24:15 volumio volumio[3078]: info: CoreStateMachine::pushState Feb 08 16:24:15 volumio volumio[3078]: info: CorePlayQueue::getTrack 0 Feb 08 16:24:15 volumio volumio[3078]: info: CoreCommandRouter::volumioPushState Feb 08 16:24:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 08 16:24:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:24:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:24:16 volumio go-librespot[3405]: go-librespot daemon starting... Feb 08 16:24:16 volumio go-librespot[3406]: time="2026-02-08T16:24:16+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 16:24:16 volumio go-librespot[3406]: time="2026-02-08T16:24:16+07:00" level=debug msg="app state loaded" Feb 08 16:24:16 volumio go-librespot[3406]: time="2026-02-08T16:24:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 16:24:16 volumio volumio[3078]: info: go-librespot daemon successfully initialized Feb 08 16:24:17 volumio mpd[3308]: 2026-02-08T16:24:17 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 08 16:24:17 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 08 16:24:17 volumio sudo[3268]: pam_unix(sudo:session): session closed for user root Feb 08 16:24:17 volumio sudo[3279]: pam_unix(sudo:session): session closed for user root Feb 08 16:24:17 volumio volumio[3078]: error: MPD error: The expression evaluated to a falsy value: Feb 08 16:24:17 volumio volumio[3078]: assert.ok(self.idling) Feb 08 16:24:17 volumio volumio[3078]: error: The expression evaluated to a falsy value: Feb 08 16:24:17 volumio volumio[3078]: assert.ok(self.idling) Feb 08 16:24:17 volumio volumio[3078]: error: updateQueue error: null Feb 08 16:24:17 volumio volumio[3078]: info: MPD running with PID3308 Feb 08 16:24:17 volumio volumio[3078]: ,establishing connection Feb 08 16:24:17 volumio go-librespot[3406]: time="2026-02-08T16:24: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 16:24:17 volumio go-librespot[3406]: time="2026-02-08T16:24:17+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 16:24:17 volumio go-librespot[3406]: time="2026-02-08T16:24:17+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 16:24:17 volumio go-librespot[3406]: time="2026-02-08T16:24:17+07:00" level=info msg="zeroconf server listening on port 42653" Feb 08 16:24:17 volumio volumio[3078]: info: Completed starting Core Plugins Feb 08 16:24:17 volumio volumio[3078]: info: ------------------------------------------- Feb 08 16:24:17 volumio volumio[3078]: info: ----- MyVolumio plugins startup ---- Feb 08 16:24:17 volumio volumio[3078]: info: ------------------------------------------- Feb 08 16:24:17 volumio volumio[3078]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 08 16:24:17 volumio volumio[3078]: error: updateQueue error: null Feb 08 16:24:17 volumio go-librespot[3406]: time="2026-02-08T16:24:17+07:00" level=debug msg="obtained new client token: AACT9MEY3tZ5j9g7oRQNVWVV4rCY6f/JkWfVlypDrHHrORcvmdg0p/i5jeIAIsJ+tx45vbNyr9Q4ThfnqzKEIDy6cVFPWYUTs1wUSY1mwtIGLWbS4+vmIU/loRmj4uSm2jYAzqumAxUoeLIME0dJCeWbk/X7qTbEWxbLX63XFBLsrl+6nTFj6e75qE0SH7VQB4FSZJBACxoOahHcrbGafb7U6S/kv+YaOvK3UOT2XSnjrp20xMcPrrsddw==" Feb 08 16:24:17 volumio go-librespot[3406]: time="2026-02-08T16:24:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 16:24:17 volumio go-librespot[3406]: time="2026-02-08T16:24:17+07:00" level=debug msg="completed keyexchange" Feb 08 16:24:17 volumio go-librespot[3406]: time="2026-02-08T16:24:17+07:00" level=debug msg="completed challenge" Feb 08 16:24:17 volumio go-librespot[3406]: time="2026-02-08T16:24: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 16:24:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 16:24:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 16:24:19 volumio volumio[3078]: info: Initializing connection to go-librespot Websocket Feb 08 16:24:20 volumio volumio[3078]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 16:24:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 08 16:24:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:24:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:24:21 volumio go-librespot[3417]: go-librespot daemon starting... Feb 08 16:24:21 volumio go-librespot[3418]: time="2026-02-08T16:24:21+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 16:24:21 volumio go-librespot[3418]: time="2026-02-08T16:24:21+07:00" level=debug msg="app state loaded" Feb 08 16:24:21 volumio go-librespot[3418]: time="2026-02-08T16:24:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 16:24:21 volumio go-librespot[3418]: time="2026-02-08T16:24: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 16:24:21 volumio go-librespot[3418]: time="2026-02-08T16:24:21+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 16:24:21 volumio go-librespot[3418]: time="2026-02-08T16:24:21+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 16:24:21 volumio go-librespot[3418]: time="2026-02-08T16:24:21+07:00" level=info msg="zeroconf server listening on port 44931" Feb 08 16:24:21 volumio go-librespot[3418]: time="2026-02-08T16:24:21+07:00" level=debug msg="obtained new client token: AACBTm/GOAxU1/O9vFQfbOLMabh+hbvlnDGHV3vAa/lmoPj6hng8qVjUriFMg0MkmGpAvusLnAJxkiZmFAKax/mVGPsAfq6wQX9F8cCYOok0VVreu9v1dla7g87339B3U1IRWckCfje+gVTSXkQzP6bmpv7qIEN98SY29xLyL730OSzdO9nWwY0y7uP6RAh3ryCP89glQOrwCJ+TN6mxXM0nSPhqdRVJ4pV4ArtEItAGZ8fcXCoWhApWyw==" Feb 08 16:24:21 volumio go-librespot[3418]: time="2026-02-08T16:24:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 16:24:22 volumio go-librespot[3418]: time="2026-02-08T16:24:22+07:00" level=debug msg="completed keyexchange" Feb 08 16:24:22 volumio go-librespot[3418]: time="2026-02-08T16:24:22+07:00" level=debug msg="completed challenge" Feb 08 16:24:22 volumio go-librespot[3418]: time="2026-02-08T16:24:22+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 16:24:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 16:24:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 16:24:22 volumio volumio[3078]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 08 16:24:23 volumio volumio[3078]: info: Initializing connection to go-librespot Websocket Feb 08 16:24:23 volumio volumio[3078]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 16:24:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 08 16:24:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:24:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:24:25 volumio go-librespot[3425]: go-librespot daemon starting... Feb 08 16:24:25 volumio go-librespot[3426]: time="2026-02-08T16:24:25+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 16:24:25 volumio go-librespot[3426]: time="2026-02-08T16:24:25+07:00" level=debug msg="app state loaded" Feb 08 16:24:25 volumio go-librespot[3426]: time="2026-02-08T16:24:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 16:24:25 volumio go-librespot[3426]: time="2026-02-08T16:24:25+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 08 16:24:25 volumio go-librespot[3426]: time="2026-02-08T16:24:25+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 08 16:24:25 volumio go-librespot[3426]: time="2026-02-08T16:24:25+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 08 16:24:25 volumio go-librespot[3426]: time="2026-02-08T16:24:25+07:00" level=info msg="zeroconf server listening on port 40395" Feb 08 16:24:26 volumio volumio[3078]: info: Initializing connection to go-librespot Websocket Feb 08 16:24:26 volumio go-librespot[3426]: time="2026-02-08T16:24:26+07:00" level=debug msg="new websocket client" Feb 08 16:24:26 volumio volumio[3078]: info: Connection to go-librespot Websocket established Feb 08 16:24:26 volumio volumio[3078]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 08 16:24:26 volumio volumio[3078]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 08 16:24:26 volumio volumio[3078]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 08 16:24:26 volumio volumio[3078]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 08 16:24:26 volumio volumio[3078]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 08 16:24:26 volumio volumio[3078]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 08 16:24:26 volumio volumio[3078]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 08 16:24:26 volumio volumio[3078]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 08 16:24:26 volumio volumio[3078]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 08 16:24:26 volumio volumio[3078]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 08 16:24:26 volumio volumio[3078]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 08 16:24:26 volumio volumio[3078]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 08 16:24:26 volumio volumio[3078]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 08 16:24:26 volumio volumio[3078]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 08 16:24:26 volumio volumio[3078]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 08 16:24:26 volumio volumio[3078]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 08 16:24:26 volumio volumio[3078]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 08 16:24:26 volumio volumio[3078]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 08 16:24:26 volumio volumio[3078]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 08 16:24:26 volumio volumio[3078]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 08 16:24:26 volumio volumio[3078]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 08 16:24:26 volumio volumio[3078]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 08 16:24:26 volumio volumio[3078]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 08 16:24:26 volumio volumio[3078]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 08 16:24:26 volumio volumio[3078]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 08 16:24:26 volumio volumio[3078]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 08 16:24:26 volumio volumio[3078]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 08 16:24:26 volumio volumio[3078]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 08 16:24:26 volumio go-librespot[3426]: time="2026-02-08T16:24:26+07:00" level=debug msg="obtained new client token: AAD0n4/UMRMaSu/MPrrEKNzx4xJccJW3qJ2muidpkxiClqNxSVEDy4ODsp18bOpi66u7QWfelosg9mvgpdKTgxUWs2nERNbcWc3Ro9IQAn1wq0UqQCF237h0oKT7WVzlNY6pfOGku/ZJ49HtyugV/m9Bu33qBjklHn6xdwVUAUrA2xSLEu6tzsOjAIAUHBrWUorY8kVZZsqAiTtK7hG+9LoAmVoV2/nXQ+AWtyBEHYa20ooLWLEtbzs=" Feb 08 16:24:26 volumio volumio[3078]: info: Adding plugin bluetooth to MyMusic Plugins Feb 08 16:24:26 volumio volumio[3078]: info: Adding plugin multiroom to MyMusic Plugins Feb 08 16:24:26 volumio volumio[3078]: info: Adding plugin metavolumio to MyMusic Plugins Feb 08 16:24:26 volumio volumio[3078]: info: Adding plugin cd_controller to MyMusic Plugins Feb 08 16:24:26 volumio volumio[3078]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 08 16:24:26 volumio volumio[3078]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 08 16:24:26 volumio volumio[3078]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 08 16:24:26 volumio volumio[3078]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 08 16:24:26 volumio go-librespot[3426]: time="2026-02-08T16:24:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 16:24:26 volumio go-librespot[3426]: time="2026-02-08T16:24:26+07:00" level=debug msg="completed keyexchange" Feb 08 16:24:26 volumio go-librespot[3426]: time="2026-02-08T16:24:26+07:00" level=debug msg="completed challenge" Feb 08 16:24:26 volumio go-librespot[3426]: time="2026-02-08T16:24: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 16:24:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 16:24:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 16:24:28 volumio volumio[3078]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 08 16:24:28 volumio volumio[3078]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 08 16:24:28 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 16:24:28 volumio volumio[3078]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 16:24:28 volumio volumio[3078]: info: Starting MyVolumio Remote Streaming Endpoints Feb 08 16:24:28 volumio volumio[3078]: info: MyVolumio login type: Token Feb 08 16:24:28 volumio volumio[3078]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 08 16:24:28 volumio volumio[3078]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 08 16:24:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 08 16:24:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:24:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:24:29 volumio go-librespot[3447]: go-librespot daemon starting... Feb 08 16:24:29 volumio go-librespot[3448]: time="2026-02-08T16:24:29+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 16:24:29 volumio go-librespot[3448]: time="2026-02-08T16:24:29+07:00" level=debug msg="app state loaded" Feb 08 16:24:29 volumio go-librespot[3448]: time="2026-02-08T16:24:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 16:24:29 volumio volumio[3078]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 08 16:24:29 volumio volumio[3078]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 08 16:24:29 volumio volumio[3078]: info: Streaming services startup Feb 08 16:24:29 volumio volumio[3078]: info: Starting Streaming Daemon Feb 08 16:24:29 volumio sudo[3455]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 08 16:24:29 volumio sudo[3455]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:24:29 volumio volumio[3078]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 08 16:24:30 volumio sudo[3455]: pam_unix(sudo:session): session closed for user root Feb 08 16:24:30 volumio volumio[3078]: info: Getting Spotify volume Feb 08 16:24:30 volumio volumio[3078]: info: Connection to go-librespot Websocket closed Feb 08 16:24:30 volumio volumio[3078]: error: Cannot start Volumio Streaming Daemon Feb 08 16:24:30 volumio volumio[3078]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 08 16:24:30 volumio volumio[3078]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 08 16:24:30 volumio volumio[3078]: 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 16:24:30 volumio go-librespot[3448]: time="2026-02-08T16:24: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 16:24:30 volumio go-librespot[3448]: time="2026-02-08T16:24:30+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 16:24:30 volumio go-librespot[3448]: time="2026-02-08T16:24:30+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 16:24:30 volumio go-librespot[3448]: time="2026-02-08T16:24:30+07:00" level=info msg="zeroconf server listening on port 41433" Feb 08 16:24:30 volumio volumio[3078]: info: CoreCommandRouter::volumioGetState Feb 08 16:24:30 volumio volumio[3078]: info: CorePlayQueue::getTrack 0 Feb 08 16:24:30 volumio volumio[3078]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 08 16:24:30 volumio volumio[3078]: SPOTIFY: SPOTIFY VOLUME undefined Feb 08 16:24:30 volumio volumio[3078]: SPOTIFY: VOLUMIO VOLUME 100 Feb 08 16:24:30 volumio volumio[3078]: info: Aligning Spotify Volume to Volumio Volume Feb 08 16:24:30 volumio volumio[3078]: info: CoreCommandRouter::volumioGetState Feb 08 16:24:30 volumio volumio[3078]: info: CorePlayQueue::getTrack 0 Feb 08 16:24:30 volumio volumio[3078]: info: Setting Spotify Volume from Volumio: 100 Feb 08 16:24:30 volumio go-librespot[3448]: time="2026-02-08T16:24:30+07:00" level=debug msg="obtained new client token: AAAd+Em0SFleQHV97hWMYDlnOZQwC6COIYZ/HZrvw1NWUEczILkq1MKGnbl4AdqVRo0DWAwYLr8B8F/0LlleslM9WAz1khR1vNREcCvio2qpR2B8Yc3iF9Bi5FQwBiseLqXpfFBpW53vzgGSEVdkBHkYJbgmqYurIzjOrtT1LaixbJwNh7uie26sXwLaUBg0D5Lrndd99ojPPSxnQqAj3BGlc1RZkngGe51/m0n+J0jL0FM8pm7lyZhfXg==" Feb 08 16:24:30 volumio go-librespot[3448]: time="2026-02-08T16:24:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 16:24:30 volumio go-librespot[3448]: time="2026-02-08T16:24:30+07:00" level=debug msg="completed keyexchange" Feb 08 16:24:30 volumio go-librespot[3448]: time="2026-02-08T16:24:30+07:00" level=debug msg="completed challenge" Feb 08 16:24:30 volumio go-librespot[3448]: time="2026-02-08T16:24:30+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 16:24:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 16:24:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 16:24:30 volumio volumio[3078]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 16:24:30 volumio volumio[3078]: Error: socket hang up Feb 08 16:24:30 volumio volumio[3078]: at connResetException (node:internal/errors:720:14) Feb 08 16:24:30 volumio volumio[3078]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 08 16:24:30 volumio volumio[3078]: at Socket.emit (node:events:526:35) Feb 08 16:24:30 volumio volumio[3078]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 08 16:24:30 volumio volumio[3078]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 08 16:24:30 volumio volumio[3078]: code: 'ECONNRESET', Feb 08 16:24:30 volumio volumio[3078]: response: undefined Feb 08 16:24:30 volumio volumio[3078]: } Feb 08 16:24:30 volumio volumio[3078]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 16:24:32 volumio sudo[3477]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-08 16:23' Feb 08 16:24:32 volumio sudo[3477]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:24:32 volumio sudo[3477]: pam_unix(sudo:session): session closed for user root Feb 08 16:24:32 volumio volumio-remote-updater[643]: [2026-02-08 16:24:32] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 08 16:24:32 volumio volumio-remote-updater[643]: [2026-02-08 16:24:32] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 08 16:24:32 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 08 16:24:32 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 08 16:24:32 volumio systemd[1]: volumio.service: Consumed 55.510s CPU time. Feb 08 16:24:32 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 08 16:24:32 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 08 16:24:32 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 7466. Feb 08 16:24:32 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 08 16:24:32 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 08 16:24:32 volumio systemd[1]: volumio.service: Consumed 55.510s CPU time. Feb 08 16:24:32 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 08 16:24:32 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 08 16:24:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 08 16:24:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:24:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:24:34 volumio go-librespot[3511]: go-librespot daemon starting... Feb 08 16:24:34 volumio go-librespot[3512]: time="2026-02-08T16:24:34+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 16:24:34 volumio go-librespot[3512]: time="2026-02-08T16:24:34+07:00" level=debug msg="app state loaded" Feb 08 16:24:34 volumio go-librespot[3512]: time="2026-02-08T16:24:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 16:24:34 volumio go-librespot[3512]: time="2026-02-08T16:24: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-gew4.spotify.com:80]" Feb 08 16:24:34 volumio go-librespot[3512]: time="2026-02-08T16:24:34+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 16:24:34 volumio go-librespot[3512]: time="2026-02-08T16:24:34+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 16:24:34 volumio go-librespot[3512]: time="2026-02-08T16:24:34+07:00" level=info msg="zeroconf server listening on port 35833" Feb 08 16:24:34 volumio go-librespot[3512]: time="2026-02-08T16:24:34+07:00" level=debug msg="obtained new client token: AABoFq9KCHeY907WIRXIzTlsY3p+IacHkz8RWqLiXx4ighe3N+/+mVBi6dDPF4rZzz05uyjUXMZbbZ5eMDE6FY/rMLxIPPwZM9QinyRMvpBTFCK3+dEzsxplZxNQs9CgBn/qVVyqMVKiRWi+IRc5v2N74kXM6a1BruyC5v2K27c3WggYottDRsX15TjX6Tvhf9OWK6ShBKVesZBJv0MVUbvMrT1ruw7FPnBuF8qIGo070M14BC2EXWThPA==" Feb 08 16:24:34 volumio go-librespot[3512]: time="2026-02-08T16:24:34+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 08 16:24:35 volumio go-librespot[3512]: time="2026-02-08T16:24:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 08 16:24:35 volumio go-librespot[3512]: time="2026-02-08T16:24:35+07:00" level=debug msg="completed keyexchange" Feb 08 16:24:35 volumio go-librespot[3512]: time="2026-02-08T16:24:35+07:00" level=debug msg="completed challenge" Feb 08 16:24:35 volumio go-librespot[3512]: time="2026-02-08T16:24:35+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 16:24:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 16:24:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 16:24:36 volumio volumio[3495]: info: ------------------------------------------- Feb 08 16:24:36 volumio volumio[3495]: info: ----- Volumio3 ---- Feb 08 16:24:36 volumio volumio[3495]: info: ------------------------------------------- Feb 08 16:24:36 volumio volumio[3495]: info: ----- System startup ---- Feb 08 16:24:36 volumio volumio[3495]: info: ------------------------------------------- Feb 08 16:24:37 volumio volumio-remote-updater[643]: [2026-02-08 16:24:37] [connect] Successful connection Feb 08 16:24:37 volumio volumio[3495]: info: MYVOLUMIO Environment detected Feb 08 16:24:38 volumio volumio[3495]: info: Plugin folders cleanup Feb 08 16:24:38 volumio volumio[3495]: info: Scanning into folder /volumio/app/plugins/ Feb 08 16:24:38 volumio volumio[3495]: info: Scanning category audio_interface Feb 08 16:24:38 volumio volumio[3495]: info: Scanning category miscellanea Feb 08 16:24:38 volumio volumio[3495]: info: Scanning category music_service Feb 08 16:24:38 volumio volumio[3495]: info: Scanning category plugins.json Feb 08 16:24:38 volumio volumio[3495]: info: Scanning category system_controller Feb 08 16:24:38 volumio volumio[3495]: info: Scanning category user_interface Feb 08 16:24:38 volumio volumio[3495]: info: Scanning into folder /data/plugins/ Feb 08 16:24:38 volumio volumio[3495]: info: Scanning category music_service Feb 08 16:24:38 volumio volumio[3495]: info: Plugin folders cleanup completed Feb 08 16:24:38 volumio volumio[3495]: info: ------------------------------------------- Feb 08 16:24:38 volumio volumio[3495]: info: ----- Core plugins startup ---- Feb 08 16:24:38 volumio volumio[3495]: info: ------------------------------------------- Feb 08 16:24:38 volumio volumio[3495]: info: Loading plugins from folder /volumio/app/plugins/ Feb 08 16:24:38 volumio volumio[3495]: info: Adding plugin upnp to MyMusic Plugins Feb 08 16:24:38 volumio volumio[3495]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 08 16:24:38 volumio volumio[3495]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 08 16:24:38 volumio volumio[3495]: info: Loading plugins from folder /data/plugins/ Feb 08 16:24:38 volumio volumio[3495]: info: Loading plugin "system"... Feb 08 16:24:38 volumio volumio[3495]: info: Loading plugin "appearance"... Feb 08 16:24:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 08 16:24:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:24:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:24:38 volumio go-librespot[3531]: go-librespot daemon starting... Feb 08 16:24:38 volumio go-librespot[3532]: time="2026-02-08T16:24:38+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 16:24:38 volumio go-librespot[3532]: time="2026-02-08T16:24:38+07:00" level=debug msg="app state loaded" Feb 08 16:24:38 volumio go-librespot[3532]: time="2026-02-08T16:24:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 16:24:38 volumio go-librespot[3532]: time="2026-02-08T16:24: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 16:24:38 volumio go-librespot[3532]: time="2026-02-08T16:24:38+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 16:24:38 volumio go-librespot[3532]: time="2026-02-08T16:24:38+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 16:24:39 volumio go-librespot[3532]: time="2026-02-08T16:24:39+07:00" level=info msg="zeroconf server listening on port 41849" Feb 08 16:24:39 volumio go-librespot[3532]: time="2026-02-08T16:24:39+07:00" level=debug msg="obtained new client token: AAA1oqBOUbregCnx9Xfc0W7Bppoq7Yd39egZBSnirUddJ+eVlbAu8UFy3DInLJsZwxs03BhSrdyM7jaAQ/k0sWkpMb0MHaG4uCoNSrAsF6dCNUguq+ffFPh4p38X4Du8MmxvO95VJRwTgJQeotTqvV7Q7WhiyP8vVj/MptaovjPgmWZfnlO1+VkA8RjH0pFUvIjlvrAeObzsKLK6bCYM/dXQ14rbwuDuzjS0U8O2F3jxxexjjtP/sZY=" Feb 08 16:24:39 volumio go-librespot[3532]: time="2026-02-08T16:24:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 16:24:39 volumio go-librespot[3532]: time="2026-02-08T16:24:39+07:00" level=debug msg="completed keyexchange" Feb 08 16:24:39 volumio go-librespot[3532]: time="2026-02-08T16:24:39+07:00" level=debug msg="completed challenge" Feb 08 16:24:39 volumio go-librespot[3532]: time="2026-02-08T16:24: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 16:24:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 16:24:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 16:24:40 volumio volumio[3495]: info: Loading plugin "network"... Feb 08 16:24:40 volumio volumio[3495]: info: Refreshing Cached IP Addresses Feb 08 16:24:40 volumio sudo[3540]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 08 16:24:40 volumio sudo[3540]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:24:40 volumio sudo[3542]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 08 16:24:40 volumio sudo[3542]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:24:40 volumio sudo[3540]: pam_unix(sudo:session): session closed for user root Feb 08 16:24:40 volumio volumio[3495]: info: Loading plugin "services"... Feb 08 16:24:40 volumio volumio[3495]: info: Loading plugin "alsa_controller"... Feb 08 16:24:40 volumio sudo[3542]: pam_unix(sudo:session): session closed for user root Feb 08 16:24:40 volumio sudo[3549]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 08 16:24:40 volumio sudo[3549]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:24:40 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 16:24:40 volumio volumio[3495]: info: Loading plugin "wizard"... Feb 08 16:24:40 volumio volumio[3495]: info: Loading plugin "networkfs"... Feb 08 16:24:40 volumio volumio[3495]: info: Starting Udev Watcher for removable devices Feb 08 16:24:40 volumio volumio[3495]: info: Ignoring mount for partition: boot Feb 08 16:24:40 volumio volumio[3495]: info: Ignoring mount for partition: volumio Feb 08 16:24:40 volumio volumio[3495]: info: Ignoring mount for partition: volumio_data Feb 08 16:24:40 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 16:24:40 volumio volumio[3495]: info: Loading plugin "volumio_command_line_client"... Feb 08 16:24:40 volumio volumio[3495]: info: Loading plugin "upnp"... Feb 08 16:24:40 volumio volumio[3495]: info: [1770542680501] Starting Upmpd Daemon Feb 08 16:24:40 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 16:24:40 volumio volumio[3495]: info: Loading plugin "my_music"... Feb 08 16:24:40 volumio volumio[3495]: info: Loading plugin "mpd"... Feb 08 16:24:41 volumio volumio[3495]: info: Loading plugin "upnp_browser"... Feb 08 16:24:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 08 16:24:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:24:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:24:42 volumio go-librespot[3575]: go-librespot daemon starting... Feb 08 16:24:42 volumio go-librespot[3576]: time="2026-02-08T16:24:42+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 16:24:42 volumio go-librespot[3576]: time="2026-02-08T16:24:42+07:00" level=debug msg="app state loaded" Feb 08 16:24:42 volumio go-librespot[3576]: time="2026-02-08T16:24:42+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 16:24:42 volumio sudo[3549]: pam_unix(sudo:session): session closed for user root Feb 08 16:24:43 volumio go-librespot[3576]: time="2026-02-08T16:24: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-gew1.spotify.com:80]" Feb 08 16:24:43 volumio go-librespot[3576]: time="2026-02-08T16:24:43+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 16:24:43 volumio go-librespot[3576]: time="2026-02-08T16:24:43+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 16:24:43 volumio go-librespot[3576]: time="2026-02-08T16:24:43+07:00" level=info msg="zeroconf server listening on port 43387" Feb 08 16:24:43 volumio go-librespot[3576]: time="2026-02-08T16:24:43+07:00" level=debug msg="obtained new client token: AADeOFQnAeej9inciHDqXBtaDlWBykAHNNBNTdPUAij8J8lrQJfD4gDNO0ucMBA14DfcpdtE7pbCnRxGGOKkYSdIaoo5YehPN1igxnYf67Kq8BoIvfTtfLxLEZDV4FpylpsN+DLAy/X1YBsUcdMOlTwH+WWmvlSGWxJ9wSTiYa459lYh/Yp0+70GTGWKU9pq+960995nrKd4ppkEIDn+0HjkpMJu9j4WLJlAEBiCsdhR4NaoWEyfFQ0szA==" Feb 08 16:24:43 volumio go-librespot[3576]: time="2026-02-08T16:24:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 16:24:43 volumio go-librespot[3576]: time="2026-02-08T16:24:43+07:00" level=debug msg="completed keyexchange" Feb 08 16:24:43 volumio go-librespot[3576]: time="2026-02-08T16:24:43+07:00" level=debug msg="completed challenge" Feb 08 16:24:43 volumio go-librespot[3576]: time="2026-02-08T16:24: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 16:24:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 16:24:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 16:24:44 volumio volumio[3495]: info: Starting UPNP Browser Feb 08 16:24:44 volumio volumio[3495]: info: Loading plugin "alarm-clock"... Feb 08 16:24:44 volumio volumio[3495]: info: Loading plugin "airplay_emulation"... Feb 08 16:24:44 volumio volumio[3495]: info: Starting Shairport Sync Feb 08 16:24:44 volumio volumio[3495]: info: Loading plugin "last_100"... Feb 08 16:24:44 volumio volumio[3495]: info: Loading plugin "webradio"... Feb 08 16:24:44 volumio volumio[3495]: info: Loading plugin "i2s_dacs"... Feb 08 16:24:44 volumio volumio[3495]: info: Loading plugin "volumiodiscovery"... Feb 08 16:24:44 volumio volumio[3495]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 08 16:24:44 volumio volumio[3495]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 16:24:44 volumio node[3495]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 08 16:24:44 volumio volumio[3495]: *** WARNING *** For more information see Feb 08 16:24:44 volumio volumio[3495]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 08 16:24:44 volumio volumio[3495]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 16:24:44 volumio volumio[3495]: *** WARNING *** For more information see Feb 08 16:24:44 volumio node[3495]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 16:24:44 volumio node[3495]: *** WARNING *** For more information see Feb 08 16:24:44 volumio node[3495]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 08 16:24:44 volumio node[3495]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 16:24:44 volumio node[3495]: *** WARNING *** For more information see Feb 08 16:24:44 volumio volumio[3495]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 08 16:24:44 volumio volumio[3495]: info: Discovery: Started advertising with name: Volumio Feb 08 16:24:44 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 16:24:44 volumio volumio[3495]: info: Loading plugin "spop"... Feb 08 16:24:46 volumio volumio[3495]: info: Loading plugin "ytcr"... Feb 08 16:24:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 08 16:24:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:24:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:24:46 volumio go-librespot[3586]: go-librespot daemon starting... Feb 08 16:24:46 volumio go-librespot[3587]: time="2026-02-08T16:24:46+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 16:24:46 volumio go-librespot[3587]: time="2026-02-08T16:24:46+07:00" level=debug msg="app state loaded" Feb 08 16:24:46 volumio go-librespot[3587]: time="2026-02-08T16:24:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 16:24:47 volumio go-librespot[3587]: time="2026-02-08T16:24:47+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 08 16:24:47 volumio go-librespot[3587]: time="2026-02-08T16:24:47+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 08 16:24:47 volumio go-librespot[3587]: time="2026-02-08T16:24:47+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 08 16:24:47 volumio go-librespot[3587]: time="2026-02-08T16:24:47+07:00" level=info msg="zeroconf server listening on port 38899" Feb 08 16:24:47 volumio go-librespot[3587]: time="2026-02-08T16:24:47+07:00" level=debug msg="obtained new client token: AABDK3Hg9gYoGQ8WI7lhy5I7w+UI/aS02Svp1/E1KZT3IgIFfALkVqZV5wq/6HxWJyYwGE3TwAen129tEJ/L9MUeFPaRg3pLxBm/X8xJ1vchbZhzb/1fxGBAbcmRrxU4uH5S4eSX17llYQu1INxUwXtfIk2whPFvzHotOiFN7vKhNKhHcuzr3w7q7+3cJy+/84+CvegD6lQhb5aSU9yO4jsQpyfolBBOCoWaiwGjo5bU6dtpqDZQJjVySQ==" Feb 08 16:24:47 volumio go-librespot[3587]: time="2026-02-08T16:24:47+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 16:24:47 volumio go-librespot[3587]: time="2026-02-08T16:24: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 16:24:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 16:24:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 16:24:49 volumio volumio[3495]: info: Loading plugin "ytmusic"... Feb 08 16:24:50 volumio volumio-remote-updater[643]: [2026-02-08 16:24:50] [connect] Successful connection Feb 08 16:24:50 volumio volumio[3495]: info: Loading plugin "outputs"... Feb 08 16:24:50 volumio volumio[3495]: info: Loading plugin "albumart"... Feb 08 16:24:50 volumio volumio[3495]: info: Plugin example_plugin is not enabled Feb 08 16:24:50 volumio volumio[3495]: info: Loading plugin "inputs"... Feb 08 16:24:50 volumio volumio[3495]: info: Loading plugin "updater_comm"... Feb 08 16:24:50 volumio volumio[3495]: info: Plugin mpdemulation is not enabled Feb 08 16:24:50 volumio volumio[3495]: info: Loading plugin "rest_api"... Feb 08 16:24:50 volumio volumio[3495]: info: Loading plugin "websocket"... Feb 08 16:24:50 volumio volumio[3495]: info: Starting Socket.io Server version 1.7.4 Feb 08 16:24:50 volumio volumio[3495]: info: Loading plugin "RoonBridge"... Feb 08 16:24:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 08 16:24:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:24:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:24:51 volumio go-librespot[3618]: go-librespot daemon starting... Feb 08 16:24:51 volumio go-librespot[3619]: time="2026-02-08T16:24:51+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 16:24:51 volumio go-librespot[3619]: time="2026-02-08T16:24:51+07:00" level=debug msg="app state loaded" Feb 08 16:24:51 volumio go-librespot[3619]: time="2026-02-08T16:24:51+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 16:24:51 volumio volumio[3495]: info: Applying required configuration parameters for plugin RoonBridge Feb 08 16:24:51 volumio volumio[3495]: info: Loading i18n strings for locale en Feb 08 16:24:51 volumio volumio[3495]: Updating browse sources language Feb 08 16:24:51 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 16:24:51 volumio volumio[3608]: Forking 3 albumart workers Feb 08 16:24:51 volumio go-librespot[3619]: time="2026-02-08T16:24: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 16:24:51 volumio go-librespot[3619]: time="2026-02-08T16:24:51+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 16:24:51 volumio go-librespot[3619]: time="2026-02-08T16:24:51+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 16:24:51 volumio go-librespot[3619]: time="2026-02-08T16:24:51+07:00" level=info msg="zeroconf server listening on port 36233" Feb 08 16:24:51 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 16:24:51 volumio volumio[3495]: info: CoreCommandRouter::initPlayerControls Feb 08 16:24:51 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:51 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:51 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:51 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:51 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:51 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:51 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:51 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:51 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 16:24:51 volumio volumio[3495]: Express server listening on port 3000 Feb 08 16:24:51 volumio volumio[3495]: [Metrics] WebUI: 16s 266.08ms Feb 08 16:24:51 volumio volumio[3495]: info: CoreStateMachine::resetVolumioState Feb 08 16:24:51 volumio volumio[3495]: info: CoreStateMachine::getcurrentVolume Feb 08 16:24:51 volumio volumio[3495]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 16:24:52 volumio go-librespot[3619]: time="2026-02-08T16:24:52+07:00" level=debug msg="obtained new client token: AAC81yYJ7e83Rt+FbsY97Vf3OQ3eJWezN4Wq8tCfRQaLtOWa6WHOMjTfsLzZIAKp9kYhGtD2sXnago50bV2ZnD7YqLoxWq07xuXhrOm4InpuHkHyxtZHE921jsIJ3qXhs5qQYE9wyG0oHYRlUJKzT03r/4gZVUe259MligfTgm7qnytbLK5xqdP3XQ+HepJK25cjRAoBvIDVb7J6OXTRkXp0qpnxszFCmE6hduM7iZBZy1B98tIdL9Ttqg==" Feb 08 16:24:52 volumio go-librespot[3619]: time="2026-02-08T16:24:52+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 16:24:52 volumio sudo[3661]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 08 16:24:52 volumio sudo[3661]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:24:52 volumio sudo[3663]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 08 16:24:52 volumio sudo[3663]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:24:52 volumio sudo[3661]: pam_unix(sudo:session): session closed for user root Feb 08 16:24:52 volumio sudo[3663]: pam_unix(sudo:session): session closed for user root Feb 08 16:24:52 volumio volumio[3495]: info: Volumio Network Manager: Network status updated: 1 Feb 08 16:24:52 volumio go-librespot[3619]: time="2026-02-08T16:24:52+07:00" level=debug msg="completed keyexchange" Feb 08 16:24:52 volumio go-librespot[3619]: time="2026-02-08T16:24:52+07:00" level=debug msg="completed challenge" Feb 08 16:24:52 volumio go-librespot[3619]: time="2026-02-08T16:24: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 16:24:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 16:24:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 16:24:52 volumio volumio[3495]: info: VolumeController:: Volume=100 Mute =false Feb 08 16:24:52 volumio volumio[3495]: info: CoreStateMachine::pushState Feb 08 16:24:52 volumio volumio[3495]: info: CorePlayQueue::getTrack 0 Feb 08 16:24:52 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 08 16:24:52 volumio volumio[3495]: info: CoreCommandRouter::volumioPushState Feb 08 16:24:52 volumio volumio[3495]: info: CoreStateMachine::updateTrackBlock Feb 08 16:24:52 volumio volumio[3495]: info: CorePlayQueue::getTrackBlock Feb 08 16:24:52 volumio volumio[3495]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 16:24:52 volumio volumio-remote-updater[643]: [2026-02-08 16:24:52] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770542690 101 Feb 08 16:24:52 volumio volumio[3495]: 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 16:24:52 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 16:24:52 volumio volumio[3495]: info: Reloading queue from file Feb 08 16:24:52 volumio volumio[3495]: info: CoreStateMachine::setRepeat null single undefined Feb 08 16:24:52 volumio volumio[3495]: info: CoreStateMachine::pushState Feb 08 16:24:52 volumio volumio[3495]: info: CorePlayQueue::getTrack 0 Feb 08 16:24:52 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 08 16:24:52 volumio volumio[3495]: info: CoreCommandRouter::volumioPushState Feb 08 16:24:52 volumio volumio[3495]: info: CoreStateMachine::setRandom null Feb 08 16:24:52 volumio volumio[3495]: info: CoreStateMachine::pushState Feb 08 16:24:52 volumio volumio[3495]: info: CorePlayQueue::getTrack 0 Feb 08 16:24:52 volumio volumio[3495]: info: CoreCommandRouter::volumioPushState Feb 08 16:24:52 volumio volumio[3495]: info: Setting Device type: Raspberry PI Feb 08 16:24:52 volumio volumio[3495]: info: Completed loading Core Plugins Feb 08 16:24:52 volumio volumio[3495]: info: Preparing to generate the ALSA configuration file Feb 08 16:24:52 volumio volumio[3495]: info: VolumeController:: Volume=100 Mute =false Feb 08 16:24:52 volumio volumio[3495]: info: CoreStateMachine::pushState Feb 08 16:24:52 volumio volumio[3495]: info: CorePlayQueue::getTrack 0 Feb 08 16:24:52 volumio volumio[3495]: info: CoreCommandRouter::volumioPushState Feb 08 16:24:53 volumio volumio[3495]: info: Asound.conf file unchanged, so no further update is needed Feb 08 16:24:53 volumio volumio[3495]: info: Output device has changed, restarting MPD Feb 08 16:24:53 volumio volumio[3495]: info: Output device has changed, restarting Shairport Sync Feb 08 16:24:53 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:53 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 16:24:53 volumio sudo[3679]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 16:24:53 volumio sudo[3677]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 08 16:24:53 volumio sudo[3677]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:24:53 volumio volumio[3495]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 16:24:53 volumio sudo[3679]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:24:53 volumio volumio[3495]: info: ___________ START PLUGINS ___________ Feb 08 16:24:53 volumio sudo[3682]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 16:24:53 volumio sudo[3679]: pam_unix(sudo:session): session closed for user root Feb 08 16:24:53 volumio sudo[3682]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:24:53 volumio volumio[3495]: info: ControllerMpd::onStart: Initializing MPD Feb 08 16:24:53 volumio volumio[3495]: info: Creating MPD Configuration file Feb 08 16:24:53 volumio sudo[3691]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 16:24:53 volumio sudo[3691]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:24:53 volumio sudo[3691]: pam_unix(sudo:session): session closed for user root Feb 08 16:24:53 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 16:24:53 volumio volumio[3495]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 16:24:53 volumio volumio[3495]: info: [1770542693306] CoreMusicLibrary::Adding element Media Servers Feb 08 16:24:53 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 08 16:24:53 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 16:24:53 volumio sudo[3677]: pam_unix(sudo:session): session closed for user root Feb 08 16:24:53 volumio sudo[3694]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 16:24:53 volumio sudo[3694]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:24:53 volumio volumio[3495]: info: UPNP Browser: Client initialized successfully Feb 08 16:24:53 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 08 16:24:53 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 08 16:24:53 volumio systemd[1]: mpd.service: Consumed 7.179s CPU time. Feb 08 16:24:53 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 08 16:24:53 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 08 16:24:53 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 08 16:24:53 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:53 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 16:24:53 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 08 16:24:53 volumio volumio[3495]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 16:24:53 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:53 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 08 16:24:53 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 16:24:53 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 08 16:24:53 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 08 16:24:53 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 08 16:24:53 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 08 16:24:53 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 08 16:24:53 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 08 16:24:53 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 08 16:24:53 volumio volumio[3495]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 16:24:53 volumio volumio[3495]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 16:24:53 volumio volumio[3495]: info: [1770542693709] CoreMusicLibrary::Adding element Last_100 Feb 08 16:24:53 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 16:24:53 volumio volumio[3495]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 16:24:53 volumio volumio[3495]: info: [1770542693729] CoreMusicLibrary::Adding element Webradio Feb 08 16:24:53 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 16:24:53 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 16:24:53 volumio volumio[3495]: info: Initializing BBC Radios Feb 08 16:24:53 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 16:24:53 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 16:24:54 volumio volumio[3495]: info: Creating Spotify config file Feb 08 16:24:54 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:54 volumio sudo[3707]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 08 16:24:54 volumio sudo[3707]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 08 16:24:54 volumio sudo[3707]: pam_unix(sudo:session): session closed for user root Feb 08 16:24:54 volumio volumio[3626]: Starting albumart workers Feb 08 16:24:54 volumio volumio[3628]: Starting albumart workers Feb 08 16:24:55 volumio volumio[3627]: Starting albumart workers Feb 08 16:24:55 volumio volumio[3495]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 16:24:55 volumio volumio[3495]: info: [1770542695176] CoreMusicLibrary::Adding element YouTube Music Feb 08 16:24:55 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 16:24:55 volumio volumio[3495]: Cannot find translation for source YouTube Music Feb 08 16:24:55 volumio volumio[3495]: info: Volumio Calling Home Feb 08 16:24:55 volumio sudo[3724]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 08 16:24:55 volumio sudo[3724]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:24:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 08 16:24:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:24:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:24:55 volumio go-librespot[3729]: go-librespot daemon starting... Feb 08 16:24:55 volumio go-librespot[3730]: time="2026-02-08T16:24:55+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 16:24:55 volumio sudo[3724]: pam_unix(sudo:session): session closed for user root Feb 08 16:24:56 volumio volumio[3495]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 08 16:24:56 volumio volumio[3495]: info: Discovery: Found device Volumio Feb 08 16:24:56 volumio volumio[3495]: info: CoreCommandRouter::volumioGetState Feb 08 16:24:56 volumio volumio[3495]: info: CorePlayQueue::getTrack 0 Feb 08 16:24:56 volumio volumio[3495]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 08 16:24:56 volumio volumio[3495]: info: Discovery: Found device Volumio Feb 08 16:24:56 volumio volumio[3495]: info: CoreCommandRouter::volumioGetState Feb 08 16:24:56 volumio volumio[3495]: info: CorePlayQueue::getTrack 0 Feb 08 16:24:56 volumio go-librespot[3730]: time="2026-02-08T16:24:56+07:00" level=info msg="zeroconf server listening on port 43787" Feb 08 16:24:56 volumio volumio[3495]: info: MPD Permissions set Feb 08 16:24:56 volumio volumio[3495]: info: MPD Permissions set Feb 08 16:24:56 volumio volumio[3495]: info: Upmpdcli Daemon Started Feb 08 16:24:56 volumio volumio[3495]: info: Spotify config file written Feb 08 16:24:56 volumio sudo[3738]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 08 16:24:56 volumio sudo[3738]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:24:56 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 08 16:24:56 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 08 16:24:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:24:56 volumio volumio[3495]: 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 16:24:56 volumio go-librespot[3740]: go-librespot daemon starting... Feb 08 16:24:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:24:56 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:56 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:56 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:56 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:56 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:56 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:56 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:56 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:56 volumio sudo[3738]: pam_unix(sudo:session): session closed for user root Feb 08 16:24:56 volumio go-librespot[3741]: time="2026-02-08T16:24:56+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 16:24:56 volumio go-librespot[3741]: time="2026-02-08T16:24:56+07:00" level=debug msg="app state loaded" Feb 08 16:24:56 volumio go-librespot[3741]: time="2026-02-08T16:24:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 16:24:56 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 16:24:56 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:56 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:56 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:56 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:56 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:56 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:56 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:56 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:56 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:57 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 16:24:57 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:24:57 volumio volumio[3495]: info: No need to fix Spotify hosts Feb 08 16:24:57 volumio go-librespot[3741]: time="2026-02-08T16:24:57+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 16:24:57 volumio go-librespot[3741]: time="2026-02-08T16:24:57+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 16:24:57 volumio go-librespot[3741]: time="2026-02-08T16:24:57+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 16:24:57 volumio go-librespot[3741]: time="2026-02-08T16:24:57+07:00" level=info msg="zeroconf server listening on port 34711" Feb 08 16:24:57 volumio volumio[3495]: info: Volumio called home Feb 08 16:24:57 volumio go-librespot[3741]: time="2026-02-08T16:24:57+07:00" level=debug msg="obtained new client token: AAAESYIyZ9wpXkKpMtglLLk7EwZVDXD5nUQPsXBSOFwsa0hSyS7q0NurQZ5Mhs4UzZIS26thliAoXOycO/nt9CyoniQKWDOLvi/Xb2R9iosjoAhbBVG1bwLOyS30JJMKt7i+JZur63tJwZaSx7hWyEaIiOvzHeo6fgmF3ivJ5yk3rLw1sry26W+otUH0BDw7+9jx7cMXd/bOvZrIspez8lBcRdx1ewVApvuWFZV3fnl3R4d09YlKhDJ/BA==" Feb 08 16:24:57 volumio go-librespot[3741]: time="2026-02-08T16:24:57+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 08 16:24:57 volumio volumio[3495]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 08 16:24:57 volumio volumio[3495]: SPOTIFY: BQBnBRo1DMkHwM-gnh2ImOJQj5RVjb0S_RQGfMP8pwfkOG_0BzMVLMK60uUTGtW34pwVKLgVsgrqk7Vl0GP9llKI6Jc_oEePsQVAWZSIyIchAC9SKDKS5tFg1gfTczNpwDss1PG9kJRc2TBOiQ7IJaSifEdOL7pOYSo-k5KRWM-D9EnjFeU_KQr-VaItFm1OHzAV07Dk33sQgK9JAhtWwBhjENwiOnx_u1E05Uf-40tb1wWp_u19Fp-Kl2MMIqGxLquOaXNvITgYa_q6GwGTYqe1--9Rk31isriC2DV-8urfhMC8OsJPHj86 Feb 08 16:24:57 volumio volumio[3495]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 08 16:24:58 volumio volumio[3495]: info: New Spotify access token = BQBnBRo1DMkHwM-gnh2ImOJQj5RVjb0S_RQGfMP8pwfkOG_0BzMVLMK60uUTGtW34pwVKLgVsgrqk7Vl0GP9llKI6Jc_oEePsQVAWZSIyIchAC9SKDKS5tFg1gfTczNpwDss1PG9kJRc2TBOiQ7IJaSifEdOL7pOYSo-k5KRWM-D9EnjFeU_KQr-VaItFm1OHzAV07Dk33sQgK9JAhtWwBhjENwiOnx_u1E05Uf-40tb1wWp_u19Fp-Kl2MMIqGxLquOaXNvITgYa_q6GwGTYqe1--9Rk31isriC2DV-8urfhMC8OsJPHj86 Feb 08 16:24:58 volumio volumio[3495]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 08 16:24:58 volumio go-librespot[3741]: time="2026-02-08T16:24:58+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 08 16:24:58 volumio volumio[3495]: info: Starting Shairport Sync Feb 08 16:24:58 volumio volumio[3495]: info: Starting Shairport Sync Feb 08 16:24:58 volumio volumio[3495]: info: Starting Shairport Sync Feb 08 16:24:58 volumio go-librespot[3741]: time="2026-02-08T16:24:58+07:00" level=debug msg="completed keyexchange" Feb 08 16:24:58 volumio go-librespot[3741]: time="2026-02-08T16:24:58+07:00" level=debug msg="completed challenge" Feb 08 16:24:58 volumio sudo[3777]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 16:24:58 volumio sudo[3779]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 16:24:58 volumio sudo[3777]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:24:58 volumio sudo[3779]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:24:58 volumio go-librespot[3741]: time="2026-02-08T16:24:58+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 16:24:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 16:24:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 16:24:58 volumio sudo[3781]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 16:24:58 volumio sudo[3781]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:24:58 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 08 16:24:58 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 08 16:24:58 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 16:24:58 volumio systemd[1]: shairport-sync.service: Consumed 2.327s CPU time. Feb 08 16:24:58 volumio volumio[3495]: info: CoreCommandRouter::volumioGetState Feb 08 16:24:58 volumio volumio[3495]: info: CorePlayQueue::getTrack 0 Feb 08 16:24:58 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 16:24:58 volumio sudo[3777]: pam_unix(sudo:session): session closed for user root Feb 08 16:24:58 volumio sudo[3781]: pam_unix(sudo:session): session closed for user root Feb 08 16:24:58 volumio sudo[3779]: pam_unix(sudo:session): session closed for user root Feb 08 16:24:58 volumio volumio[3495]: info: Shairport-Sync Started Feb 08 16:24:58 volumio volumio[3495]: Error adding Membership: Error: addMembership EINVAL Feb 08 16:24:58 volumio volumio[3495]: info: Shairport-Sync Started Feb 08 16:24:58 volumio volumio[3495]: info: Shairport-Sync Started Feb 08 16:24:58 volumio volumio[3495]: 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 16:24:58 volumio volumio[3495]: info: Spotify Successfully logged in Feb 08 16:24:58 volumio volumio[3495]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 16:24:58 volumio volumio[3495]: info: [1770542698760] CoreMusicLibrary::Adding element Spotify Feb 08 16:24:58 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 16:24:58 volumio volumio[3495]: Cannot find translation for source YouTube Music Feb 08 16:24:58 volumio volumio[3495]: Cannot find translation for source Spotify Feb 08 16:24:59 volumio volumio[3495]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 08 16:24:59 volumio volumio[3495]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 16:24:59 volumio volumio[3495]: info: VolumeController:: Volume=100 Mute =false Feb 08 16:24:59 volumio volumio[3495]: info: CoreCommandRouter::volumioGetState Feb 08 16:24:59 volumio volumio[3495]: info: CorePlayQueue::getTrack 0 Feb 08 16:24:59 volumio volumio[3495]: info: CoreStateMachine::pushState Feb 08 16:24:59 volumio volumio[3495]: info: CorePlayQueue::getTrack 0 Feb 08 16:24:59 volumio volumio[3495]: info: CoreCommandRouter::volumioPushState Feb 08 16:25:00 volumio volumio[3495]: info: go-librespot daemon successfully initialized Feb 08 16:25:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 08 16:25:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:25:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:25:01 volumio go-librespot[3819]: go-librespot daemon starting... Feb 08 16:25:01 volumio mpd[3722]: 2026-02-08T16:25:01 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 08 16:25:01 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 08 16:25:01 volumio sudo[3682]: pam_unix(sudo:session): session closed for user root Feb 08 16:25:01 volumio sudo[3694]: pam_unix(sudo:session): session closed for user root Feb 08 16:25:01 volumio go-librespot[3820]: time="2026-02-08T16:25:01+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 16:25:01 volumio go-librespot[3820]: time="2026-02-08T16:25:01+07:00" level=debug msg="app state loaded" Feb 08 16:25:01 volumio go-librespot[3820]: time="2026-02-08T16:25:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 16:25:01 volumio volumio[3495]: error: MPD error: The expression evaluated to a falsy value: Feb 08 16:25:01 volumio volumio[3495]: assert.ok(self.idling) Feb 08 16:25:01 volumio volumio[3495]: error: The expression evaluated to a falsy value: Feb 08 16:25:01 volumio volumio[3495]: assert.ok(self.idling) Feb 08 16:25:01 volumio volumio[3495]: error: updateQueue error: null Feb 08 16:25:01 volumio volumio[3495]: info: MPD running with PID3722 Feb 08 16:25:01 volumio volumio[3495]: ,establishing connection Feb 08 16:25:01 volumio volumio[3495]: info: Completed starting Core Plugins Feb 08 16:25:01 volumio volumio[3495]: info: ------------------------------------------- Feb 08 16:25:01 volumio volumio[3495]: info: ----- MyVolumio plugins startup ---- Feb 08 16:25:01 volumio volumio[3495]: info: ------------------------------------------- Feb 08 16:25:01 volumio volumio[3495]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 08 16:25:01 volumio volumio[3495]: error: updateQueue error: null Feb 08 16:25:01 volumio go-librespot[3820]: time="2026-02-08T16:25:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 16:25:01 volumio go-librespot[3820]: time="2026-02-08T16:25:01+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 08 16:25:01 volumio go-librespot[3820]: time="2026-02-08T16:25:01+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 08 16:25:02 volumio go-librespot[3820]: time="2026-02-08T16:25:02+07:00" level=info msg="zeroconf server listening on port 41785" Feb 08 16:25:02 volumio go-librespot[3820]: time="2026-02-08T16:25:02+07:00" level=debug msg="obtained new client token: AAA4gQoUNs7vcZF7aFpPpCj+bLjimh09Yn+rAlTH4eFRleBhiLRWGhLkvt8PxBaUMapDy/y2RXT3ucQitFcvCXAyyUiVELkRPtHmdhP8YCLJ20PzQWAwMNw5BE4juKjwZNwRlPoCP1a3GrbHIpoxpAsgkm1npdydx+MOSJsV5RTgVm7TvznxFORPeVxEWnybSWdJmuFKjfMv/eVOGCM9YJUbebxG6SyGa4vdOKHIEge6t3vvTnV9dAg=" Feb 08 16:25:02 volumio go-librespot[3820]: time="2026-02-08T16:25:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 16:25:02 volumio go-librespot[3820]: time="2026-02-08T16:25:02+07:00" level=debug msg="completed keyexchange" Feb 08 16:25:02 volumio go-librespot[3820]: time="2026-02-08T16:25:02+07:00" level=debug msg="completed challenge" Feb 08 16:25:02 volumio go-librespot[3820]: time="2026-02-08T16:25:02+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 16:25:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 16:25:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 16:25:03 volumio volumio[3495]: info: Initializing connection to go-librespot Websocket Feb 08 16:25:04 volumio volumio[3495]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 16:25:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 08 16:25:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:25:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:25:05 volumio go-librespot[3831]: go-librespot daemon starting... Feb 08 16:25:05 volumio go-librespot[3832]: time="2026-02-08T16:25:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 16:25:05 volumio go-librespot[3832]: time="2026-02-08T16:25:05+07:00" level=debug msg="app state loaded" Feb 08 16:25:05 volumio go-librespot[3832]: time="2026-02-08T16:25:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 16:25:06 volumio go-librespot[3832]: time="2026-02-08T16:25:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 16:25:06 volumio go-librespot[3832]: time="2026-02-08T16:25:06+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 16:25:06 volumio go-librespot[3832]: time="2026-02-08T16:25:06+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 16:25:06 volumio go-librespot[3832]: time="2026-02-08T16:25:06+07:00" level=info msg="zeroconf server listening on port 37201" Feb 08 16:25:06 volumio volumio[3495]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 08 16:25:06 volumio go-librespot[3832]: time="2026-02-08T16:25:06+07:00" level=debug msg="obtained new client token: AADYIUVBhdHsfz5ZVAE5B1NYGc7AiM8uFfGFYLn2frXaUh4xv74PimH0sOeeA09Z8zpCat28OV7oLpfFlpbbRQZ2j78pem7WxrRLk067RmEOCKfSwoJDFCsNiY2cQGw7DFSiRGPvU8/eEHc7VoZwhAVjof1aWXiVzO/+2eT71lTVYbjjLAs3J/HzrymYBgIbBuc39abq59SQaV11z7rf2B+SNrNU4/7BV7HYmNZp3GWTHko9pSK1QKBYcw==" Feb 08 16:25:06 volumio go-librespot[3832]: time="2026-02-08T16:25:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 16:25:06 volumio go-librespot[3832]: time="2026-02-08T16:25:06+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 16:25:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 16:25:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 16:25:07 volumio volumio[3495]: info: Initializing connection to go-librespot Websocket Feb 08 16:25:07 volumio volumio[3495]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 16:25:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 08 16:25:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:25:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:25:09 volumio go-librespot[3839]: go-librespot daemon starting... Feb 08 16:25:09 volumio go-librespot[3840]: time="2026-02-08T16:25:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 16:25:09 volumio go-librespot[3840]: time="2026-02-08T16:25:09+07:00" level=debug msg="app state loaded" Feb 08 16:25:09 volumio go-librespot[3840]: time="2026-02-08T16:25:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 16:25:10 volumio volumio[3495]: info: Initializing connection to go-librespot Websocket Feb 08 16:25:10 volumio go-librespot[3840]: time="2026-02-08T16:25:10+07:00" level=debug msg="new websocket client" Feb 08 16:25:10 volumio volumio[3495]: info: Connection to go-librespot Websocket established Feb 08 16:25:10 volumio volumio[3495]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 08 16:25:10 volumio volumio[3495]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 08 16:25:10 volumio volumio[3495]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 08 16:25:10 volumio volumio[3495]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 08 16:25:10 volumio volumio[3495]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 08 16:25:10 volumio volumio[3495]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 08 16:25:10 volumio volumio[3495]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 08 16:25:10 volumio volumio[3495]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 08 16:25:10 volumio volumio[3495]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 08 16:25:10 volumio volumio[3495]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 08 16:25:10 volumio volumio[3495]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 08 16:25:10 volumio volumio[3495]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 08 16:25:10 volumio volumio[3495]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 08 16:25:10 volumio volumio[3495]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 08 16:25:10 volumio volumio[3495]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 08 16:25:10 volumio volumio[3495]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 08 16:25:10 volumio volumio[3495]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 08 16:25:10 volumio volumio[3495]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 08 16:25:10 volumio volumio[3495]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 08 16:25:10 volumio volumio[3495]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 08 16:25:10 volumio volumio[3495]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 08 16:25:10 volumio volumio[3495]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 08 16:25:10 volumio volumio[3495]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 08 16:25:10 volumio volumio[3495]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 08 16:25:10 volumio volumio[3495]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 08 16:25:10 volumio volumio[3495]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 08 16:25:10 volumio volumio[3495]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 08 16:25:10 volumio volumio[3495]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 08 16:25:10 volumio volumio[3495]: info: Adding plugin bluetooth to MyMusic Plugins Feb 08 16:25:10 volumio volumio[3495]: info: Adding plugin multiroom to MyMusic Plugins Feb 08 16:25:10 volumio volumio[3495]: info: Adding plugin metavolumio to MyMusic Plugins Feb 08 16:25:10 volumio volumio[3495]: info: Adding plugin cd_controller to MyMusic Plugins Feb 08 16:25:10 volumio volumio[3495]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 08 16:25:10 volumio volumio[3495]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 08 16:25:10 volumio volumio[3495]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 08 16:25:10 volumio volumio[3495]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 08 16:25:10 volumio go-librespot[3840]: time="2026-02-08T16:25:10+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 16:25:10 volumio go-librespot[3840]: time="2026-02-08T16:25:10+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 16:25:10 volumio go-librespot[3840]: time="2026-02-08T16:25:10+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 16:25:10 volumio go-librespot[3840]: time="2026-02-08T16:25:10+07:00" level=info msg="zeroconf server listening on port 36105" Feb 08 16:25:10 volumio go-librespot[3840]: time="2026-02-08T16:25:10+07:00" level=debug msg="obtained new client token: AADotjYDTthkXO711pjdZpLFC9OU3anPbycHEYVCodq80Bg/Tlyq6ToWxIM3fpxRu2z7S6cpO3mkvcrLpXhLVp99l9LkDUDslpmt94clXoHtYctgHrKfW0gSuRU2aeS1Mq1k7OWUubF/vsl+ebqZvZ38edXErbePjxTfAlJ1EAjL8D1Rwkwh37MOVWPptnnE8FT3a2EeHJvdaeLrzF7NkhU9HLWKMEfPhXHNi6099sYp+iwnmmDrAqC3Hw==" Feb 08 16:25:10 volumio go-librespot[3840]: time="2026-02-08T16:25:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 16:25:10 volumio go-librespot[3840]: time="2026-02-08T16:25:10+07:00" level=debug msg="completed keyexchange" Feb 08 16:25:10 volumio go-librespot[3840]: time="2026-02-08T16:25:10+07:00" level=debug msg="completed challenge" Feb 08 16:25:10 volumio go-librespot[3840]: time="2026-02-08T16:25:10+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 16:25:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 16:25:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 16:25:12 volumio volumio[3495]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 08 16:25:12 volumio volumio[3495]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 08 16:25:12 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 16:25:12 volumio volumio[3495]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 16:25:12 volumio volumio[3495]: info: Starting MyVolumio Remote Streaming Endpoints Feb 08 16:25:12 volumio volumio[3495]: info: MyVolumio login type: Token Feb 08 16:25:12 volumio volumio[3495]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 08 16:25:12 volumio volumio[3495]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 08 16:25:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 08 16:25:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:25:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:25:14 volumio go-librespot[3863]: go-librespot daemon starting... Feb 08 16:25:14 volumio volumio[3495]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 08 16:25:14 volumio volumio[3495]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 08 16:25:14 volumio volumio[3495]: info: Streaming services startup Feb 08 16:25:14 volumio volumio[3495]: info: Starting Streaming Daemon Feb 08 16:25:14 volumio go-librespot[3864]: time="2026-02-08T16:25:14+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 16:25:14 volumio go-librespot[3864]: time="2026-02-08T16:25:14+07:00" level=debug msg="app state loaded" Feb 08 16:25:14 volumio go-librespot[3864]: time="2026-02-08T16:25:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 16:25:14 volumio sudo[3872]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 08 16:25:14 volumio sudo[3872]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:25:14 volumio volumio[3495]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 08 16:25:14 volumio sudo[3872]: pam_unix(sudo:session): session closed for user root Feb 08 16:25:14 volumio volumio[3495]: info: Getting Spotify volume Feb 08 16:25:14 volumio volumio[3495]: info: Connection to go-librespot Websocket closed Feb 08 16:25:14 volumio volumio[3495]: error: Cannot start Volumio Streaming Daemon Feb 08 16:25:14 volumio volumio[3495]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 08 16:25:14 volumio volumio[3495]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 08 16:25:14 volumio volumio[3495]: 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 16:25:14 volumio volumio[3495]: info: CoreCommandRouter::volumioGetState Feb 08 16:25:14 volumio volumio[3495]: info: CorePlayQueue::getTrack 0 Feb 08 16:25:14 volumio volumio[3495]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 08 16:25:14 volumio volumio[3495]: SPOTIFY: SPOTIFY VOLUME undefined Feb 08 16:25:14 volumio volumio[3495]: SPOTIFY: VOLUMIO VOLUME 100 Feb 08 16:25:14 volumio volumio[3495]: info: Aligning Spotify Volume to Volumio Volume Feb 08 16:25:14 volumio volumio[3495]: info: CoreCommandRouter::volumioGetState Feb 08 16:25:14 volumio volumio[3495]: info: CorePlayQueue::getTrack 0 Feb 08 16:25:14 volumio volumio[3495]: info: Setting Spotify Volume from Volumio: 100 Feb 08 16:25:14 volumio go-librespot[3864]: time="2026-02-08T16:25:14+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 16:25:14 volumio go-librespot[3864]: time="2026-02-08T16:25:14+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 16:25:14 volumio go-librespot[3864]: time="2026-02-08T16:25:14+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 16:25:14 volumio go-librespot[3864]: time="2026-02-08T16:25:14+07:00" level=info msg="zeroconf server listening on port 35563" Feb 08 16:25:14 volumio go-librespot[3864]: time="2026-02-08T16:25:14+07:00" level=debug msg="obtained new client token: AAAFj+RFqqmhB7WFP4ZWlaeIn5P2USZgMlW/wxbsH3B4bJuuG3lNRDouK8QhImhyTVsr2zDGAkAs/jD3QuW4yNy6ULW90F8a1sCloHeA+xKlsosiWqxW8Y0svYfqPIX/sDb4swDPrdAP4/WFXQm2p1J6ALPuWYIw0OpTPPJ4735xfrCb4K8lTXv0tf2FTgY+iNG/yAUv8JqotKiuFKjQ9mnXEDE6RTEuy81gHF7RVYT8u+zmqiTPtn+EfQ==" Feb 08 16:25:15 volumio go-librespot[3864]: time="2026-02-08T16:25:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 16:25:15 volumio go-librespot[3864]: time="2026-02-08T16:25:15+07:00" level=debug msg="completed keyexchange" Feb 08 16:25:15 volumio go-librespot[3864]: time="2026-02-08T16:25:15+07:00" level=debug msg="completed challenge" Feb 08 16:25:15 volumio go-librespot[3864]: time="2026-02-08T16:25:15+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 16:25:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 16:25:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 16:25:15 volumio volumio[3495]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 16:25:15 volumio volumio[3495]: Error: socket hang up Feb 08 16:25:15 volumio volumio[3495]: at connResetException (node:internal/errors:720:14) Feb 08 16:25:15 volumio volumio[3495]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 08 16:25:15 volumio volumio[3495]: at Socket.emit (node:events:526:35) Feb 08 16:25:15 volumio volumio[3495]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 08 16:25:15 volumio volumio[3495]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 08 16:25:15 volumio volumio[3495]: code: 'ECONNRESET', Feb 08 16:25:15 volumio volumio[3495]: response: undefined Feb 08 16:25:15 volumio volumio[3495]: } Feb 08 16:25:15 volumio volumio[3495]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 16:25:16 volumio sudo[3892]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-08 16:24' Feb 08 16:25:16 volumio sudo[3892]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:25:17 volumio sudo[3892]: pam_unix(sudo:session): session closed for user root Feb 08 16:25:17 volumio volumio-remote-updater[643]: [2026-02-08 16:25:17] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 08 16:25:17 volumio volumio-remote-updater[643]: [2026-02-08 16:25:17] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 08 16:25:17 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 08 16:25:17 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 08 16:25:17 volumio systemd[1]: volumio.service: Consumed 55.475s CPU time. Feb 08 16:25:17 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 08 16:25:17 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 08 16:25:17 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 7467. Feb 08 16:25:17 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 08 16:25:17 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 08 16:25:17 volumio systemd[1]: volumio.service: Consumed 55.475s CPU time. Feb 08 16:25:17 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 08 16:25:17 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 08 16:25:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 08 16:25:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:25:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:25:18 volumio go-librespot[3920]: go-librespot daemon starting... Feb 08 16:25:18 volumio go-librespot[3921]: time="2026-02-08T16:25:18+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 16:25:18 volumio go-librespot[3921]: time="2026-02-08T16:25:18+07:00" level=debug msg="app state loaded" Feb 08 16:25:18 volumio go-librespot[3921]: time="2026-02-08T16:25:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 16:25:18 volumio go-librespot[3921]: time="2026-02-08T16:25:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 16:25:18 volumio go-librespot[3921]: time="2026-02-08T16:25:18+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 16:25:18 volumio go-librespot[3921]: time="2026-02-08T16:25:18+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 16:25:18 volumio go-librespot[3921]: time="2026-02-08T16:25:18+07:00" level=info msg="zeroconf server listening on port 35503" Feb 08 16:25:19 volumio go-librespot[3921]: time="2026-02-08T16:25:19+07:00" level=debug msg="obtained new client token: AABAALHuloyfEIgB7MBkGDcnWX+dNNUaxrt/Kx5PqSgund8lbgaSJQuQhEuNg90Y+z0PEi1GaH/6vt6GMMlkHEnK6SG5ZqnraPdB7VD509tWCjM31r1lBX0cNcj8+4e3ISLRGmKBa6EDD5sOtmhmNYEvuxkiODd8trS6puYqYZ9sJZMqXBDVb9b4cB75ddZxGFZjZNTYMeH2oHVrd5OdvFI9EJ7G2NJrxPi9XWs7PApzqi/1E3s3gJQ=" Feb 08 16:25:19 volumio go-librespot[3921]: time="2026-02-08T16:25:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 16:25:19 volumio go-librespot[3921]: time="2026-02-08T16:25:19+07:00" level=debug msg="completed keyexchange" Feb 08 16:25:19 volumio go-librespot[3921]: time="2026-02-08T16:25:19+07:00" level=debug msg="completed challenge" Feb 08 16:25:19 volumio go-librespot[3921]: time="2026-02-08T16:25:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 16:25:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 16:25:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 16:25:20 volumio volumio[3905]: info: ------------------------------------------- Feb 08 16:25:20 volumio volumio[3905]: info: ----- Volumio3 ---- Feb 08 16:25:20 volumio volumio[3905]: info: ------------------------------------------- Feb 08 16:25:20 volumio volumio[3905]: info: ----- System startup ---- Feb 08 16:25:20 volumio volumio[3905]: info: ------------------------------------------- Feb 08 16:25:22 volumio volumio-remote-updater[643]: [2026-02-08 16:25:22] [connect] Successful connection Feb 08 16:25:22 volumio volumio[3905]: info: MYVOLUMIO Environment detected Feb 08 16:25:22 volumio volumio[3905]: info: Plugin folders cleanup Feb 08 16:25:22 volumio volumio[3905]: info: Scanning into folder /volumio/app/plugins/ Feb 08 16:25:22 volumio volumio[3905]: info: Scanning category audio_interface Feb 08 16:25:22 volumio volumio[3905]: info: Scanning category miscellanea Feb 08 16:25:22 volumio volumio[3905]: info: Scanning category music_service Feb 08 16:25:22 volumio volumio[3905]: info: Scanning category plugins.json Feb 08 16:25:22 volumio volumio[3905]: info: Scanning category system_controller Feb 08 16:25:22 volumio volumio[3905]: info: Scanning category user_interface Feb 08 16:25:22 volumio volumio[3905]: info: Scanning into folder /data/plugins/ Feb 08 16:25:22 volumio volumio[3905]: info: Scanning category music_service Feb 08 16:25:22 volumio volumio[3905]: info: Plugin folders cleanup completed Feb 08 16:25:22 volumio volumio[3905]: info: ------------------------------------------- Feb 08 16:25:22 volumio volumio[3905]: info: ----- Core plugins startup ---- Feb 08 16:25:22 volumio volumio[3905]: info: ------------------------------------------- Feb 08 16:25:22 volumio volumio[3905]: info: Loading plugins from folder /volumio/app/plugins/ Feb 08 16:25:22 volumio volumio[3905]: info: Adding plugin upnp to MyMusic Plugins Feb 08 16:25:22 volumio volumio[3905]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 08 16:25:22 volumio volumio[3905]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 08 16:25:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 08 16:25:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:25:22 volumio volumio[3905]: info: Loading plugins from folder /data/plugins/ Feb 08 16:25:22 volumio volumio[3905]: info: Loading plugin "system"... Feb 08 16:25:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:25:22 volumio go-librespot[3937]: go-librespot daemon starting... Feb 08 16:25:22 volumio volumio[3905]: info: Loading plugin "appearance"... Feb 08 16:25:22 volumio go-librespot[3938]: time="2026-02-08T16:25:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 16:25:22 volumio go-librespot[3938]: time="2026-02-08T16:25:22+07:00" level=debug msg="app state loaded" Feb 08 16:25:22 volumio go-librespot[3938]: time="2026-02-08T16:25:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 16:25:23 volumio go-librespot[3938]: time="2026-02-08T16:25:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 08 16:25:23 volumio go-librespot[3938]: time="2026-02-08T16:25:23+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 08 16:25:23 volumio go-librespot[3938]: time="2026-02-08T16:25:23+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 08 16:25:23 volumio go-librespot[3938]: time="2026-02-08T16:25:23+07:00" level=info msg="zeroconf server listening on port 32781" Feb 08 16:25:23 volumio go-librespot[3938]: time="2026-02-08T16:25:23+07:00" level=debug msg="obtained new client token: AACoQObEDt7vcTcfngJOuvipq0V7N7CcsIXitmga/Dp6J3wOSNIo1feZ+qiPzazkBpqwb8Dv5DufZKgN6D+/QBum2rtWBFHPfoWQoskoaIWV3oS6h0MrJQ/fcwTnzT3CqF379Gl87yLW7aBXOobmVgylOCNY8lmcu5LaGN9VvoYNrUgqm/xq4DTG68ru89usdeoL0Vq5pcq21lquujlqnFW5zlK7Mwr/5Tr9G5HOfVWtBj6Wgg+aJOrHPA==" Feb 08 16:25:23 volumio go-librespot[3938]: time="2026-02-08T16:25:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 16:25:23 volumio go-librespot[3938]: time="2026-02-08T16:25:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 08 16:25:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 16:25:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 16:25:24 volumio volumio[3905]: info: Loading plugin "network"... Feb 08 16:25:24 volumio volumio[3905]: info: Refreshing Cached IP Addresses Feb 08 16:25:24 volumio sudo[3949]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 08 16:25:24 volumio sudo[3949]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:25:24 volumio sudo[3951]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 08 16:25:24 volumio sudo[3951]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:25:24 volumio sudo[3949]: pam_unix(sudo:session): session closed for user root Feb 08 16:25:24 volumio volumio[3905]: info: Loading plugin "services"... Feb 08 16:25:24 volumio sudo[3951]: pam_unix(sudo:session): session closed for user root Feb 08 16:25:24 volumio volumio[3905]: info: Loading plugin "alsa_controller"... Feb 08 16:25:24 volumio sudo[3959]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 08 16:25:24 volumio sudo[3959]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:25:24 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 16:25:24 volumio volumio[3905]: info: Loading plugin "wizard"... Feb 08 16:25:24 volumio volumio[3905]: info: Loading plugin "networkfs"... Feb 08 16:25:24 volumio volumio[3905]: info: Starting Udev Watcher for removable devices Feb 08 16:25:25 volumio volumio[3905]: info: Ignoring mount for partition: boot Feb 08 16:25:25 volumio volumio[3905]: info: Ignoring mount for partition: volumio Feb 08 16:25:25 volumio volumio[3905]: info: Ignoring mount for partition: volumio_data Feb 08 16:25:25 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 16:25:25 volumio volumio[3905]: info: Loading plugin "volumio_command_line_client"... Feb 08 16:25:25 volumio volumio[3905]: info: Loading plugin "upnp"... Feb 08 16:25:25 volumio volumio[3905]: info: [1770542725063] Starting Upmpd Daemon Feb 08 16:25:25 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 16:25:25 volumio volumio[3905]: info: Loading plugin "my_music"... Feb 08 16:25:25 volumio volumio[3905]: info: Loading plugin "mpd"... Feb 08 16:25:25 volumio volumio[3905]: info: Loading plugin "upnp_browser"... Feb 08 16:25:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 08 16:25:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:25:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:25:26 volumio go-librespot[3982]: go-librespot daemon starting... Feb 08 16:25:26 volumio go-librespot[3983]: time="2026-02-08T16:25:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 16:25:26 volumio go-librespot[3983]: time="2026-02-08T16:25:26+07:00" level=debug msg="app state loaded" Feb 08 16:25:26 volumio go-librespot[3983]: time="2026-02-08T16:25:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 16:25:27 volumio go-librespot[3983]: time="2026-02-08T16:25:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 16:25:27 volumio go-librespot[3983]: time="2026-02-08T16:25:27+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 16:25:27 volumio go-librespot[3983]: time="2026-02-08T16:25:27+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 16:25:27 volumio go-librespot[3983]: time="2026-02-08T16:25:27+07:00" level=info msg="zeroconf server listening on port 44301" Feb 08 16:25:27 volumio sudo[3959]: pam_unix(sudo:session): session closed for user root Feb 08 16:25:27 volumio go-librespot[3983]: time="2026-02-08T16:25:27+07:00" level=debug msg="obtained new client token: AABa+hyLD2NTyvRkAqC05a+6IRE/6pTOcmsPvUWvhN1oN6TWpn5TgT10k98n4ZKqY6ueURQt8rm2KGjIGfl15msZd1RsAAlNfrpbztdDgWA8sCMDnTZi1zfrS8oqVOfvKbIlhE/Vs6my5CQxRxaTyEL2fqVBxps2oPw0cZFgdcu8LMr8EPKcVwz/JtbW8LepKkdRGeKUy7dSgWuUZ5qAL3yNl1TWGiyug3dezH+sh42RLpt2LgqLFP0Mdw==" Feb 08 16:25:27 volumio go-librespot[3983]: time="2026-02-08T16:25:27+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 08 16:25:27 volumio go-librespot[3983]: time="2026-02-08T16:25:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 08 16:25:28 volumio go-librespot[3983]: time="2026-02-08T16:25:28+07:00" level=debug msg="completed keyexchange" Feb 08 16:25:28 volumio go-librespot[3983]: time="2026-02-08T16:25:28+07:00" level=debug msg="completed challenge" Feb 08 16:25:28 volumio go-librespot[3983]: time="2026-02-08T16:25:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 16:25:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 16:25:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 16:25:28 volumio volumio[3905]: info: Starting UPNP Browser Feb 08 16:25:28 volumio volumio[3905]: info: Loading plugin "alarm-clock"... Feb 08 16:25:28 volumio volumio[3905]: info: Loading plugin "airplay_emulation"... Feb 08 16:25:29 volumio volumio[3905]: info: Starting Shairport Sync Feb 08 16:25:29 volumio volumio[3905]: info: Loading plugin "last_100"... Feb 08 16:25:29 volumio volumio[3905]: info: Loading plugin "webradio"... Feb 08 16:25:29 volumio volumio[3905]: info: Loading plugin "i2s_dacs"... Feb 08 16:25:29 volumio volumio[3905]: info: Loading plugin "volumiodiscovery"... Feb 08 16:25:29 volumio volumio[3905]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 08 16:25:29 volumio volumio[3905]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 16:25:29 volumio node[3905]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 08 16:25:29 volumio volumio[3905]: *** WARNING *** For more information see Feb 08 16:25:29 volumio volumio[3905]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 08 16:25:29 volumio volumio[3905]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 16:25:29 volumio volumio[3905]: *** WARNING *** For more information see Feb 08 16:25:29 volumio node[3905]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 16:25:29 volumio volumio[3905]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 08 16:25:29 volumio node[3905]: *** WARNING *** For more information see Feb 08 16:25:29 volumio node[3905]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 08 16:25:29 volumio node[3905]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 16:25:29 volumio node[3905]: *** WARNING *** For more information see Feb 08 16:25:29 volumio volumio[3905]: info: Discovery: Started advertising with name: Volumio Feb 08 16:25:29 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 16:25:29 volumio volumio[3905]: info: Loading plugin "spop"... Feb 08 16:25:31 volumio volumio[3905]: info: Loading plugin "ytcr"... Feb 08 16:25:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 08 16:25:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:25:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:25:31 volumio go-librespot[3994]: go-librespot daemon starting... Feb 08 16:25:31 volumio go-librespot[3995]: time="2026-02-08T16:25:31+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 16:25:31 volumio go-librespot[3995]: time="2026-02-08T16:25:31+07:00" level=debug msg="app state loaded" Feb 08 16:25:31 volumio go-librespot[3995]: time="2026-02-08T16:25:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 16:25:31 volumio go-librespot[3995]: time="2026-02-08T16:25:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 16:25:31 volumio go-librespot[3995]: time="2026-02-08T16:25:31+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 16:25:31 volumio go-librespot[3995]: time="2026-02-08T16:25:31+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 16:25:31 volumio go-librespot[3995]: time="2026-02-08T16:25:31+07:00" level=info msg="zeroconf server listening on port 38483" Feb 08 16:25:32 volumio go-librespot[3995]: time="2026-02-08T16:25:32+07:00" level=debug msg="obtained new client token: AADDk9QWsWzhoFtEeCPO1HasopOnhftqLfLi3jBWrUa7cVINfpB6mkNU/3nohxXs+M8hPPCqkKO8C+DdJelCst47J6xBryMQYTM1kIMUMk46r0z9ZETGdtfgI9puM9/5td+CoO0pKAEx9TFiTrsGeykCsrEc7D/cVJhk9a6jkdRPHU5GITyh0m3H8DFEr8wKmzuvuKZFv9I+aDGl0RhhUSltxzpKFfIEja+afBegjvBCVOONiFMKViE=" Feb 08 16:25:32 volumio go-librespot[3995]: time="2026-02-08T16:25:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 16:25:32 volumio go-librespot[3995]: time="2026-02-08T16:25:32+07:00" level=debug msg="completed keyexchange" Feb 08 16:25:32 volumio go-librespot[3995]: time="2026-02-08T16:25:32+07:00" level=debug msg="completed challenge" Feb 08 16:25:32 volumio go-librespot[3995]: time="2026-02-08T16:25:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 16:25:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 16:25:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 16:25:33 volumio volumio[3905]: info: Loading plugin "ytmusic"... Feb 08 16:25:34 volumio volumio-remote-updater[643]: [2026-02-08 16:25:34] [connect] Successful connection Feb 08 16:25:34 volumio volumio[3905]: info: Loading plugin "outputs"... Feb 08 16:25:34 volumio volumio[3905]: info: Loading plugin "albumart"... Feb 08 16:25:35 volumio volumio[3905]: info: Plugin example_plugin is not enabled Feb 08 16:25:35 volumio volumio[3905]: info: Loading plugin "inputs"... Feb 08 16:25:35 volumio volumio[3905]: info: Loading plugin "updater_comm"... Feb 08 16:25:35 volumio volumio[3905]: info: Plugin mpdemulation is not enabled Feb 08 16:25:35 volumio volumio[3905]: info: Loading plugin "rest_api"... Feb 08 16:25:35 volumio volumio[3905]: info: Loading plugin "websocket"... Feb 08 16:25:35 volumio volumio[3905]: info: Starting Socket.io Server version 1.7.4 Feb 08 16:25:35 volumio volumio[3905]: info: Loading plugin "RoonBridge"... Feb 08 16:25:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 08 16:25:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:25:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:25:35 volumio go-librespot[4028]: go-librespot daemon starting... Feb 08 16:25:35 volumio go-librespot[4029]: time="2026-02-08T16:25:35+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 16:25:35 volumio go-librespot[4029]: time="2026-02-08T16:25:35+07:00" level=debug msg="app state loaded" Feb 08 16:25:35 volumio go-librespot[4029]: time="2026-02-08T16:25:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 16:25:35 volumio volumio[3905]: info: Applying required configuration parameters for plugin RoonBridge Feb 08 16:25:35 volumio volumio[3905]: info: Loading i18n strings for locale en Feb 08 16:25:35 volumio volumio[3905]: Updating browse sources language Feb 08 16:25:35 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 16:25:36 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 16:25:36 volumio volumio[3905]: info: CoreCommandRouter::initPlayerControls Feb 08 16:25:36 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:25:36 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:25:36 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:25:36 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:25:36 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:25:36 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:25:36 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:25:36 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:25:36 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 16:25:36 volumio volumio[3905]: Express server listening on port 3000 Feb 08 16:25:36 volumio volumio[3905]: [Metrics] WebUI: 16s 78.32ms Feb 08 16:25:36 volumio volumio[3905]: info: CoreStateMachine::resetVolumioState Feb 08 16:25:36 volumio volumio[3905]: info: CoreStateMachine::getcurrentVolume Feb 08 16:25:36 volumio volumio[3905]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 16:25:36 volumio volumio[4018]: Forking 3 albumart workers Feb 08 16:25:36 volumio go-librespot[4029]: time="2026-02-08T16:25:36+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 16:25:36 volumio go-librespot[4029]: time="2026-02-08T16:25:36+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 16:25:36 volumio go-librespot[4029]: time="2026-02-08T16:25:36+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 16:25:36 volumio go-librespot[4029]: time="2026-02-08T16:25:36+07:00" level=info msg="zeroconf server listening on port 45371" Feb 08 16:25:36 volumio sudo[4045]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 08 16:25:36 volumio sudo[4045]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:25:36 volumio sudo[4045]: pam_unix(sudo:session): session closed for user root Feb 08 16:25:36 volumio sudo[4042]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 08 16:25:36 volumio sudo[4042]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:25:36 volumio volumio[3905]: info: Volumio Network Manager: Network status updated: 1 Feb 08 16:25:36 volumio sudo[4042]: pam_unix(sudo:session): session closed for user root Feb 08 16:25:36 volumio go-librespot[4029]: time="2026-02-08T16:25:36+07:00" level=debug msg="obtained new client token: AAAky+dFRab2byngTExUB/F9LICvu9XXFRjRydSLiSV7hiPz4hkrFzZV8+Y8AxRK0O9086poBUoN2ACCiVVT9vHf0tOX5EH6GrxNVGVUE+kpQUbdMpii3Fd3xJg7tsmjPDAqK3lFgYVgGTCHwe97+oM11Ho6mjtJTfBG813OKO7fn9bRVbTzZQ1XwAfNvWfThEdoqznKP8jNm6+MuD4Eq8FH971oCtj17PgN1j/l+jl2dh+lLdYQB+PLiQ==" Feb 08 16:25:36 volumio go-librespot[4029]: time="2026-02-08T16:25:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 16:25:36 volumio volumio[3905]: info: VolumeController:: Volume=100 Mute =false Feb 08 16:25:36 volumio volumio[3905]: info: CoreStateMachine::pushState Feb 08 16:25:36 volumio volumio[3905]: info: CorePlayQueue::getTrack 0 Feb 08 16:25:36 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 08 16:25:36 volumio volumio[3905]: info: CoreCommandRouter::volumioPushState Feb 08 16:25:36 volumio volumio[3905]: info: CoreStateMachine::updateTrackBlock Feb 08 16:25:36 volumio volumio[3905]: info: CorePlayQueue::getTrackBlock Feb 08 16:25:36 volumio volumio[3905]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 16:25:36 volumio go-librespot[4029]: time="2026-02-08T16:25:36+07:00" level=debug msg="completed keyexchange" Feb 08 16:25:36 volumio go-librespot[4029]: time="2026-02-08T16:25:36+07:00" level=debug msg="completed challenge" Feb 08 16:25:36 volumio volumio-remote-updater[643]: [2026-02-08 16:25:36] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770542734 101 Feb 08 16:25:36 volumio volumio[3905]: 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 16:25:36 volumio go-librespot[4029]: time="2026-02-08T16:25:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 16:25:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 16:25:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 16:25:36 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 16:25:36 volumio volumio[3905]: info: Reloading queue from file Feb 08 16:25:36 volumio volumio[3905]: info: CoreStateMachine::setRepeat null single undefined Feb 08 16:25:36 volumio volumio[3905]: info: CoreStateMachine::pushState Feb 08 16:25:36 volumio volumio[3905]: info: CorePlayQueue::getTrack 0 Feb 08 16:25:36 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 08 16:25:36 volumio volumio[3905]: info: CoreCommandRouter::volumioPushState Feb 08 16:25:36 volumio volumio[3905]: info: CoreStateMachine::setRandom null Feb 08 16:25:36 volumio volumio[3905]: info: CoreStateMachine::pushState Feb 08 16:25:36 volumio volumio[3905]: info: CorePlayQueue::getTrack 0 Feb 08 16:25:36 volumio volumio[3905]: info: CoreCommandRouter::volumioPushState Feb 08 16:25:37 volumio volumio[3905]: info: Setting Device type: Raspberry PI Feb 08 16:25:37 volumio volumio[3905]: info: Completed loading Core Plugins Feb 08 16:25:37 volumio volumio[3905]: info: Preparing to generate the ALSA configuration file Feb 08 16:25:37 volumio volumio[3905]: info: VolumeController:: Volume=100 Mute =false Feb 08 16:25:37 volumio volumio[3905]: info: CoreStateMachine::pushState Feb 08 16:25:37 volumio volumio[3905]: info: CorePlayQueue::getTrack 0 Feb 08 16:25:37 volumio volumio[3905]: info: CoreCommandRouter::volumioPushState Feb 08 16:25:37 volumio volumio[3905]: info: Asound.conf file unchanged, so no further update is needed Feb 08 16:25:37 volumio volumio[3905]: info: Output device has changed, restarting MPD Feb 08 16:25:37 volumio volumio[3905]: info: Output device has changed, restarting Shairport Sync Feb 08 16:25:37 volumio sudo[4088]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 08 16:25:37 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:25:37 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 16:25:37 volumio sudo[4088]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:25:37 volumio sudo[4090]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 16:25:37 volumio sudo[4090]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:25:37 volumio sudo[4090]: pam_unix(sudo:session): session closed for user root Feb 08 16:25:37 volumio sudo[4092]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 16:25:37 volumio sudo[4092]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:25:37 volumio volumio[3905]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 16:25:37 volumio volumio[3905]: info: ___________ START PLUGINS ___________ Feb 08 16:25:37 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 08 16:25:37 volumio volumio[3905]: info: ControllerMpd::onStart: Initializing MPD Feb 08 16:25:37 volumio sudo[4088]: pam_unix(sudo:session): session closed for user root Feb 08 16:25:37 volumio volumio[3905]: info: Creating MPD Configuration file Feb 08 16:25:37 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 16:25:37 volumio volumio[3905]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 16:25:37 volumio volumio[3905]: info: [1770542737644] CoreMusicLibrary::Adding element Media Servers Feb 08 16:25:37 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 16:25:37 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 08 16:25:37 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 08 16:25:37 volumio systemd[1]: mpd.service: Consumed 7.130s CPU time. Feb 08 16:25:37 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 08 16:25:37 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 08 16:25:37 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 08 16:25:37 volumio volumio[3905]: info: UPNP Browser: Client initialized successfully Feb 08 16:25:37 volumio sudo[4101]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 16:25:37 volumio sudo[4101]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:25:37 volumio sudo[4101]: pam_unix(sudo:session): session closed for user root Feb 08 16:25:37 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 08 16:25:37 volumio sudo[4103]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 16:25:37 volumio sudo[4103]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:25:37 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 08 16:25:37 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:25:37 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 16:25:37 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 08 16:25:37 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 08 16:25:37 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 08 16:25:37 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 08 16:25:37 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 08 16:25:37 volumio volumio[3905]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 16:25:37 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:25:37 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 16:25:37 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 08 16:25:37 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 08 16:25:38 volumio volumio[3905]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 16:25:38 volumio volumio[3905]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 16:25:38 volumio volumio[3905]: info: [1770542738004] CoreMusicLibrary::Adding element Last_100 Feb 08 16:25:38 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 16:25:38 volumio volumio[3905]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 16:25:38 volumio volumio[3905]: info: [1770542738013] CoreMusicLibrary::Adding element Webradio Feb 08 16:25:38 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 16:25:38 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 16:25:38 volumio volumio[3905]: info: Initializing BBC Radios Feb 08 16:25:38 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 16:25:38 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 16:25:38 volumio volumio[3905]: info: Creating Spotify config file Feb 08 16:25:38 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:25:38 volumio sudo[4117]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 08 16:25:38 volumio sudo[4117]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 08 16:25:38 volumio sudo[4117]: pam_unix(sudo:session): session closed for user root Feb 08 16:25:39 volumio volumio[4044]: Starting albumart workers Feb 08 16:25:39 volumio volumio[4047]: Starting albumart workers Feb 08 16:25:39 volumio volumio[3905]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 16:25:39 volumio volumio[3905]: info: [1770542739554] CoreMusicLibrary::Adding element YouTube Music Feb 08 16:25:39 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 16:25:39 volumio volumio[3905]: Cannot find translation for source YouTube Music Feb 08 16:25:39 volumio volumio[3905]: info: Volumio Calling Home Feb 08 16:25:39 volumio volumio[4046]: Starting albumart workers Feb 08 16:25:39 volumio sudo[4134]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 08 16:25:39 volumio sudo[4134]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:25:39 volumio sudo[4134]: pam_unix(sudo:session): session closed for user root Feb 08 16:25:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 08 16:25:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:25:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:25:40 volumio go-librespot[4139]: go-librespot daemon starting... Feb 08 16:25:40 volumio go-librespot[4140]: time="2026-02-08T16:25:40+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 16:25:40 volumio volumio[3905]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 08 16:25:40 volumio volumio[3905]: info: Discovery: Found device Volumio Feb 08 16:25:40 volumio volumio[3905]: info: CoreCommandRouter::volumioGetState Feb 08 16:25:40 volumio volumio[3905]: info: CorePlayQueue::getTrack 0 Feb 08 16:25:40 volumio volumio[3905]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 08 16:25:40 volumio volumio[3905]: info: Discovery: Found device Volumio Feb 08 16:25:40 volumio volumio[3905]: info: CoreCommandRouter::volumioGetState Feb 08 16:25:40 volumio volumio[3905]: info: CorePlayQueue::getTrack 0 Feb 08 16:25:40 volumio volumio[3905]: info: MPD Permissions set Feb 08 16:25:40 volumio volumio[3905]: info: MPD Permissions set Feb 08 16:25:40 volumio volumio[3905]: info: Upmpdcli Daemon Started Feb 08 16:25:40 volumio volumio[3905]: info: Volumio called home Feb 08 16:25:40 volumio volumio[3905]: info: Spotify config file written Feb 08 16:25:40 volumio sudo[4148]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 08 16:25:40 volumio sudo[4148]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:25:40 volumio go-librespot[4140]: time="2026-02-08T16:25:40+07:00" level=info msg="zeroconf server listening on port 37559" Feb 08 16:25:40 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 08 16:25:40 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 08 16:25:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:25:41 volumio go-librespot[4150]: go-librespot daemon starting... Feb 08 16:25:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:25:41 volumio sudo[4148]: pam_unix(sudo:session): session closed for user root Feb 08 16:25:41 volumio go-librespot[4151]: time="2026-02-08T16:25:41+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 16:25:41 volumio go-librespot[4151]: time="2026-02-08T16:25:41+07:00" level=debug msg="app state loaded" Feb 08 16:25:41 volumio go-librespot[4151]: time="2026-02-08T16:25:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 16:25:41 volumio volumio[3905]: 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 16:25:41 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:25:41 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:25:41 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:25:41 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:25:41 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:25:41 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:25:41 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:25:41 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:25:41 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 16:25:41 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:25:41 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:25:41 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:25:41 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:25:41 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:25:41 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:25:41 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:25:41 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:25:41 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:25:41 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 16:25:41 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 16:25:41 volumio volumio[3905]: info: No need to fix Spotify hosts Feb 08 16:25:41 volumio go-librespot[4151]: time="2026-02-08T16:25:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 08 16:25:41 volumio go-librespot[4151]: time="2026-02-08T16:25:41+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 16:25:41 volumio go-librespot[4151]: time="2026-02-08T16:25:41+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 16:25:41 volumio go-librespot[4151]: time="2026-02-08T16:25:41+07:00" level=info msg="zeroconf server listening on port 42677" Feb 08 16:25:42 volumio go-librespot[4151]: time="2026-02-08T16:25:42+07:00" level=debug msg="obtained new client token: AADTL73nGpiujC8LbWp8PiQ8FUBMBVp6S7+5J/AZhZRXSN/AUFysID0xTU07ysLQPZjBPaZ0UARDqde7zDV+bEqqCcMPsqRqIPCFBijDN6NORHrdaglh5vrxDp4xjB8/kYZc6UFPNDX1U6GJ0sO2co6FeXjEb+P2VuYDOH4LBPWSTAoaDbowm1SeYlOwi4RBisntDW/w/dwY94evUZnkprk5+2a8CRIH98DC5EnYW+ka3btPH1CiaR8=" Feb 08 16:25:42 volumio go-librespot[4151]: time="2026-02-08T16:25:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 16:25:42 volumio go-librespot[4151]: time="2026-02-08T16:25:42+07:00" level=debug msg="completed keyexchange" Feb 08 16:25:42 volumio go-librespot[4151]: time="2026-02-08T16:25:42+07:00" level=debug msg="completed challenge" Feb 08 16:25:42 volumio volumio[3905]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 08 16:25:42 volumio volumio[3905]: SPOTIFY: BQDaKvxn7pJofW8SmrOIfT-xggvGOYLNvW9P14uYkfxh-2j-mAjhDnuISFjawElpYG225k4_ngt81WN0UytFZXn4tgwhhfHZslygimBW4BuzLzaTe9cyTgvj9TlPwV2O23K9wgsNcimtjjvckqUF7lZzcfJzFU3_4tZ6A6RsmsAP4dQ1yxjkE1RY17AF9JSxLL3eatR90C3vScPWbub_9b4akTgSeSNJ5PMRk0lksSGi8cehRzdEJ2pX9Mgd1lj3VY181IKe6lVgSqkskl28Jyfn3OJsHp_ECGB8r5qous4mVLFXCALcfOCW Feb 08 16:25:42 volumio volumio[3905]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 08 16:25:42 volumio volumio[3905]: info: New Spotify access token = BQDaKvxn7pJofW8SmrOIfT-xggvGOYLNvW9P14uYkfxh-2j-mAjhDnuISFjawElpYG225k4_ngt81WN0UytFZXn4tgwhhfHZslygimBW4BuzLzaTe9cyTgvj9TlPwV2O23K9wgsNcimtjjvckqUF7lZzcfJzFU3_4tZ6A6RsmsAP4dQ1yxjkE1RY17AF9JSxLL3eatR90C3vScPWbub_9b4akTgSeSNJ5PMRk0lksSGi8cehRzdEJ2pX9Mgd1lj3VY181IKe6lVgSqkskl28Jyfn3OJsHp_ECGB8r5qous4mVLFXCALcfOCW Feb 08 16:25:42 volumio volumio[3905]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 08 16:25:42 volumio go-librespot[4151]: time="2026-02-08T16:25:42+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 16:25:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 16:25:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 16:25:42 volumio volumio[3905]: info: Starting Shairport Sync Feb 08 16:25:42 volumio volumio[3905]: info: Starting Shairport Sync Feb 08 16:25:42 volumio volumio[3905]: info: Starting Shairport Sync Feb 08 16:25:42 volumio sudo[4188]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 16:25:42 volumio sudo[4188]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:25:42 volumio sudo[4190]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 16:25:42 volumio sudo[4190]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:25:42 volumio sudo[4192]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 16:25:42 volumio sudo[4192]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:25:42 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 08 16:25:42 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 08 16:25:42 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 16:25:42 volumio systemd[1]: shairport-sync.service: Consumed 2.324s CPU time. Feb 08 16:25:42 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 16:25:42 volumio sudo[4188]: pam_unix(sudo:session): session closed for user root Feb 08 16:25:42 volumio volumio[3905]: info: CoreCommandRouter::volumioGetState Feb 08 16:25:42 volumio volumio[3905]: info: CorePlayQueue::getTrack 0 Feb 08 16:25:43 volumio volumio[3905]: info: Shairport-Sync Started Feb 08 16:25:43 volumio volumio[3905]: Error adding Membership: Error: addMembership EINVAL Feb 08 16:25:43 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 08 16:25:43 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 08 16:25:43 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 16:25:43 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 16:25:43 volumio sudo[4190]: pam_unix(sudo:session): session closed for user root Feb 08 16:25:43 volumio volumio[3905]: 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 16:25:43 volumio sudo[4192]: pam_unix(sudo:session): session closed for user root Feb 08 16:25:43 volumio volumio[3905]: info: Spotify Successfully logged in Feb 08 16:25:43 volumio volumio[3905]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 16:25:43 volumio volumio[3905]: info: [1770542743288] CoreMusicLibrary::Adding element Spotify Feb 08 16:25:43 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 16:25:43 volumio volumio[3905]: Cannot find translation for source YouTube Music Feb 08 16:25:43 volumio volumio[3905]: Cannot find translation for source Spotify Feb 08 16:25:43 volumio volumio[3905]: info: Shairport-Sync Started Feb 08 16:25:43 volumio volumio[3905]: info: Shairport-Sync Started Feb 08 16:25:44 volumio volumio[3905]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 08 16:25:44 volumio volumio[3905]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 16:25:44 volumio volumio[3905]: info: VolumeController:: Volume=100 Mute =false Feb 08 16:25:44 volumio volumio[3905]: info: CoreCommandRouter::volumioGetState Feb 08 16:25:44 volumio volumio[3905]: info: CorePlayQueue::getTrack 0 Feb 08 16:25:44 volumio volumio[3905]: info: CoreStateMachine::pushState Feb 08 16:25:44 volumio volumio[3905]: info: CorePlayQueue::getTrack 0 Feb 08 16:25:44 volumio volumio[3905]: info: CoreCommandRouter::volumioPushState Feb 08 16:25:45 volumio volumio[3905]: info: go-librespot daemon successfully initialized Feb 08 16:25:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 08 16:25:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:25:45 volumio mpd[4132]: 2026-02-08T16:25:45 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 08 16:25:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:25:45 volumio go-librespot[4231]: go-librespot daemon starting... Feb 08 16:25:45 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 08 16:25:45 volumio sudo[4103]: pam_unix(sudo:session): session closed for user root Feb 08 16:25:45 volumio sudo[4092]: pam_unix(sudo:session): session closed for user root Feb 08 16:25:45 volumio go-librespot[4234]: time="2026-02-08T16:25:45+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 16:25:45 volumio go-librespot[4234]: time="2026-02-08T16:25:45+07:00" level=debug msg="app state loaded" Feb 08 16:25:45 volumio go-librespot[4234]: time="2026-02-08T16:25:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 16:25:45 volumio volumio[3905]: error: MPD error: The expression evaluated to a falsy value: Feb 08 16:25:45 volumio volumio[3905]: assert.ok(self.idling) Feb 08 16:25:45 volumio volumio[3905]: error: The expression evaluated to a falsy value: Feb 08 16:25:45 volumio volumio[3905]: assert.ok(self.idling) Feb 08 16:25:45 volumio volumio[3905]: info: Completed starting Core Plugins Feb 08 16:25:45 volumio volumio[3905]: info: ------------------------------------------- Feb 08 16:25:45 volumio volumio[3905]: info: ----- MyVolumio plugins startup ---- Feb 08 16:25:45 volumio volumio[3905]: info: ------------------------------------------- Feb 08 16:25:45 volumio volumio[3905]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 08 16:25:45 volumio volumio[3905]: error: updateQueue error: null Feb 08 16:25:46 volumio volumio[3905]: info: MPD running with PID4132 Feb 08 16:25:46 volumio volumio[3905]: ,establishing connection Feb 08 16:25:46 volumio volumio[3905]: error: updateQueue error: null Feb 08 16:25:46 volumio go-librespot[4234]: time="2026-02-08T16:25:46+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 16:25:46 volumio go-librespot[4234]: time="2026-02-08T16:25:46+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 16:25:46 volumio go-librespot[4234]: time="2026-02-08T16:25:46+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 16:25:46 volumio go-librespot[4234]: time="2026-02-08T16:25:46+07:00" level=info msg="zeroconf server listening on port 34203" Feb 08 16:25:46 volumio go-librespot[4234]: time="2026-02-08T16:25:46+07:00" level=debug msg="obtained new client token: AAAtgE+GSS6Owu+Y1n8QfDURislH1RDDxLUUEeI41m/KkuRRqI0LobQ3AawMCQ9sJaChdVbbzOmMLbk3c/1PPF0HsnpNDHbngp291UgTS3cNsvNI1ykqMNiQ5TAGRjP+YvC5KVG2c3TCOya+G/n5CIMtn1y5UlO+z7u0A829S0pCrpdjWJvRkN6Drj7IxxUOAhBX/o0jLjmZvJD63/ns/unb2zuBo25C9C/7Nrm0gA2kFLSdXq/Yh8V4Pw==" Feb 08 16:25:46 volumio go-librespot[4234]: time="2026-02-08T16:25:46+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 08 16:25:46 volumio go-librespot[4234]: time="2026-02-08T16:25:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 08 16:25:46 volumio go-librespot[4234]: time="2026-02-08T16:25:46+07:00" level=debug msg="completed keyexchange" Feb 08 16:25:46 volumio go-librespot[4234]: time="2026-02-08T16:25:46+07:00" level=debug msg="completed challenge" Feb 08 16:25:46 volumio go-librespot[4234]: time="2026-02-08T16:25:46+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 16:25:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 16:25:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 16:25:48 volumio volumio[3905]: info: Initializing connection to go-librespot Websocket Feb 08 16:25:48 volumio volumio[3905]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 16:25:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 08 16:25:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:25:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:25:50 volumio go-librespot[4243]: go-librespot daemon starting... Feb 08 16:25:50 volumio go-librespot[4244]: time="2026-02-08T16:25:50+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 16:25:50 volumio go-librespot[4244]: time="2026-02-08T16:25:50+07:00" level=debug msg="app state loaded" Feb 08 16:25:50 volumio go-librespot[4244]: time="2026-02-08T16:25:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 16:25:50 volumio go-librespot[4244]: time="2026-02-08T16:25:50+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 16:25:50 volumio go-librespot[4244]: time="2026-02-08T16:25:50+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 16:25:50 volumio go-librespot[4244]: time="2026-02-08T16:25:50+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 16:25:50 volumio go-librespot[4244]: time="2026-02-08T16:25:50+07:00" level=info msg="zeroconf server listening on port 36181" Feb 08 16:25:50 volumio volumio[3905]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 08 16:25:50 volumio go-librespot[4244]: time="2026-02-08T16:25:50+07:00" level=debug msg="obtained new client token: AAC7TtTJwITHLImZOVM1fD7GV6kBMg1TQvci1Oawj3pBgFoFijAQ4gJiDkv4xMjsVhjqejL16v4W28qKhWf3hd6hnb8XVE3gMHyAEwdhsWiSh2djbRgHkZusOzAsIBiT0YdzxgA6OYQtnOUkBMHk4CAXX21bHwbU3iAsfacXJqUtzB5uFV/R6QSjAVzFqCpDtJvugFpWd121eyPw5yGZsRUGjB+N9G7Yal0tguvbxf4cbe9Fj7XWyEMaJg==" Feb 08 16:25:50 volumio go-librespot[4244]: time="2026-02-08T16:25:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 16:25:51 volumio go-librespot[4244]: time="2026-02-08T16:25:51+07:00" level=debug msg="completed keyexchange" Feb 08 16:25:51 volumio go-librespot[4244]: time="2026-02-08T16:25:51+07:00" level=debug msg="completed challenge" Feb 08 16:25:51 volumio go-librespot[4244]: time="2026-02-08T16:25:51+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 16:25:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 16:25:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 16:25:51 volumio volumio[3905]: info: Initializing connection to go-librespot Websocket Feb 08 16:25:51 volumio volumio[3905]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 16:25:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 08 16:25:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:25:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:25:54 volumio go-librespot[4252]: go-librespot daemon starting... Feb 08 16:25:54 volumio go-librespot[4253]: time="2026-02-08T16:25:54+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 16:25:54 volumio go-librespot[4253]: time="2026-02-08T16:25:54+07:00" level=debug msg="app state loaded" Feb 08 16:25:54 volumio go-librespot[4253]: time="2026-02-08T16:25:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 16:25:54 volumio volumio[3905]: info: Initializing connection to go-librespot Websocket Feb 08 16:25:54 volumio go-librespot[4253]: time="2026-02-08T16:25:54+07:00" level=debug msg="new websocket client" Feb 08 16:25:54 volumio volumio[3905]: info: Connection to go-librespot Websocket established Feb 08 16:25:54 volumio volumio[3905]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 08 16:25:54 volumio volumio[3905]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 08 16:25:54 volumio volumio[3905]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 08 16:25:54 volumio volumio[3905]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 08 16:25:54 volumio volumio[3905]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 08 16:25:54 volumio volumio[3905]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 08 16:25:54 volumio volumio[3905]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 08 16:25:54 volumio volumio[3905]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 08 16:25:54 volumio volumio[3905]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 08 16:25:54 volumio volumio[3905]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 08 16:25:54 volumio volumio[3905]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 08 16:25:54 volumio volumio[3905]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 08 16:25:54 volumio volumio[3905]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 08 16:25:54 volumio volumio[3905]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 08 16:25:54 volumio volumio[3905]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 08 16:25:54 volumio volumio[3905]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 08 16:25:54 volumio volumio[3905]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 08 16:25:54 volumio volumio[3905]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 08 16:25:54 volumio volumio[3905]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 08 16:25:54 volumio volumio[3905]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 08 16:25:54 volumio volumio[3905]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 08 16:25:54 volumio volumio[3905]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 08 16:25:54 volumio volumio[3905]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 08 16:25:54 volumio volumio[3905]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 08 16:25:54 volumio volumio[3905]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 08 16:25:54 volumio volumio[3905]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 08 16:25:54 volumio volumio[3905]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 08 16:25:54 volumio volumio[3905]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 08 16:25:54 volumio volumio[3905]: info: Adding plugin bluetooth to MyMusic Plugins Feb 08 16:25:54 volumio volumio[3905]: info: Adding plugin multiroom to MyMusic Plugins Feb 08 16:25:54 volumio volumio[3905]: info: Adding plugin metavolumio to MyMusic Plugins Feb 08 16:25:54 volumio volumio[3905]: info: Adding plugin cd_controller to MyMusic Plugins Feb 08 16:25:54 volumio volumio[3905]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 08 16:25:54 volumio volumio[3905]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 08 16:25:54 volumio volumio[3905]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 08 16:25:54 volumio volumio[3905]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 08 16:25:54 volumio go-librespot[4253]: time="2026-02-08T16:25:54+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 16:25:54 volumio go-librespot[4253]: time="2026-02-08T16:25:54+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 16:25:54 volumio go-librespot[4253]: time="2026-02-08T16:25:54+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 16:25:54 volumio go-librespot[4253]: time="2026-02-08T16:25:54+07:00" level=info msg="zeroconf server listening on port 38129" Feb 08 16:25:55 volumio go-librespot[4253]: time="2026-02-08T16:25:55+07:00" level=debug msg="obtained new client token: AABPccEH3v5gk309iyfZF6ss/6XF7OcbQa8on1YTQop5cRObVWLMU4Rd1fDvqMqG04q9zALTxtq7HAcofTDZjeCzfmFW087HOBlKA6cOeJufqf31bGUzzmRFwlIDALodACnIjLTxEGs90egFzrqi+T9x3WkOMBdwDg8cbZNjhJHjFndN48GK8zclrAhi/ND3b0MuOtBD/SQbONrQVJ6TJZ79DrUqlBjn21WEfqOTAhG5qzwuaEbG4Co=" Feb 08 16:25:55 volumio go-librespot[4253]: time="2026-02-08T16:25:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 16:25:55 volumio go-librespot[4253]: time="2026-02-08T16:25:55+07:00" level=debug msg="completed keyexchange" Feb 08 16:25:55 volumio go-librespot[4253]: time="2026-02-08T16:25:55+07:00" level=debug msg="completed challenge" Feb 08 16:25:55 volumio go-librespot[4253]: time="2026-02-08T16:25:55+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 16:25:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 16:25:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 16:25:56 volumio volumio[3905]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 08 16:25:56 volumio volumio[3905]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 08 16:25:56 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 16:25:56 volumio volumio[3905]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 16:25:56 volumio volumio[3905]: info: Starting MyVolumio Remote Streaming Endpoints Feb 08 16:25:56 volumio volumio[3905]: info: MyVolumio login type: Token Feb 08 16:25:56 volumio volumio[3905]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 08 16:25:56 volumio volumio[3905]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 08 16:25:58 volumio volumio[3905]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 08 16:25:58 volumio volumio[3905]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 08 16:25:58 volumio volumio[3905]: info: Streaming services startup Feb 08 16:25:58 volumio volumio[3905]: info: Starting Streaming Daemon Feb 08 16:25:58 volumio sudo[4275]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 08 16:25:58 volumio sudo[4275]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 16:25:58 volumio volumio[3905]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 08 16:25:58 volumio sudo[4275]: pam_unix(sudo:session): session closed for user root Feb 08 16:25:58 volumio volumio[3905]: info: Getting Spotify volume Feb 08 16:25:58 volumio volumio[3905]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 16:25:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 08 16:25:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:25:58 volumio volumio[3905]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 16:25:58 volumio volumio[3905]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 08 16:25:58 volumio volumio[3905]: errno: -111, Feb 08 16:25:58 volumio volumio[3905]: code: 'ECONNREFUSED', Feb 08 16:25:58 volumio volumio[3905]: syscall: 'connect', Feb 08 16:25:58 volumio volumio[3905]: address: '127.0.0.1', Feb 08 16:25:58 volumio volumio[3905]: port: 9879, Feb 08 16:25:58 volumio volumio[3905]: response: undefined Feb 08 16:25:58 volumio volumio[3905]: } Feb 08 16:25:58 volumio volumio[3905]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 16:25:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 16:25:58 volumio go-librespot[4281]: go-librespot daemon starting... Feb 08 16:25:58 volumio go-librespot[4285]: time="2026-02-08T16:25:58+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 16:25:58 volumio go-librespot[4285]: time="2026-02-08T16:25:58+07:00" level=debug msg="app state loaded" Feb 08 16:25:58 volumio go-librespot[4285]: time="2026-02-08T16:25:58+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 16:25:59 volumio go-librespot[4285]: time="2026-02-08T16:25: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 16:25:59 volumio go-librespot[4285]: time="2026-02-08T16:25:59+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 16:25:59 volumio go-librespot[4285]: time="2026-02-08T16:25:59+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 16:25:59 volumio go-librespot[4285]: time="2026-02-08T16:25:59+07:00" level=info msg="zeroconf server listening on port 42887" Feb 08 16:25:59 volumio go-librespot[4285]: time="2026-02-08T16:25:59+07:00" level=debug msg="obtained new client token: AAA2sA41AjhZHnaeoURHxP3q/tE1qXG7q87GOFSYqMbOTWNYCSK48OE5uEirSYblqurBMI98pr2mBUya/NqAVpe3e93bEqY1uKygKuhRl+SLGJt7B2zZoLAqcrHhA085o5UXjuSPGU82tuhRibayEL40YAOPNjUJFrrui+HoCHXYh1Zg0mvuJz3952rspAYxY0zed2VJ11EtqG1sCMzjge/3VixKAOAHc6paKWDZTcYU2xhhHuYoikR1LQ==" Feb 08 16:25:59 volumio go-librespot[4285]: time="2026-02-08T16:25:59+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 16:25:59 volumio go-librespot[4285]: time="2026-02-08T16:25:59+07:00" level=debug msg="completed keyexchange" Feb 08 16:25:59 volumio go-librespot[4285]: time="2026-02-08T16:25:59+07:00" level=debug msg="completed challenge" Feb 08 16:25:59 volumio go-librespot[4285]: time="2026-02-08T16:25:59+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 16:25:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 16:25:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 16:26:00 volumio sudo[4305]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-08 16:24' Feb 08 16:26:00 volumio sudo[4305]: 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"