Feb 18 09:12:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 18 09:12:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:12:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:12:00 volumio go-librespot[17869]: go-librespot daemon starting... Feb 18 09:12:00 volumio go-librespot[17870]: time="2026-02-18T09:12:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 09:12:00 volumio go-librespot[17870]: time="2026-02-18T09:12:00+07:00" level=debug msg="app state loaded" Feb 18 09:12:00 volumio go-librespot[17870]: time="2026-02-18T09:12:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 09:12:00 volumio go-librespot[17870]: time="2026-02-18T09:12:00+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 09:12:00 volumio go-librespot[17870]: time="2026-02-18T09:12:00+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 09:12:00 volumio go-librespot[17870]: time="2026-02-18T09:12:00+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 09:12:00 volumio go-librespot[17870]: time="2026-02-18T09:12:00+07:00" level=info msg="zeroconf server listening on port 35037" Feb 18 09:12:00 volumio go-librespot[17870]: time="2026-02-18T09:12:00+07:00" level=debug msg="obtained new client token: AABO5dhJN38kJ1vTpseIWNeKMmkA0vwmoquZH+YgrpLEbSwAy9SWrkDqPowGTTxv5AvYagGJk0cBELXGDy4bl86TbxpYPfWbYwW/gBdnSyZLQ76u+kqlCzRvATQx5pEDzJvEQx1gl7663yioxrhtn62no+RaGxJzPRTMw0H55+6C/vTcYRbGeqS2GcYu25n+20WB6e8HjfVSJgU4ngcNcSGw70vWUIX2AynB5OFvDxDkvGq2UyCWD3vuHw==" Feb 18 09:12:01 volumio go-librespot[17870]: time="2026-02-18T09:12:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 09:12:01 volumio go-librespot[17870]: time="2026-02-18T09:12:01+07:00" level=debug msg="completed keyexchange" Feb 18 09:12:01 volumio go-librespot[17870]: time="2026-02-18T09:12:01+07:00" level=debug msg="completed challenge" Feb 18 09:12:01 volumio go-librespot[17870]: time="2026-02-18T09:12:01+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 09:12:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 09:12:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 09:12:02 volumio volumio[17782]: info: Loading plugin "ytmusic"... Feb 18 09:12:03 volumio volumio-remote-updater[25144]: [2026-02-18 09:12:03] [connect] Successful connection Feb 18 09:12:03 volumio volumio[17782]: info: Loading plugin "outputs"... Feb 18 09:12:03 volumio volumio[17782]: info: Loading plugin "albumart"... Feb 18 09:12:03 volumio volumio[17782]: info: Plugin example_plugin is not enabled Feb 18 09:12:03 volumio volumio[17782]: info: Loading plugin "inputs"... Feb 18 09:12:03 volumio volumio[17782]: info: Loading plugin "updater_comm"... Feb 18 09:12:03 volumio volumio[17782]: info: Plugin mpdemulation is not enabled Feb 18 09:12:03 volumio volumio[17782]: info: Loading plugin "rest_api"... Feb 18 09:12:04 volumio volumio[17782]: info: Loading plugin "websocket"... Feb 18 09:12:04 volumio volumio[17782]: info: Starting Socket.io Server version 1.7.4 Feb 18 09:12:04 volumio volumio[17782]: info: Loading plugin "RoonBridge"... Feb 18 09:12:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 18 09:12:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:12:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:12:04 volumio go-librespot[17906]: go-librespot daemon starting... Feb 18 09:12:04 volumio go-librespot[17907]: time="2026-02-18T09:12:04+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 09:12:04 volumio go-librespot[17907]: time="2026-02-18T09:12:04+07:00" level=debug msg="app state loaded" Feb 18 09:12:04 volumio go-librespot[17907]: time="2026-02-18T09:12:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 09:12:04 volumio volumio[17782]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 09:12:04 volumio volumio[17782]: info: Loading i18n strings for locale en Feb 18 09:12:04 volumio volumio[17782]: Updating browse sources language Feb 18 09:12:04 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 09:12:04 volumio volumio[17896]: Forking 3 albumart workers Feb 18 09:12:04 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 09:12:04 volumio volumio[17782]: info: CoreCommandRouter::initPlayerControls Feb 18 09:12:04 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:04 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:04 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:04 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:04 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:04 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:04 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:04 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:05 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 09:12:05 volumio volumio[17782]: Express server listening on port 3000 Feb 18 09:12:05 volumio volumio[17782]: [Metrics] WebUI: 16s 234.33ms Feb 18 09:12:05 volumio volumio[17782]: info: CoreStateMachine::resetVolumioState Feb 18 09:12:05 volumio volumio[17782]: info: CoreStateMachine::getcurrentVolume Feb 18 09:12:05 volumio volumio[17782]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 09:12:05 volumio go-librespot[17907]: time="2026-02-18T09:12:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 09:12:05 volumio go-librespot[17907]: time="2026-02-18T09:12:05+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 09:12:05 volumio go-librespot[17907]: time="2026-02-18T09:12:05+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 09:12:05 volumio go-librespot[17907]: time="2026-02-18T09:12:05+07:00" level=info msg="zeroconf server listening on port 45197" Feb 18 09:12:05 volumio sudo[17953]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 09:12:05 volumio sudo[17953]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:12:05 volumio sudo[17951]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 09:12:05 volumio sudo[17951]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:12:05 volumio sudo[17953]: pam_unix(sudo:session): session closed for user root Feb 18 09:12:05 volumio go-librespot[17907]: time="2026-02-18T09:12:05+07:00" level=debug msg="obtained new client token: AABIAOfgPzppstCLJ0B/cOhattkQt1tIKYICr6m2pQckBIO/0eu6JTg+pQy7+pQENZka41NvJ8guEMYfy3HO2e9l9cmQJ9kxcHCkZwD85yPq4qvO6HrbDEpYM1kWrMDMArIB62nRzS5Cti6CxgPyHk7P+3q8+VSNYojLuXRXcrNP3UrqEQcFZ2a7izmWwDgv56ipmh4Ylj+qIts8ABFFQq896aSwzWcU5RXLCiW9QygLSrzIMgBEf/AgPA==" Feb 18 09:12:05 volumio volumio[17782]: info: Volumio Network Manager: Network status updated: 1 Feb 18 09:12:05 volumio sudo[17951]: pam_unix(sudo:session): session closed for user root Feb 18 09:12:05 volumio go-librespot[17907]: time="2026-02-18T09:12:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 09:12:05 volumio go-librespot[17907]: time="2026-02-18T09:12:05+07:00" level=debug msg="completed keyexchange" Feb 18 09:12:05 volumio go-librespot[17907]: time="2026-02-18T09:12:05+07:00" level=debug msg="completed challenge" Feb 18 09:12:05 volumio go-librespot[17907]: time="2026-02-18T09:12:05+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 09:12:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 09:12:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 09:12:05 volumio volumio[17782]: info: VolumeController:: Volume=100 Mute =false Feb 18 09:12:05 volumio volumio[17782]: info: CoreStateMachine::pushState Feb 18 09:12:05 volumio volumio[17782]: info: CorePlayQueue::getTrack 0 Feb 18 09:12:05 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 09:12:05 volumio volumio[17782]: info: CoreCommandRouter::volumioPushState Feb 18 09:12:05 volumio volumio[17782]: info: CoreStateMachine::updateTrackBlock Feb 18 09:12:05 volumio volumio[17782]: info: CorePlayQueue::getTrackBlock Feb 18 09:12:05 volumio volumio[17782]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 09:12:05 volumio volumio-remote-updater[25144]: [2026-02-18 09:12:05] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771380723 101 Feb 18 09:12:05 volumio volumio[17782]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 18 09:12:05 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 09:12:05 volumio volumio[17782]: info: Reloading queue from file Feb 18 09:12:05 volumio volumio[17782]: info: CoreStateMachine::setRepeat null single undefined Feb 18 09:12:05 volumio volumio[17782]: info: CoreStateMachine::pushState Feb 18 09:12:05 volumio volumio[17782]: info: CorePlayQueue::getTrack 0 Feb 18 09:12:05 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 09:12:05 volumio volumio[17782]: info: CoreCommandRouter::volumioPushState Feb 18 09:12:05 volumio volumio[17782]: info: CoreStateMachine::setRandom null Feb 18 09:12:05 volumio volumio[17782]: info: CoreStateMachine::pushState Feb 18 09:12:05 volumio volumio[17782]: info: CorePlayQueue::getTrack 0 Feb 18 09:12:05 volumio volumio[17782]: info: CoreCommandRouter::volumioPushState Feb 18 09:12:05 volumio volumio[17782]: info: Setting Device type: Raspberry PI Feb 18 09:12:05 volumio volumio[17782]: info: Completed loading Core Plugins Feb 18 09:12:05 volumio volumio[17782]: info: Preparing to generate the ALSA configuration file Feb 18 09:12:06 volumio volumio[17782]: info: VolumeController:: Volume=100 Mute =false Feb 18 09:12:06 volumio volumio[17782]: info: CoreStateMachine::pushState Feb 18 09:12:06 volumio volumio[17782]: info: CorePlayQueue::getTrack 0 Feb 18 09:12:06 volumio volumio[17782]: info: CoreCommandRouter::volumioPushState Feb 18 09:12:06 volumio volumio[17782]: info: Asound.conf file unchanged, so no further update is needed Feb 18 09:12:06 volumio volumio[17782]: info: Output device has changed, restarting MPD Feb 18 09:12:06 volumio volumio[17782]: info: Output device has changed, restarting Shairport Sync Feb 18 09:12:06 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:06 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 09:12:06 volumio sudo[17967]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 09:12:06 volumio sudo[17967]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:12:06 volumio volumio[17782]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 09:12:06 volumio volumio[17782]: info: ___________ START PLUGINS ___________ Feb 18 09:12:06 volumio sudo[17969]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 09:12:06 volumio sudo[17969]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:12:06 volumio volumio[17782]: info: ControllerMpd::onStart: Initializing MPD Feb 18 09:12:06 volumio volumio[17782]: info: Creating MPD Configuration file Feb 18 09:12:06 volumio sudo[17969]: pam_unix(sudo:session): session closed for user root Feb 18 09:12:06 volumio sudo[17972]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 09:12:06 volumio sudo[17972]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:12:06 volumio sudo[17967]: pam_unix(sudo:session): session closed for user root Feb 18 09:12:06 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 09:12:06 volumio volumio[17782]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 09:12:06 volumio volumio[17782]: info: [1771380726365] CoreMusicLibrary::Adding element Media Servers Feb 18 09:12:06 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 09:12:06 volumio volumio[17782]: info: UPNP Browser: Client initialized successfully Feb 18 09:12:06 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 09:12:06 volumio sudo[17982]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 09:12:06 volumio sudo[17979]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 09:12:06 volumio sudo[17982]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:12:06 volumio sudo[17979]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:12:06 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:06 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 09:12:06 volumio sudo[17979]: pam_unix(sudo:session): session closed for user root Feb 18 09:12:06 volumio volumio[17782]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 09:12:06 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:06 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 09:12:06 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 09:12:06 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 09:12:06 volumio systemd[1]: mpd.service: Consumed 7.125s CPU time. Feb 18 09:12:06 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 09:12:06 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 09:12:06 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 09:12:06 volumio volumio[17782]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 09:12:06 volumio volumio[17782]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 09:12:06 volumio volumio[17782]: info: [1771380726699] CoreMusicLibrary::Adding element Last_100 Feb 18 09:12:06 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 09:12:06 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 09:12:06 volumio volumio[17782]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 09:12:06 volumio volumio[17782]: info: [1771380726715] CoreMusicLibrary::Adding element Webradio Feb 18 09:12:06 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 09:12:06 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 09:12:06 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 09:12:06 volumio volumio[17782]: info: Initializing BBC Radios Feb 18 09:12:06 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 09:12:06 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 09:12:06 volumio volumio[17782]: info: Creating Spotify config file Feb 18 09:12:06 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:07 volumio sudo[17994]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 09:12:07 volumio sudo[17994]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 09:12:07 volumio sudo[17994]: pam_unix(sudo:session): session closed for user root Feb 18 09:12:07 volumio volumio[17917]: Starting albumart workers Feb 18 09:12:08 volumio volumio[17916]: Starting albumart workers Feb 18 09:12:08 volumio volumio[17915]: Starting albumart workers Feb 18 09:12:08 volumio volumio[17782]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 09:12:08 volumio volumio[17782]: info: [1771380728407] CoreMusicLibrary::Adding element YouTube Music Feb 18 09:12:08 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 09:12:08 volumio volumio[17782]: Cannot find translation for source YouTube Music Feb 18 09:12:08 volumio volumio[17782]: info: Volumio Calling Home Feb 18 09:12:08 volumio sudo[18011]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 09:12:08 volumio sudo[18011]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:12:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 18 09:12:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:12:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:12:08 volumio go-librespot[18016]: go-librespot daemon starting... Feb 18 09:12:08 volumio sudo[18011]: pam_unix(sudo:session): session closed for user root Feb 18 09:12:08 volumio go-librespot[18017]: time="2026-02-18T09:12:08+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 09:12:09 volumio volumio[17782]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 09:12:09 volumio volumio[17782]: info: Discovery: Found device Volumio Feb 18 09:12:09 volumio volumio[17782]: info: CoreCommandRouter::volumioGetState Feb 18 09:12:09 volumio volumio[17782]: info: CorePlayQueue::getTrack 0 Feb 18 09:12:09 volumio volumio[17782]: info: MPD Permissions set Feb 18 09:12:09 volumio volumio[17782]: info: MPD Permissions set Feb 18 09:12:09 volumio volumio[17782]: info: Upmpdcli Daemon Started Feb 18 09:12:09 volumio go-librespot[18017]: time="2026-02-18T09:12:09+07:00" level=info msg="zeroconf server listening on port 32911" Feb 18 09:12:09 volumio volumio[17782]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 09:12:09 volumio volumio[17782]: info: Discovery: Found device Volumio Feb 18 09:12:09 volumio volumio[17782]: info: CoreCommandRouter::volumioGetState Feb 18 09:12:09 volumio volumio[17782]: info: CorePlayQueue::getTrack 0 Feb 18 09:12:09 volumio volumio[17782]: info: Volumio called home Feb 18 09:12:09 volumio volumio[17782]: info: Spotify config file written Feb 18 09:12:09 volumio sudo[18025]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 09:12:09 volumio sudo[18025]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:12:10 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 18 09:12:10 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 18 09:12:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:12:10 volumio volumio[17782]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 18 09:12:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:12:10 volumio go-librespot[18039]: go-librespot daemon starting... Feb 18 09:12:10 volumio sudo[18025]: pam_unix(sudo:session): session closed for user root Feb 18 09:12:10 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:10 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:10 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:10 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:10 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:10 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:10 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:10 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:10 volumio go-librespot[18040]: time="2026-02-18T09:12:10+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 09:12:10 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 09:12:10 volumio go-librespot[18040]: time="2026-02-18T09:12:10+07:00" level=debug msg="app state loaded" Feb 18 09:12:10 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:10 volumio go-librespot[18040]: time="2026-02-18T09:12:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 09:12:10 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:10 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:10 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:10 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:10 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:10 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:10 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:10 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:10 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 09:12:10 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:10 volumio volumio[17782]: info: No need to fix Spotify hosts Feb 18 09:12:10 volumio go-librespot[18040]: time="2026-02-18T09:12: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 09:12:10 volumio go-librespot[18040]: time="2026-02-18T09:12:10+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 09:12:10 volumio go-librespot[18040]: time="2026-02-18T09:12:10+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 09:12:10 volumio go-librespot[18040]: time="2026-02-18T09:12:10+07:00" level=info msg="zeroconf server listening on port 45073" Feb 18 09:12:11 volumio go-librespot[18040]: time="2026-02-18T09:12:11+07:00" level=debug msg="obtained new client token: AAA35dsBcSlGUpVaT8J5K0/4O6xG8whNa2dsb3OcS/Kp4bCAVva8uqzuTQ9BqGGF0YNPeuzhhGfw8QfVEgyBj0F1FQcL0P9Kn2G47TwV3mutGTnYvKEN9b/LD96OtszfXcV+kHa7D7p+0WwYzYzuJMDqO69MkcDoKzEGAk4/OLHK3zdXM/10FMVkJPFnIRNHacs/sn8/x6P+/XoeQ+d08s9g5C3be93G5s1WJyt5gVxHK5Ii8CjU3eA=" Feb 18 09:12:11 volumio volumio[17782]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 09:12:11 volumio volumio[17782]: SPOTIFY: BQChfWtmnHUaSbBEcR4ixUW7Pr7G1apCn14rfrui8ojY3x7ccr3G_Y1vhiBh5FAu459geBs4Ih_t_WylHn15Sm1tjw4pagZLjfKDgDhH0cVzrem1nzJ1VewSsshWJqIquaXll7mr2RmsYLKC7xl2OgjJyYunDRNTIKHkPWMggJP-kfk9BcztHflgD2zeql1U2PQ9CuGheWogY7tFtbgib9S48KVXMrnmA8A82MUM95PmpWWXf3wHgkdgX863zKq2n-XwTFwJlZRw8Ou3lWxUZ_rCEC7j5hKVHQna1vmnnDWk2S14JbhSmLw6 Feb 18 09:12:11 volumio volumio[17782]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 09:12:11 volumio volumio[17782]: info: New Spotify access token = BQChfWtmnHUaSbBEcR4ixUW7Pr7G1apCn14rfrui8ojY3x7ccr3G_Y1vhiBh5FAu459geBs4Ih_t_WylHn15Sm1tjw4pagZLjfKDgDhH0cVzrem1nzJ1VewSsshWJqIquaXll7mr2RmsYLKC7xl2OgjJyYunDRNTIKHkPWMggJP-kfk9BcztHflgD2zeql1U2PQ9CuGheWogY7tFtbgib9S48KVXMrnmA8A82MUM95PmpWWXf3wHgkdgX863zKq2n-XwTFwJlZRw8Ou3lWxUZ_rCEC7j5hKVHQna1vmnnDWk2S14JbhSmLw6 Feb 18 09:12:11 volumio volumio[17782]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 09:12:11 volumio volumio[17782]: info: Starting Shairport Sync Feb 18 09:12:11 volumio go-librespot[18040]: time="2026-02-18T09:12:11+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 18 09:12:11 volumio volumio[17782]: info: Starting Shairport Sync Feb 18 09:12:11 volumio volumio[17782]: info: Starting Shairport Sync Feb 18 09:12:11 volumio sudo[18064]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 09:12:11 volumio sudo[18064]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:12:11 volumio go-librespot[18040]: time="2026-02-18T09:12:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 18 09:12:11 volumio sudo[18066]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 09:12:11 volumio sudo[18066]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:12:11 volumio sudo[18069]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 09:12:11 volumio sudo[18069]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:12:11 volumio go-librespot[18040]: time="2026-02-18T09:12:11+07:00" level=debug msg="completed keyexchange" Feb 18 09:12:11 volumio go-librespot[18040]: time="2026-02-18T09:12:11+07:00" level=debug msg="completed challenge" Feb 18 09:12:11 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 09:12:11 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 09:12:11 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 09:12:11 volumio systemd[1]: shairport-sync.service: Consumed 2.335s CPU time. Feb 18 09:12:11 volumio go-librespot[18040]: time="2026-02-18T09:12:11+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 09:12:11 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 09:12:11 volumio sudo[18064]: pam_unix(sudo:session): session closed for user root Feb 18 09:12:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 09:12:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 09:12:11 volumio sudo[18066]: pam_unix(sudo:session): session closed for user root Feb 18 09:12:11 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 09:12:11 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 09:12:11 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 09:12:11 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 09:12:11 volumio sudo[18069]: pam_unix(sudo:session): session closed for user root Feb 18 09:12:11 volumio volumio[17782]: info: Shairport-Sync Started Feb 18 09:12:11 volumio volumio[17782]: Error adding Membership: Error: addMembership EINVAL Feb 18 09:12:11 volumio volumio[17782]: info: Shairport-Sync Started Feb 18 09:12:11 volumio volumio[17782]: info: Shairport-Sync Started Feb 18 09:12:11 volumio volumio[17782]: info: CoreCommandRouter::volumioGetState Feb 18 09:12:11 volumio volumio[17782]: info: CorePlayQueue::getTrack 0 Feb 18 09:12:12 volumio volumio[17782]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 18 09:12:12 volumio volumio[17782]: info: Spotify Successfully logged in Feb 18 09:12:12 volumio volumio[17782]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 09:12:12 volumio volumio[17782]: info: [1771380732141] CoreMusicLibrary::Adding element Spotify Feb 18 09:12:12 volumio volumio[17782]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 09:12:12 volumio volumio[17782]: Cannot find translation for source YouTube Music Feb 18 09:12:12 volumio volumio[17782]: Cannot find translation for source Spotify Feb 18 09:12:12 volumio volumio[17782]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 09:12:12 volumio volumio[17782]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 09:12:13 volumio volumio[17782]: info: VolumeController:: Volume=100 Mute =false Feb 18 09:12:13 volumio volumio[17782]: info: CoreCommandRouter::volumioGetState Feb 18 09:12:13 volumio volumio[17782]: info: CorePlayQueue::getTrack 0 Feb 18 09:12:13 volumio volumio[17782]: info: CoreStateMachine::pushState Feb 18 09:12:13 volumio volumio[17782]: info: CorePlayQueue::getTrack 0 Feb 18 09:12:13 volumio volumio[17782]: info: CoreCommandRouter::volumioPushState Feb 18 09:12:14 volumio volumio[17782]: info: go-librespot daemon successfully initialized Feb 18 09:12:14 volumio mpd[18009]: 2026-02-18T09:12:14 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 09:12:14 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 09:12:14 volumio sudo[17972]: pam_unix(sudo:session): session closed for user root Feb 18 09:12:14 volumio sudo[17982]: pam_unix(sudo:session): session closed for user root Feb 18 09:12:14 volumio volumio[17782]: error: MPD error: The expression evaluated to a falsy value: Feb 18 09:12:14 volumio volumio[17782]: assert.ok(self.idling) Feb 18 09:12:14 volumio volumio[17782]: error: The expression evaluated to a falsy value: Feb 18 09:12:14 volumio volumio[17782]: assert.ok(self.idling) Feb 18 09:12:14 volumio volumio[17782]: info: MPD running with PID18009 Feb 18 09:12:14 volumio volumio[17782]: ,establishing connection Feb 18 09:12:14 volumio volumio[17782]: error: updateQueue error: null Feb 18 09:12:14 volumio volumio[17782]: info: Completed starting Core Plugins Feb 18 09:12:14 volumio volumio[17782]: info: ------------------------------------------- Feb 18 09:12:14 volumio volumio[17782]: info: ----- MyVolumio plugins startup ---- Feb 18 09:12:14 volumio volumio[17782]: info: ------------------------------------------- Feb 18 09:12:14 volumio volumio[17782]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 09:12:14 volumio volumio[17782]: error: updateQueue error: null Feb 18 09:12:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 18 09:12:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:12:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:12:14 volumio go-librespot[18109]: go-librespot daemon starting... Feb 18 09:12:14 volumio go-librespot[18110]: time="2026-02-18T09:12:14+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 09:12:14 volumio go-librespot[18110]: time="2026-02-18T09:12:14+07:00" level=debug msg="app state loaded" Feb 18 09:12:14 volumio go-librespot[18110]: time="2026-02-18T09:12:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 09:12:15 volumio go-librespot[18110]: time="2026-02-18T09:12:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 09:12:15 volumio go-librespot[18110]: time="2026-02-18T09:12:15+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 09:12:15 volumio go-librespot[18110]: time="2026-02-18T09:12:15+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 09:12:15 volumio go-librespot[18110]: time="2026-02-18T09:12:15+07:00" level=info msg="zeroconf server listening on port 42419" Feb 18 09:12:15 volumio go-librespot[18110]: time="2026-02-18T09:12:15+07:00" level=debug msg="obtained new client token: AABljYZyfxp7UyaJ11thMJwzswETh8j98W6MGEUENxoAOHEsqJFqIuHK4vnGMvUKnbB0m7yzTFsKRDHjZZxHxObAxMMQlDuIc99gDxkzg1HHsPtZpzQubqT1eVzhT7GE570TSN9f65wVtqFpG70vp6PhJo77Bl3izRhtW/t63wOWktL5C4FFenPSHMvRNQFzIwWTPwZLObvzWqsewd9Q600LvR9vQHNiUStlvaAGYUhXTuFEab4er8RElg==" Feb 18 09:12:15 volumio go-librespot[18110]: time="2026-02-18T09:12:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 09:12:15 volumio go-librespot[18110]: time="2026-02-18T09:12:15+07:00" level=debug msg="completed keyexchange" Feb 18 09:12:15 volumio go-librespot[18110]: time="2026-02-18T09:12:15+07:00" level=debug msg="completed challenge" Feb 18 09:12:15 volumio go-librespot[18110]: time="2026-02-18T09:12: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 18 09:12:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 09:12:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 09:12:17 volumio volumio[17782]: info: Initializing connection to go-librespot Websocket Feb 18 09:12:17 volumio volumio[17782]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 09:12:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 18 09:12:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:12:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:12:19 volumio go-librespot[18117]: go-librespot daemon starting... Feb 18 09:12:19 volumio go-librespot[18118]: time="2026-02-18T09:12:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 09:12:19 volumio go-librespot[18118]: time="2026-02-18T09:12:19+07:00" level=debug msg="app state loaded" Feb 18 09:12:19 volumio go-librespot[18118]: time="2026-02-18T09:12:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 09:12:19 volumio volumio[17782]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 09:12:19 volumio go-librespot[18118]: time="2026-02-18T09:12:19+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 09:12:19 volumio go-librespot[18118]: time="2026-02-18T09:12:19+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 09:12:19 volumio go-librespot[18118]: time="2026-02-18T09:12:19+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 09:12:19 volumio go-librespot[18118]: time="2026-02-18T09:12:19+07:00" level=info msg="zeroconf server listening on port 33901" Feb 18 09:12:19 volumio go-librespot[18118]: time="2026-02-18T09:12:19+07:00" level=debug msg="obtained new client token: AAB3CCRvhJwqK/MI1EbnqjRcOJ538TVJIOXYeV6smT7CUlU4dbVxlsZkRywtiNhzwLUKLWcqGJeS/lT1XtlUCqRG4LOMlYwxNJ3iWwi2aIi1AWqvz0x5sd2ZH4Zt72kejfL9rU7etaORS+ykgdgFAGadnLhcUA1ACfvT9uT8PAbncjoff72jexM+4ltJSt8NnPhQQfm1yryUO16P5+dQu6H1mOarJUdXS10ne4HKpI504kMMU9cxmSsuNQ==" Feb 18 09:12:20 volumio go-librespot[18118]: time="2026-02-18T09:12:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 09:12:20 volumio go-librespot[18118]: time="2026-02-18T09:12:20+07:00" level=debug msg="completed keyexchange" Feb 18 09:12:20 volumio go-librespot[18118]: time="2026-02-18T09:12:20+07:00" level=debug msg="completed challenge" Feb 18 09:12:20 volumio volumio[17782]: info: Initializing connection to go-librespot Websocket Feb 18 09:12:20 volumio go-librespot[18118]: time="2026-02-18T09:12:20+07:00" level=debug msg="new websocket client" Feb 18 09:12:20 volumio volumio[17782]: info: Connection to go-librespot Websocket established Feb 18 09:12:20 volumio go-librespot[18118]: time="2026-02-18T09:12:20+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 09:12:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 09:12:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 09:12:20 volumio volumio[17782]: info: Connection to go-librespot Websocket closed Feb 18 09:12:23 volumio volumio[17782]: info: Getting Spotify volume Feb 18 09:12:23 volumio volumio[17782]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 09:12:23 volumio volumio[17782]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 09:12:23 volumio volumio[17782]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 18 09:12:23 volumio volumio[17782]: errno: -111, Feb 18 09:12:23 volumio volumio[17782]: code: 'ECONNREFUSED', Feb 18 09:12:23 volumio volumio[17782]: syscall: 'connect', Feb 18 09:12:23 volumio volumio[17782]: address: '127.0.0.1', Feb 18 09:12:23 volumio volumio[17782]: port: 9879, Feb 18 09:12:23 volumio volumio[17782]: response: undefined Feb 18 09:12:23 volumio volumio[17782]: } Feb 18 09:12:23 volumio volumio[17782]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 09:12:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 18 09:12:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:12:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:12:23 volumio go-librespot[18130]: go-librespot daemon starting... Feb 18 09:12:23 volumio go-librespot[18139]: time="2026-02-18T09:12:23+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 09:12:23 volumio go-librespot[18139]: time="2026-02-18T09:12:23+07:00" level=debug msg="app state loaded" Feb 18 09:12:23 volumio go-librespot[18139]: time="2026-02-18T09:12:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 09:12:23 volumio go-librespot[18139]: time="2026-02-18T09:12:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 09:12:23 volumio go-librespot[18139]: time="2026-02-18T09:12:23+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 09:12:23 volumio go-librespot[18139]: time="2026-02-18T09:12:23+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 09:12:23 volumio go-librespot[18139]: time="2026-02-18T09:12:23+07:00" level=info msg="zeroconf server listening on port 38437" Feb 18 09:12:24 volumio go-librespot[18139]: time="2026-02-18T09:12:24+07:00" level=debug msg="obtained new client token: AAA0D9YuK40WMobLYYKYWPzDrEbOqvAabBLGhpVOlIgf4N/IHrAYNrsIaq4CZOlVMLZ+9+qNmrTMoRcA30CtQItXbMWQqPYUGuK7u+CEj0P8SdRXti00qbFoIGQ3DgQsnXov+OXXMcNNDG9mRNTVtlLSGrlZmJhEqcKzvjndmPinfyuGgE9tGtIHREEZnMdKTZgh+NaWstqNafiI+ZmawTc+2u4ETyWhMhLo4KW+KzwW2te5d96IiSQ=" Feb 18 09:12:24 volumio go-librespot[18139]: time="2026-02-18T09:12:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 09:12:24 volumio go-librespot[18139]: time="2026-02-18T09:12:24+07:00" level=debug msg="completed keyexchange" Feb 18 09:12:24 volumio go-librespot[18139]: time="2026-02-18T09:12:24+07:00" level=debug msg="completed challenge" Feb 18 09:12:24 volumio go-librespot[18139]: time="2026-02-18T09:12:24+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 09:12:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 09:12:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 09:12:24 volumio sudo[18163]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 09:11' Feb 18 09:12:24 volumio sudo[18163]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:12:25 volumio sudo[18163]: pam_unix(sudo:session): session closed for user root Feb 18 09:12:25 volumio volumio-remote-updater[25144]: [2026-02-18 09:12:25] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 18 09:12:25 volumio volumio-remote-updater[25144]: [2026-02-18 09:12:25] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 18 09:12:25 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 18 09:12:25 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 18 09:12:25 volumio systemd[1]: volumio.service: Consumed 49.125s CPU time. Feb 18 09:12:25 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 09:12:25 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 09:12:25 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 21697. Feb 18 09:12:25 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 09:12:25 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 18 09:12:25 volumio systemd[1]: volumio.service: Consumed 49.125s CPU time. Feb 18 09:12:25 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 18 09:12:25 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 09:12:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 18 09:12:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:12:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:12:27 volumio go-librespot[18190]: go-librespot daemon starting... Feb 18 09:12:27 volumio go-librespot[18191]: time="2026-02-18T09:12:27+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 09:12:27 volumio go-librespot[18191]: time="2026-02-18T09:12:27+07:00" level=debug msg="app state loaded" Feb 18 09:12:27 volumio go-librespot[18191]: time="2026-02-18T09:12:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 09:12:28 volumio go-librespot[18191]: time="2026-02-18T09:12:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 09:12:28 volumio go-librespot[18191]: time="2026-02-18T09:12:28+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 09:12:28 volumio go-librespot[18191]: time="2026-02-18T09:12:28+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 09:12:28 volumio go-librespot[18191]: time="2026-02-18T09:12:28+07:00" level=info msg="zeroconf server listening on port 34895" Feb 18 09:12:28 volumio go-librespot[18191]: time="2026-02-18T09:12:28+07:00" level=debug msg="obtained new client token: AAAiI/iRuPSMKoC80V3s0gdxH9YIMsud+/CwDUqgPPzcvlACRHrcBDaniO441l+E1MTZC8VRgICDecnZgpqS4+RxdoeIgYoTE6oxOBTAXLJNvCLm4GgQ/LkAEKcWPY7OcCH+ounrJBFVb9hzQB7yGaZwE8Nro1uq3lI5gMAu46egIpM6uDAAmH4ifv6Xk8htCJgl/yEujgjRGWJ4NQlEDRucaUsK7E+rGsED8VUXFA7OyzMv/LhfrFx6jQ==" Feb 18 09:12:28 volumio go-librespot[18191]: time="2026-02-18T09:12:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 09:12:28 volumio go-librespot[18191]: time="2026-02-18T09:12:28+07:00" level=debug msg="completed keyexchange" Feb 18 09:12:28 volumio go-librespot[18191]: time="2026-02-18T09:12:28+07:00" level=debug msg="completed challenge" Feb 18 09:12:28 volumio go-librespot[18191]: time="2026-02-18T09:12: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 18 09:12:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 09:12:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 09:12:29 volumio volumio[18175]: info: ------------------------------------------- Feb 18 09:12:29 volumio volumio[18175]: info: ----- Volumio3 ---- Feb 18 09:12:29 volumio volumio[18175]: info: ------------------------------------------- Feb 18 09:12:29 volumio volumio[18175]: info: ----- System startup ---- Feb 18 09:12:29 volumio volumio[18175]: info: ------------------------------------------- Feb 18 09:12:30 volumio volumio-remote-updater[25144]: [2026-02-18 09:12:30] [connect] Successful connection Feb 18 09:12:30 volumio volumio[18175]: info: MYVOLUMIO Environment detected Feb 18 09:12:30 volumio volumio[18175]: info: Plugin folders cleanup Feb 18 09:12:30 volumio volumio[18175]: info: Scanning into folder /volumio/app/plugins/ Feb 18 09:12:30 volumio volumio[18175]: info: Scanning category audio_interface Feb 18 09:12:30 volumio volumio[18175]: info: Scanning category miscellanea Feb 18 09:12:30 volumio volumio[18175]: info: Scanning category music_service Feb 18 09:12:30 volumio volumio[18175]: info: Scanning category plugins.json Feb 18 09:12:30 volumio volumio[18175]: info: Scanning category system_controller Feb 18 09:12:30 volumio volumio[18175]: info: Scanning category user_interface Feb 18 09:12:30 volumio volumio[18175]: info: Scanning into folder /data/plugins/ Feb 18 09:12:30 volumio volumio[18175]: info: Scanning category music_service Feb 18 09:12:30 volumio volumio[18175]: info: Plugin folders cleanup completed Feb 18 09:12:30 volumio volumio[18175]: info: ------------------------------------------- Feb 18 09:12:30 volumio volumio[18175]: info: ----- Core plugins startup ---- Feb 18 09:12:30 volumio volumio[18175]: info: ------------------------------------------- Feb 18 09:12:30 volumio volumio[18175]: info: Loading plugins from folder /volumio/app/plugins/ Feb 18 09:12:30 volumio volumio[18175]: info: Adding plugin upnp to MyMusic Plugins Feb 18 09:12:30 volumio volumio[18175]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 18 09:12:30 volumio volumio[18175]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 18 09:12:30 volumio volumio[18175]: info: Loading plugins from folder /data/plugins/ Feb 18 09:12:30 volumio volumio[18175]: info: Loading plugin "system"... Feb 18 09:12:30 volumio volumio[18175]: info: Loading plugin "appearance"... Feb 18 09:12:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 18 09:12:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:12:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:12:31 volumio go-librespot[18210]: go-librespot daemon starting... Feb 18 09:12:31 volumio go-librespot[18211]: time="2026-02-18T09:12:31+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 09:12:31 volumio go-librespot[18211]: time="2026-02-18T09:12:31+07:00" level=debug msg="app state loaded" Feb 18 09:12:31 volumio go-librespot[18211]: time="2026-02-18T09:12:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 09:12:32 volumio go-librespot[18211]: time="2026-02-18T09:12:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 09:12:32 volumio go-librespot[18211]: time="2026-02-18T09:12:32+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 09:12:32 volumio go-librespot[18211]: time="2026-02-18T09:12:32+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 09:12:32 volumio go-librespot[18211]: time="2026-02-18T09:12:32+07:00" level=info msg="zeroconf server listening on port 35581" Feb 18 09:12:32 volumio volumio[18175]: info: Loading plugin "network"... Feb 18 09:12:32 volumio volumio[18175]: info: Refreshing Cached IP Addresses Feb 18 09:12:32 volumio sudo[18221]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 09:12:32 volumio sudo[18221]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:12:32 volumio volumio[18175]: info: Loading plugin "services"... Feb 18 09:12:32 volumio sudo[18221]: pam_unix(sudo:session): session closed for user root Feb 18 09:12:32 volumio sudo[18219]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 09:12:32 volumio sudo[18219]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:12:32 volumio volumio[18175]: info: Loading plugin "alsa_controller"... Feb 18 09:12:32 volumio sudo[18219]: pam_unix(sudo:session): session closed for user root Feb 18 09:12:32 volumio sudo[18230]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 18 09:12:32 volumio sudo[18230]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:12:32 volumio go-librespot[18211]: time="2026-02-18T09:12:32+07:00" level=debug msg="obtained new client token: AAB7+txwHCHCJqPo0IAiarMH9rSm23hktNr8/GGy8EdhI3NxoS9/yTDN7mGSdcfceX0Hi7SO/X07VhJCOBBNpao9wpYVWZiIcDemq2zme7KZ9zjmN2VFpwLh2NQSrHC6OIG36KSa5eeodsaAb7WxMar1iZJNe+o08onMjVPG+JnCQ38VuhWykoZMwzW95R/A6EpjyUdrN1PuFW2/lqhgd3d3uFLlFn9KzbAy7OWkh4APOHau8sgHab1bjg==" Feb 18 09:12:32 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 09:12:32 volumio go-librespot[18211]: time="2026-02-18T09:12:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 09:12:32 volumio volumio[18175]: info: Loading plugin "wizard"... Feb 18 09:12:32 volumio volumio[18175]: info: Loading plugin "networkfs"... Feb 18 09:12:32 volumio volumio[18175]: info: Starting Udev Watcher for removable devices Feb 18 09:12:32 volumio go-librespot[18211]: time="2026-02-18T09:12:32+07:00" level=debug msg="completed keyexchange" Feb 18 09:12:32 volumio go-librespot[18211]: time="2026-02-18T09:12:32+07:00" level=debug msg="completed challenge" Feb 18 09:12:32 volumio volumio[18175]: info: Ignoring mount for partition: boot Feb 18 09:12:32 volumio volumio[18175]: info: Ignoring mount for partition: volumio Feb 18 09:12:32 volumio volumio[18175]: info: Ignoring mount for partition: volumio_data Feb 18 09:12:32 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 09:12:32 volumio volumio[18175]: info: Loading plugin "volumio_command_line_client"... Feb 18 09:12:32 volumio volumio[18175]: info: Loading plugin "upnp"... Feb 18 09:12:32 volumio volumio[18175]: info: [1771380752993] Starting Upmpd Daemon Feb 18 09:12:32 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 09:12:32 volumio volumio[18175]: info: Loading plugin "my_music"... Feb 18 09:12:33 volumio volumio[18175]: info: Loading plugin "mpd"... Feb 18 09:12:33 volumio go-librespot[18211]: time="2026-02-18T09:12:33+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 09:12:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 09:12:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 09:12:33 volumio volumio[18175]: info: Loading plugin "upnp_browser"... Feb 18 09:12:35 volumio sudo[18230]: pam_unix(sudo:session): session closed for user root Feb 18 09:12:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 18 09:12:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:12:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:12:36 volumio go-librespot[18253]: go-librespot daemon starting... Feb 18 09:12:36 volumio go-librespot[18254]: time="2026-02-18T09:12:36+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 09:12:36 volumio go-librespot[18254]: time="2026-02-18T09:12:36+07:00" level=debug msg="app state loaded" Feb 18 09:12:36 volumio go-librespot[18254]: time="2026-02-18T09:12:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 09:12:36 volumio volumio[18175]: info: Starting UPNP Browser Feb 18 09:12:36 volumio volumio[18175]: info: Loading plugin "alarm-clock"... Feb 18 09:12:36 volumio go-librespot[18254]: time="2026-02-18T09:12: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 18 09:12:36 volumio go-librespot[18254]: time="2026-02-18T09:12: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 18 09:12:36 volumio go-librespot[18254]: time="2026-02-18T09:12: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 18 09:12:36 volumio go-librespot[18254]: time="2026-02-18T09:12:36+07:00" level=info msg="zeroconf server listening on port 41647" Feb 18 09:12:36 volumio volumio[18175]: info: Loading plugin "airplay_emulation"... Feb 18 09:12:36 volumio volumio[18175]: info: Starting Shairport Sync Feb 18 09:12:36 volumio volumio[18175]: info: Loading plugin "last_100"... Feb 18 09:12:36 volumio volumio[18175]: info: Loading plugin "webradio"... Feb 18 09:12:36 volumio go-librespot[18254]: time="2026-02-18T09:12:36+07:00" level=debug msg="obtained new client token: AAALnRjNRnPUFqjC0vzzeUF4cl5GLQWVOXGIU1GRbJOpyAxyabUf4n4pWTZdq/GYiPRyEtXi5uXmQTl9Yt1l22jgs4p9uAa58o1dL6qzdz8y1w4agzCdMSHqME20LZ3DEQpe6u5tYUPGirmaJt1YgJ2FJ/R8+VC9AvNmhMOThdolliORJhtkAWcNZbu5nJc066w/EmI8Lbkz4P2qt0DHYsiu3HFG8y+gFnKbgWxzzDOTojS5U9mFdR8Y/Q==" Feb 18 09:12:37 volumio go-librespot[18254]: time="2026-02-18T09:12:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 09:12:37 volumio volumio[18175]: info: Loading plugin "i2s_dacs"... Feb 18 09:12:37 volumio go-librespot[18254]: time="2026-02-18T09:12:37+07:00" level=debug msg="completed keyexchange" Feb 18 09:12:37 volumio go-librespot[18254]: time="2026-02-18T09:12:37+07:00" level=debug msg="completed challenge" Feb 18 09:12:37 volumio volumio[18175]: info: Loading plugin "volumiodiscovery"... Feb 18 09:12:37 volumio volumio[18175]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 09:12:37 volumio volumio[18175]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 09:12:37 volumio volumio[18175]: *** WARNING *** For more information see Feb 18 09:12:37 volumio volumio[18175]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 09:12:37 volumio volumio[18175]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 09:12:37 volumio volumio[18175]: *** WARNING *** For more information see Feb 18 09:12:37 volumio node[18175]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 09:12:37 volumio node[18175]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 09:12:37 volumio node[18175]: *** WARNING *** For more information see Feb 18 09:12:37 volumio node[18175]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 09:12:37 volumio node[18175]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 09:12:37 volumio go-librespot[18254]: time="2026-02-18T09:12:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 09:12:37 volumio node[18175]: *** WARNING *** For more information see Feb 18 09:12:37 volumio volumio[18175]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 18 09:12:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 09:12:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 09:12:37 volumio volumio[18175]: info: Discovery: Started advertising with name: Volumio Feb 18 09:12:37 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 09:12:37 volumio volumio[18175]: info: Loading plugin "spop"... Feb 18 09:12:39 volumio volumio[18175]: info: Loading plugin "ytcr"... Feb 18 09:12:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 18 09:12:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:12:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:12:40 volumio go-librespot[18263]: go-librespot daemon starting... Feb 18 09:12:40 volumio go-librespot[18264]: time="2026-02-18T09:12:40+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 09:12:40 volumio go-librespot[18264]: time="2026-02-18T09:12:40+07:00" level=debug msg="app state loaded" Feb 18 09:12:40 volumio go-librespot[18264]: time="2026-02-18T09:12:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 09:12:40 volumio go-librespot[18264]: time="2026-02-18T09:12:40+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 09:12:40 volumio go-librespot[18264]: time="2026-02-18T09:12:40+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 09:12:40 volumio go-librespot[18264]: time="2026-02-18T09:12:40+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 09:12:40 volumio go-librespot[18264]: time="2026-02-18T09:12:40+07:00" level=info msg="zeroconf server listening on port 37501" Feb 18 09:12:41 volumio go-librespot[18264]: time="2026-02-18T09:12:41+07:00" level=debug msg="obtained new client token: AACDnTCq07rFXB4pHf+oMwDV+BKBnWkkgdONxGu5HY4+1Zee9TubYwazcStNFzynzYbSLKo+TxAOlBiFWWA8NZ1etzJrdijXc5C5BBSg1oZJ/HP2hWtnFrrkB2OEllXaTb77kBpKd4OSRbqW/U/jtpPZa96vkwm0O5rftZMN9nLGW/LdqzyN18l2v1qjbg6sXAD4TkwROdYjISlwgy0Y2d82IrpIzQuxfGX6Lg5468pxbDttI91UojQ=" Feb 18 09:12:41 volumio go-librespot[18264]: time="2026-02-18T09:12:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 09:12:41 volumio go-librespot[18264]: time="2026-02-18T09:12:41+07:00" level=debug msg="completed keyexchange" Feb 18 09:12:41 volumio go-librespot[18264]: time="2026-02-18T09:12:41+07:00" level=debug msg="completed challenge" Feb 18 09:12:41 volumio go-librespot[18264]: time="2026-02-18T09:12:41+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 09:12:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 09:12:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 09:12:41 volumio volumio[18175]: info: Loading plugin "ytmusic"... Feb 18 09:12:42 volumio volumio-remote-updater[25144]: [2026-02-18 09:12:42] [connect] Successful connection Feb 18 09:12:42 volumio volumio[18175]: info: Loading plugin "outputs"... Feb 18 09:12:42 volumio volumio[18175]: info: Loading plugin "albumart"... Feb 18 09:12:42 volumio volumio[18175]: info: Plugin example_plugin is not enabled Feb 18 09:12:42 volumio volumio[18175]: info: Loading plugin "inputs"... Feb 18 09:12:42 volumio volumio[18175]: info: Loading plugin "updater_comm"... Feb 18 09:12:43 volumio volumio[18175]: info: Plugin mpdemulation is not enabled Feb 18 09:12:43 volumio volumio[18175]: info: Loading plugin "rest_api"... Feb 18 09:12:43 volumio volumio[18175]: info: Loading plugin "websocket"... Feb 18 09:12:43 volumio volumio[18175]: info: Starting Socket.io Server version 1.7.4 Feb 18 09:12:43 volumio volumio[18175]: info: Loading plugin "RoonBridge"... Feb 18 09:12:43 volumio volumio[18175]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 09:12:43 volumio volumio[18175]: info: Loading i18n strings for locale en Feb 18 09:12:43 volumio volumio[18175]: Updating browse sources language Feb 18 09:12:43 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 09:12:43 volumio volumio[18286]: Forking 3 albumart workers Feb 18 09:12:44 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 09:12:44 volumio volumio[18175]: info: CoreCommandRouter::initPlayerControls Feb 18 09:12:44 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:44 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:44 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:44 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:44 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:44 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:44 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:44 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:44 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 09:12:44 volumio volumio[18175]: Express server listening on port 3000 Feb 18 09:12:44 volumio volumio[18175]: [Metrics] WebUI: 16s 53.20ms Feb 18 09:12:44 volumio volumio[18175]: info: CoreStateMachine::resetVolumioState Feb 18 09:12:44 volumio volumio[18175]: info: CoreStateMachine::getcurrentVolume Feb 18 09:12:44 volumio volumio[18175]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 09:12:44 volumio sudo[18330]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 09:12:44 volumio sudo[18330]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:12:44 volumio sudo[18330]: pam_unix(sudo:session): session closed for user root Feb 18 09:12:44 volumio sudo[18332]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 09:12:44 volumio sudo[18332]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:12:44 volumio volumio[18175]: info: Volumio Network Manager: Network status updated: 1 Feb 18 09:12:44 volumio sudo[18332]: pam_unix(sudo:session): session closed for user root Feb 18 09:12:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 18 09:12:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:12:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:12:44 volumio go-librespot[18338]: go-librespot daemon starting... Feb 18 09:12:44 volumio go-librespot[18339]: time="2026-02-18T09:12:44+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 09:12:44 volumio go-librespot[18339]: time="2026-02-18T09:12:44+07:00" level=debug msg="app state loaded" Feb 18 09:12:44 volumio volumio[18175]: info: VolumeController:: Volume=100 Mute =false Feb 18 09:12:44 volumio go-librespot[18339]: time="2026-02-18T09:12:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 09:12:44 volumio volumio[18175]: info: CoreStateMachine::pushState Feb 18 09:12:44 volumio volumio[18175]: info: CorePlayQueue::getTrack 0 Feb 18 09:12:44 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 09:12:44 volumio volumio[18175]: info: CoreCommandRouter::volumioPushState Feb 18 09:12:44 volumio volumio[18175]: info: CoreStateMachine::updateTrackBlock Feb 18 09:12:44 volumio volumio[18175]: info: CorePlayQueue::getTrackBlock Feb 18 09:12:44 volumio volumio[18175]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 09:12:44 volumio volumio-remote-updater[25144]: [2026-02-18 09:12:44] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771380762 101 Feb 18 09:12:44 volumio volumio[18175]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 18 09:12:44 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 09:12:45 volumio volumio[18175]: info: Reloading queue from file Feb 18 09:12:45 volumio volumio[18175]: info: CoreStateMachine::setRepeat null single undefined Feb 18 09:12:45 volumio volumio[18175]: info: CoreStateMachine::pushState Feb 18 09:12:45 volumio volumio[18175]: info: CorePlayQueue::getTrack 0 Feb 18 09:12:45 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 09:12:45 volumio volumio[18175]: info: CoreCommandRouter::volumioPushState Feb 18 09:12:45 volumio volumio[18175]: info: CoreStateMachine::setRandom null Feb 18 09:12:45 volumio volumio[18175]: info: CoreStateMachine::pushState Feb 18 09:12:45 volumio volumio[18175]: info: CorePlayQueue::getTrack 0 Feb 18 09:12:45 volumio volumio[18175]: info: CoreCommandRouter::volumioPushState Feb 18 09:12:45 volumio volumio[18175]: info: Setting Device type: Raspberry PI Feb 18 09:12:45 volumio volumio[18175]: info: Completed loading Core Plugins Feb 18 09:12:45 volumio volumio[18175]: info: Preparing to generate the ALSA configuration file Feb 18 09:12:45 volumio volumio[18175]: info: VolumeController:: Volume=100 Mute =false Feb 18 09:12:45 volumio go-librespot[18339]: time="2026-02-18T09:12:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 09:12:45 volumio go-librespot[18339]: time="2026-02-18T09:12:45+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 09:12:45 volumio go-librespot[18339]: time="2026-02-18T09:12:45+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 09:12:45 volumio volumio[18175]: info: CoreStateMachine::pushState Feb 18 09:12:45 volumio volumio[18175]: info: CorePlayQueue::getTrack 0 Feb 18 09:12:45 volumio volumio[18175]: info: CoreCommandRouter::volumioPushState Feb 18 09:12:45 volumio go-librespot[18339]: time="2026-02-18T09:12:45+07:00" level=info msg="zeroconf server listening on port 38779" Feb 18 09:12:45 volumio volumio[18175]: info: Asound.conf file unchanged, so no further update is needed Feb 18 09:12:45 volumio volumio[18175]: info: Output device has changed, restarting MPD Feb 18 09:12:45 volumio volumio[18175]: info: Output device has changed, restarting Shairport Sync Feb 18 09:12:45 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:45 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 09:12:45 volumio volumio[18175]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 09:12:45 volumio volumio[18175]: info: ___________ START PLUGINS ___________ Feb 18 09:12:45 volumio sudo[18359]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 09:12:45 volumio sudo[18359]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:12:45 volumio sudo[18355]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 09:12:45 volumio sudo[18357]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 09:12:45 volumio sudo[18355]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:12:45 volumio sudo[18357]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:12:45 volumio volumio[18175]: info: ControllerMpd::onStart: Initializing MPD Feb 18 09:12:45 volumio volumio[18175]: info: Creating MPD Configuration file Feb 18 09:12:45 volumio sudo[18357]: pam_unix(sudo:session): session closed for user root Feb 18 09:12:45 volumio go-librespot[18339]: time="2026-02-18T09:12:45+07:00" level=debug msg="obtained new client token: AACz44PPTLeKCpXBjCxtc6ywUV47PMuZm54b10OaN7ot03uFKvPZpVwGzg8BfV/65bepjtzQYwSv9YPjbPDa2GG4sI5dPKqwyu3+4OngM0Gt1jNeG/qQ/F7ye82f6Z2e/UBGBB3zEAHhYJK3zM6+mS7lYVs6GsriNBfZu/YbRjDiTcpj3qD2U/4TiwQLqT4R+JrPcgEMnQWE5qjEUMHvvFZT3eAUWY6Wv5BWpIA6MzqbrDtoZylTTePhqw==" Feb 18 09:12:45 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 09:12:45 volumio sudo[18368]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 09:12:45 volumio sudo[18368]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:12:45 volumio sudo[18368]: pam_unix(sudo:session): session closed for user root Feb 18 09:12:45 volumio volumio[18175]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 09:12:45 volumio volumio[18175]: info: [1771380765685] CoreMusicLibrary::Adding element Media Servers Feb 18 09:12:45 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 09:12:45 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 09:12:45 volumio sudo[18355]: pam_unix(sudo:session): session closed for user root Feb 18 09:12:45 volumio volumio[18175]: info: UPNP Browser: Client initialized successfully Feb 18 09:12:45 volumio go-librespot[18339]: time="2026-02-18T09:12:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 09:12:45 volumio sudo[18371]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 09:12:45 volumio sudo[18371]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:12:45 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:45 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 09:12:45 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 09:12:45 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 09:12:45 volumio systemd[1]: mpd.service: Consumed 7.111s CPU time. Feb 18 09:12:45 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 09:12:45 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 09:12:45 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 09:12:45 volumio go-librespot[18339]: time="2026-02-18T09:12:45+07:00" level=debug msg="completed keyexchange" Feb 18 09:12:45 volumio go-librespot[18339]: time="2026-02-18T09:12:45+07:00" level=debug msg="completed challenge" Feb 18 09:12:45 volumio volumio[18175]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 09:12:45 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:45 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 09:12:45 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 09:12:45 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 09:12:45 volumio go-librespot[18339]: time="2026-02-18T09:12:45+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 09:12:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 09:12:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 09:12:46 volumio volumio[18175]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 09:12:46 volumio volumio[18175]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 09:12:46 volumio volumio[18175]: info: [1771380766079] CoreMusicLibrary::Adding element Last_100 Feb 18 09:12:46 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 09:12:46 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 09:12:46 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 09:12:46 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 09:12:46 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 09:12:46 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 09:12:46 volumio volumio[18175]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 09:12:46 volumio volumio[18175]: info: [1771380766119] CoreMusicLibrary::Adding element Webradio Feb 18 09:12:46 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 09:12:46 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 09:12:46 volumio volumio[18175]: info: Initializing BBC Radios Feb 18 09:12:46 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 09:12:46 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 09:12:46 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 09:12:46 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 09:12:46 volumio volumio[18175]: info: Creating Spotify config file Feb 18 09:12:46 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:46 volumio sudo[18392]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 09:12:46 volumio sudo[18392]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 09:12:46 volumio sudo[18392]: pam_unix(sudo:session): session closed for user root Feb 18 09:12:47 volumio volumio[18297]: Starting albumart workers Feb 18 09:12:47 volumio volumio[18175]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 09:12:47 volumio volumio[18175]: info: [1771380767447] CoreMusicLibrary::Adding element YouTube Music Feb 18 09:12:47 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 09:12:47 volumio volumio[18175]: Cannot find translation for source YouTube Music Feb 18 09:12:47 volumio volumio[18175]: info: Volumio Calling Home Feb 18 09:12:47 volumio sudo[18401]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 09:12:47 volumio sudo[18401]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:12:47 volumio sudo[18401]: pam_unix(sudo:session): session closed for user root Feb 18 09:12:47 volumio volumio[18298]: Starting albumart workers Feb 18 09:12:47 volumio volumio[18296]: Starting albumart workers Feb 18 09:12:48 volumio volumio[18175]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 09:12:48 volumio volumio[18175]: info: Discovery: Found device Volumio Feb 18 09:12:48 volumio volumio[18175]: info: CoreCommandRouter::volumioGetState Feb 18 09:12:48 volumio volumio[18175]: info: CorePlayQueue::getTrack 0 Feb 18 09:12:48 volumio volumio[18175]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 09:12:48 volumio volumio[18175]: info: Discovery: Found device Volumio Feb 18 09:12:48 volumio volumio[18175]: info: CoreCommandRouter::volumioGetState Feb 18 09:12:48 volumio volumio[18175]: info: CorePlayQueue::getTrack 0 Feb 18 09:12:48 volumio volumio[18175]: info: MPD Permissions set Feb 18 09:12:48 volumio volumio[18175]: info: MPD Permissions set Feb 18 09:12:48 volumio volumio[18175]: info: Upmpdcli Daemon Started Feb 18 09:12:48 volumio volumio[18175]: info: Spotify config file written Feb 18 09:12:48 volumio sudo[18407]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 09:12:48 volumio sudo[18407]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:12:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:12:48 volumio volumio[18175]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 18 09:12:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:12:48 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:48 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:48 volumio go-librespot[18409]: go-librespot daemon starting... Feb 18 09:12:48 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:48 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:48 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:48 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:48 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:48 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:48 volumio sudo[18407]: pam_unix(sudo:session): session closed for user root Feb 18 09:12:48 volumio go-librespot[18410]: time="2026-02-18T09:12:48+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 09:12:48 volumio go-librespot[18410]: time="2026-02-18T09:12:48+07:00" level=debug msg="app state loaded" Feb 18 09:12:48 volumio go-librespot[18410]: time="2026-02-18T09:12:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 09:12:48 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 09:12:48 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:48 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:48 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:48 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:48 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:48 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:48 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:48 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:48 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:49 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 09:12:49 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:12:49 volumio volumio[18175]: info: No need to fix Spotify hosts Feb 18 09:12:49 volumio go-librespot[18410]: time="2026-02-18T09:12:49+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 09:12:49 volumio go-librespot[18410]: time="2026-02-18T09:12:49+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 09:12:49 volumio go-librespot[18410]: time="2026-02-18T09:12:49+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 09:12:49 volumio go-librespot[18410]: time="2026-02-18T09:12:49+07:00" level=info msg="zeroconf server listening on port 40895" Feb 18 09:12:49 volumio go-librespot[18410]: time="2026-02-18T09:12:49+07:00" level=debug msg="obtained new client token: AABTKWms/5iFd2EA+7TbFUQ+nioH70Tx0r7wo8ppNjjFeBLKaqvYvk3ev7ynozA/pKuIs58muAuLEBm2MaQ2dcuSro3aQOn9i5OQnv9uAXh1ERtyb9XHyDXLC1rD6cg4iCcv6UHslRNxVvc5hrCgTyG9poH7Uo7bgxn8BNS7vxZhnJg04DQ0yk4ZMuhxwJ6Vu39geagNYKX2h29NxEz7l7EAzPqZ3f+q1KY9p7HtYd9bkb4wuk78M7wROw==" Feb 18 09:12:49 volumio go-librespot[18410]: time="2026-02-18T09:12:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 09:12:49 volumio volumio[18175]: info: Volumio called home Feb 18 09:12:49 volumio go-librespot[18410]: time="2026-02-18T09:12:49+07:00" level=debug msg="completed keyexchange" Feb 18 09:12:49 volumio go-librespot[18410]: time="2026-02-18T09:12:49+07:00" level=debug msg="completed challenge" Feb 18 09:12:50 volumio go-librespot[18410]: time="2026-02-18T09:12:50+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 09:12:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 09:12:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 09:12:50 volumio volumio[18175]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 09:12:50 volumio volumio[18175]: SPOTIFY: BQBqvFt65GuvzYpey7dTIfKPo7VVvuUlxrDQJnVuqeVX_ga4CVQHD0-_AFghN_iByehfqodDrSVYsRsqwPRxQZkgk5tMlpxlJPP2KqMxJ8kELwgwFl4k_dOcCtebCz232M7-8Lzqm851FXKekEFJU9yk7_qnjEMFtnJenSAZUIP9GuaS_Nl3eUFj8hcIhMSN3kMpcY7Zrdp7VjDkH-TN167xONLvIa1mX7lhZbkzAYAzStx4ZTQid46m0fs1r55lH4v1Zbn0toqhYWls-qsCefuc5LEfuj0U_jiFuZ_z3Q-C5j8CvwhvSZrg Feb 18 09:12:50 volumio volumio[18175]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 09:12:50 volumio volumio[18175]: info: New Spotify access token = BQBqvFt65GuvzYpey7dTIfKPo7VVvuUlxrDQJnVuqeVX_ga4CVQHD0-_AFghN_iByehfqodDrSVYsRsqwPRxQZkgk5tMlpxlJPP2KqMxJ8kELwgwFl4k_dOcCtebCz232M7-8Lzqm851FXKekEFJU9yk7_qnjEMFtnJenSAZUIP9GuaS_Nl3eUFj8hcIhMSN3kMpcY7Zrdp7VjDkH-TN167xONLvIa1mX7lhZbkzAYAzStx4ZTQid46m0fs1r55lH4v1Zbn0toqhYWls-qsCefuc5LEfuj0U_jiFuZ_z3Q-C5j8CvwhvSZrg Feb 18 09:12:50 volumio volumio[18175]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 09:12:50 volumio volumio[18175]: info: Starting Shairport Sync Feb 18 09:12:50 volumio volumio[18175]: info: Starting Shairport Sync Feb 18 09:12:50 volumio volumio[18175]: info: Starting Shairport Sync Feb 18 09:12:50 volumio sudo[18446]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 09:12:50 volumio sudo[18446]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:12:50 volumio sudo[18448]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 09:12:50 volumio sudo[18448]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:12:50 volumio sudo[18450]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 09:12:50 volumio sudo[18450]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:12:50 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 09:12:50 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 09:12:50 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 09:12:50 volumio systemd[1]: shairport-sync.service: Consumed 2.237s CPU time. Feb 18 09:12:50 volumio volumio[18175]: info: CoreCommandRouter::volumioGetState Feb 18 09:12:50 volumio volumio[18175]: info: CorePlayQueue::getTrack 0 Feb 18 09:12:50 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 09:12:50 volumio sudo[18446]: pam_unix(sudo:session): session closed for user root Feb 18 09:12:50 volumio volumio[18175]: info: Shairport-Sync Started Feb 18 09:12:50 volumio volumio[18175]: Error adding Membership: Error: addMembership EINVAL Feb 18 09:12:50 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 09:12:50 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 09:12:50 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 09:12:50 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 09:12:50 volumio sudo[18450]: pam_unix(sudo:session): session closed for user root Feb 18 09:12:50 volumio volumio[18175]: info: Shairport-Sync Started Feb 18 09:12:50 volumio sudo[18448]: pam_unix(sudo:session): session closed for user root Feb 18 09:12:51 volumio volumio[18175]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 18 09:12:51 volumio volumio[18175]: info: Spotify Successfully logged in Feb 18 09:12:51 volumio volumio[18175]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 09:12:51 volumio volumio[18175]: info: [1771380771028] CoreMusicLibrary::Adding element Spotify Feb 18 09:12:51 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 09:12:51 volumio volumio[18175]: Cannot find translation for source YouTube Music Feb 18 09:12:51 volumio volumio[18175]: Cannot find translation for source Spotify Feb 18 09:12:51 volumio volumio[18175]: info: Shairport-Sync Started Feb 18 09:12:51 volumio volumio[18175]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 09:12:51 volumio volumio[18175]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 09:12:51 volumio volumio[18175]: info: VolumeController:: Volume=100 Mute =false Feb 18 09:12:51 volumio volumio[18175]: info: CoreCommandRouter::volumioGetState Feb 18 09:12:51 volumio volumio[18175]: info: CorePlayQueue::getTrack 0 Feb 18 09:12:51 volumio volumio[18175]: info: CoreStateMachine::pushState Feb 18 09:12:51 volumio volumio[18175]: info: CorePlayQueue::getTrack 0 Feb 18 09:12:51 volumio volumio[18175]: info: CoreCommandRouter::volumioPushState Feb 18 09:12:53 volumio volumio[18175]: info: go-librespot daemon successfully initialized Feb 18 09:12:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 18 09:12:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:12:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:12:53 volumio go-librespot[18487]: go-librespot daemon starting... Feb 18 09:12:53 volumio go-librespot[18488]: time="2026-02-18T09:12:53+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 09:12:53 volumio go-librespot[18488]: time="2026-02-18T09:12:53+07:00" level=debug msg="app state loaded" Feb 18 09:12:53 volumio go-librespot[18488]: time="2026-02-18T09:12:53+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 09:12:53 volumio mpd[18399]: 2026-02-18T09:12:53 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 09:12:53 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 09:12:53 volumio sudo[18371]: pam_unix(sudo:session): session closed for user root Feb 18 09:12:53 volumio sudo[18359]: pam_unix(sudo:session): session closed for user root Feb 18 09:12:53 volumio volumio[18175]: error: MPD error: The expression evaluated to a falsy value: Feb 18 09:12:53 volumio volumio[18175]: assert.ok(self.idling) Feb 18 09:12:53 volumio volumio[18175]: error: The expression evaluated to a falsy value: Feb 18 09:12:53 volumio volumio[18175]: assert.ok(self.idling) Feb 18 09:12:53 volumio volumio[18175]: info: MPD running with PID18399 Feb 18 09:12:53 volumio volumio[18175]: ,establishing connection Feb 18 09:12:53 volumio volumio[18175]: error: updateQueue error: null Feb 18 09:12:53 volumio volumio[18175]: info: Completed starting Core Plugins Feb 18 09:12:53 volumio volumio[18175]: info: ------------------------------------------- Feb 18 09:12:53 volumio volumio[18175]: info: ----- MyVolumio plugins startup ---- Feb 18 09:12:53 volumio volumio[18175]: info: ------------------------------------------- Feb 18 09:12:53 volumio volumio[18175]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 09:12:53 volumio volumio[18175]: error: updateQueue error: null Feb 18 09:12:53 volumio go-librespot[18488]: time="2026-02-18T09:12:53+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 09:12:53 volumio go-librespot[18488]: time="2026-02-18T09:12:53+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 09:12:53 volumio go-librespot[18488]: time="2026-02-18T09:12:53+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 09:12:53 volumio go-librespot[18488]: time="2026-02-18T09:12:53+07:00" level=info msg="zeroconf server listening on port 34801" Feb 18 09:12:54 volumio go-librespot[18488]: time="2026-02-18T09:12:54+07:00" level=debug msg="obtained new client token: AADShEo/WcimYfROTaG/F0djUYcWDwLSU2QMSePRJHJN+R78LE6tf5n1hHoH3xNrOZF5/Dr2TE1BDQAZeaStoU+FwGX75u2p2VjKLbO6I53t+9JPZjmaUZ9RoQNNsI3QLvJRpn7QCnb4B3i9TF6Q1t5dAqHDJIZrvce2LQIzAX1yklTmGQBVbAKvcKx+CMvZI8dFf2AIfRusOEjBbHn1dtZxeeG3PXrHETcy1mU79O+R7HHUkSTqyEA=" Feb 18 09:12:54 volumio go-librespot[18488]: time="2026-02-18T09:12:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 09:12:54 volumio go-librespot[18488]: time="2026-02-18T09:12:54+07:00" level=debug msg="completed keyexchange" Feb 18 09:12:54 volumio go-librespot[18488]: time="2026-02-18T09:12:54+07:00" level=debug msg="completed challenge" Feb 18 09:12:54 volumio go-librespot[18488]: time="2026-02-18T09:12:54+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 09:12:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 09:12:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 09:12:56 volumio volumio[18175]: info: Initializing connection to go-librespot Websocket Feb 18 09:12:56 volumio volumio[18175]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 09:12:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 18 09:12:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:12:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:12:57 volumio go-librespot[18499]: go-librespot daemon starting... Feb 18 09:12:57 volumio go-librespot[18500]: time="2026-02-18T09:12:57+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 09:12:57 volumio go-librespot[18500]: time="2026-02-18T09:12:57+07:00" level=debug msg="app state loaded" Feb 18 09:12:57 volumio go-librespot[18500]: time="2026-02-18T09:12:57+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 09:12:58 volumio go-librespot[18500]: time="2026-02-18T09:12:58+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 09:12:58 volumio go-librespot[18500]: time="2026-02-18T09:12:58+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 09:12:58 volumio go-librespot[18500]: time="2026-02-18T09:12:58+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 09:12:58 volumio go-librespot[18500]: time="2026-02-18T09:12:58+07:00" level=info msg="zeroconf server listening on port 46427" Feb 18 09:12:58 volumio go-librespot[18500]: time="2026-02-18T09:12:58+07:00" level=debug msg="obtained new client token: AAB5PxWPgJzcbFhX84kXeL0maFdolIHZr4KZTkLoadae9GGqXxc3aON0+s7JajGd5VpifKSegs87EjiranZX+BBNmj8miowd17N8E/UShKpCi8UTtyspZxY4DEJD+/LK5dPaVR+48cXefqUtPB4I+ymA6POyIbLtRqGV5lMB303ZTF3ZFckb/qIdXnVCyC6fxIVGTY3U2BXtOemrJhnYQ8y8ClBxQXrnN+89yrot3sX+COzyN/7OGIA4CQ==" Feb 18 09:12:58 volumio go-librespot[18500]: time="2026-02-18T09:12:58+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 09:12:58 volumio volumio[18175]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 09:12:58 volumio go-librespot[18500]: time="2026-02-18T09:12:58+07:00" level=debug msg="completed keyexchange" Feb 18 09:12:58 volumio go-librespot[18500]: time="2026-02-18T09:12:58+07:00" level=debug msg="completed challenge" Feb 18 09:12:58 volumio go-librespot[18500]: time="2026-02-18T09:12: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 18 09:12:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 09:12:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 09:12:59 volumio volumio[18175]: info: Initializing connection to go-librespot Websocket Feb 18 09:12:59 volumio volumio[18175]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 09:13:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 18 09:13:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:13:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:13:01 volumio go-librespot[18508]: go-librespot daemon starting... Feb 18 09:13:01 volumio go-librespot[18509]: time="2026-02-18T09:13:01+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 09:13:01 volumio go-librespot[18509]: time="2026-02-18T09:13:01+07:00" level=debug msg="app state loaded" Feb 18 09:13:01 volumio go-librespot[18509]: time="2026-02-18T09:13:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 09:13:02 volumio volumio[18175]: info: Initializing connection to go-librespot Websocket Feb 18 09:13:02 volumio go-librespot[18509]: time="2026-02-18T09:13:02+07:00" level=debug msg="new websocket client" Feb 18 09:13:02 volumio volumio[18175]: info: Connection to go-librespot Websocket established Feb 18 09:13:02 volumio go-librespot[18509]: time="2026-02-18T09:13:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 09:13:02 volumio go-librespot[18509]: time="2026-02-18T09:13:02+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 09:13:02 volumio go-librespot[18509]: time="2026-02-18T09:13:02+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 09:13:02 volumio go-librespot[18509]: time="2026-02-18T09:13:02+07:00" level=info msg="zeroconf server listening on port 41969" Feb 18 09:13:02 volumio volumio[18175]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 09:13:02 volumio volumio[18175]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 09:13:02 volumio volumio[18175]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 09:13:02 volumio volumio[18175]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 09:13:02 volumio volumio[18175]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 09:13:02 volumio volumio[18175]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 09:13:02 volumio volumio[18175]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 09:13:02 volumio volumio[18175]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 09:13:02 volumio volumio[18175]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 09:13:02 volumio volumio[18175]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 09:13:02 volumio volumio[18175]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 09:13:02 volumio volumio[18175]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 09:13:02 volumio volumio[18175]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 09:13:02 volumio volumio[18175]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 09:13:02 volumio volumio[18175]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 09:13:02 volumio volumio[18175]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 09:13:02 volumio volumio[18175]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 09:13:02 volumio volumio[18175]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 09:13:02 volumio volumio[18175]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 09:13:02 volumio volumio[18175]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 09:13:02 volumio volumio[18175]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 09:13:02 volumio volumio[18175]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 09:13:02 volumio volumio[18175]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 09:13:02 volumio volumio[18175]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 09:13:02 volumio volumio[18175]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 09:13:02 volumio volumio[18175]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 09:13:02 volumio volumio[18175]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 09:13:02 volumio volumio[18175]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 09:13:02 volumio volumio[18175]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 09:13:02 volumio volumio[18175]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 09:13:02 volumio volumio[18175]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 09:13:02 volumio volumio[18175]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 09:13:02 volumio volumio[18175]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 09:13:02 volumio volumio[18175]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 09:13:02 volumio volumio[18175]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 09:13:02 volumio volumio[18175]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 09:13:02 volumio go-librespot[18509]: time="2026-02-18T09:13:02+07:00" level=debug msg="obtained new client token: AAD6IGuocUjxZ+MIpliQGUWDIOLaXfQsejrlp+QgCXx2NxDOOPhiUAnkhsKc2/885YgD+Qa0Mnx+o4QznbssjELfWTLsfdOponLDYCxP0yOn5o5iEPJVgdM7k/+x3lr6tFh2GDsvcwom8gr+UexbIqrSfKZXwfJX1Zc2kN180N+bR3U8SomP1CFyyRJLm3qCUXqPYrjcWh1FRxRb10PObXErjiq5KaUV+VhVErSHjNT0lmJRycNOJ4wxWA==" Feb 18 09:13:02 volumio go-librespot[18509]: time="2026-02-18T09:13:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 09:13:02 volumio go-librespot[18509]: time="2026-02-18T09:13:02+07:00" level=debug msg="completed keyexchange" Feb 18 09:13:02 volumio go-librespot[18509]: time="2026-02-18T09:13:02+07:00" level=debug msg="completed challenge" Feb 18 09:13:02 volumio go-librespot[18509]: time="2026-02-18T09:13: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 18 09:13:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 09:13:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 09:13:04 volumio volumio[18175]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 09:13:04 volumio volumio[18175]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 09:13:04 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 09:13:04 volumio volumio[18175]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 09:13:04 volumio volumio[18175]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 09:13:04 volumio volumio[18175]: info: MyVolumio login type: Token Feb 18 09:13:04 volumio volumio[18175]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 09:13:04 volumio volumio[18175]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 09:13:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 18 09:13:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:13:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:13:06 volumio go-librespot[18530]: go-librespot daemon starting... Feb 18 09:13:06 volumio go-librespot[18531]: time="2026-02-18T09:13:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 09:13:06 volumio go-librespot[18531]: time="2026-02-18T09:13:06+07:00" level=debug msg="app state loaded" Feb 18 09:13:06 volumio go-librespot[18531]: time="2026-02-18T09:13:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 09:13:06 volumio volumio[18175]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 09:13:06 volumio volumio[18175]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 09:13:06 volumio volumio[18175]: info: Streaming services startup Feb 18 09:13:06 volumio volumio[18175]: info: Starting Streaming Daemon Feb 18 09:13:06 volumio sudo[18539]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 09:13:06 volumio sudo[18539]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:13:06 volumio volumio[18175]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 09:13:06 volumio sudo[18539]: pam_unix(sudo:session): session closed for user root Feb 18 09:13:06 volumio volumio[18175]: info: Getting Spotify volume Feb 18 09:13:06 volumio volumio[18175]: info: Connection to go-librespot Websocket closed Feb 18 09:13:06 volumio volumio[18175]: error: Cannot start Volumio Streaming Daemon Feb 18 09:13:06 volumio volumio[18175]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 09:13:06 volumio volumio[18175]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 09:13:06 volumio volumio[18175]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 18 09:13:06 volumio go-librespot[18531]: time="2026-02-18T09:13: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 18 09:13:06 volumio go-librespot[18531]: time="2026-02-18T09:13: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 18 09:13:06 volumio go-librespot[18531]: time="2026-02-18T09:13: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 18 09:13:06 volumio go-librespot[18531]: time="2026-02-18T09:13:06+07:00" level=info msg="zeroconf server listening on port 34353" Feb 18 09:13:06 volumio volumio[18175]: info: CoreCommandRouter::volumioGetState Feb 18 09:13:06 volumio volumio[18175]: info: CorePlayQueue::getTrack 0 Feb 18 09:13:06 volumio volumio[18175]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 18 09:13:06 volumio volumio[18175]: SPOTIFY: SPOTIFY VOLUME undefined Feb 18 09:13:06 volumio volumio[18175]: SPOTIFY: VOLUMIO VOLUME 100 Feb 18 09:13:06 volumio volumio[18175]: info: Aligning Spotify Volume to Volumio Volume Feb 18 09:13:06 volumio volumio[18175]: info: CoreCommandRouter::volumioGetState Feb 18 09:13:06 volumio volumio[18175]: info: CorePlayQueue::getTrack 0 Feb 18 09:13:06 volumio volumio[18175]: info: Setting Spotify Volume from Volumio: 100 Feb 18 09:13:06 volumio go-librespot[18531]: time="2026-02-18T09:13:06+07:00" level=debug msg="obtained new client token: AABK65CTXjiBcrPcTHwYj6Y01neel8I3lndijRjXDmo3nLIfIFx48MhI6okPt1BnAquKXaU5XUGdI98+kwDjbaMcRlLDz/clAKgaWUc8UsG69OWgeILv6zxRY/F3aDJOoFLuRD6sicsoOS62BPwGU1m5We95MqzXrRgIINZ9grH0OsGe7Z7MKuobk6+15x0VQKywig2QlmeQm7oFQWMFXGufovHsJi1Lo7fCvxh31wJI5mIj5UGlSGpLPg==" Feb 18 09:13:07 volumio go-librespot[18531]: time="2026-02-18T09:13:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 09:13:07 volumio go-librespot[18531]: time="2026-02-18T09:13:07+07:00" level=debug msg="completed keyexchange" Feb 18 09:13:07 volumio go-librespot[18531]: time="2026-02-18T09:13:07+07:00" level=debug msg="completed challenge" Feb 18 09:13:07 volumio go-librespot[18531]: time="2026-02-18T09:13:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 09:13:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 09:13:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 09:13:07 volumio volumio[18175]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 09:13:07 volumio volumio[18175]: Error: socket hang up Feb 18 09:13:07 volumio volumio[18175]: at connResetException (node:internal/errors:720:14) Feb 18 09:13:07 volumio volumio[18175]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 18 09:13:07 volumio volumio[18175]: at Socket.emit (node:events:526:35) Feb 18 09:13:07 volumio volumio[18175]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 18 09:13:07 volumio volumio[18175]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 18 09:13:07 volumio volumio[18175]: code: 'ECONNRESET', Feb 18 09:13:07 volumio volumio[18175]: response: undefined Feb 18 09:13:07 volumio volumio[18175]: } Feb 18 09:13:07 volumio volumio[18175]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 09:13:08 volumio sudo[18560]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 09:12' Feb 18 09:13:08 volumio sudo[18560]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:13:08 volumio sudo[18560]: pam_unix(sudo:session): session closed for user root Feb 18 09:13:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 18 09:13:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:13:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:13:10 volumio go-librespot[18568]: go-librespot daemon starting... Feb 18 09:13:10 volumio go-librespot[18569]: time="2026-02-18T09:13:10+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 09:13:10 volumio go-librespot[18569]: time="2026-02-18T09:13:10+07:00" level=debug msg="app state loaded" Feb 18 09:13:10 volumio go-librespot[18569]: time="2026-02-18T09:13:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 09:13:10 volumio volumio-remote-updater[25144]: [2026-02-18 09:13:10] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Feb 18 09:13:10 volumio volumio-remote-updater[25144]: [2026-02-18 09:13:10] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Feb 18 09:13:10 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 18 09:13:10 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 18 09:13:10 volumio systemd[1]: volumio.service: Consumed 55.670s CPU time. Feb 18 09:13:10 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 09:13:10 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 09:13:10 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 21698. Feb 18 09:13:10 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 09:13:10 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 18 09:13:10 volumio systemd[1]: volumio.service: Consumed 55.670s CPU time. Feb 18 09:13:10 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 18 09:13:10 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 09:13:10 volumio go-librespot[18569]: time="2026-02-18T09:13: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 18 09:13:10 volumio go-librespot[18569]: time="2026-02-18T09:13: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 18 09:13:10 volumio go-librespot[18569]: time="2026-02-18T09:13: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 18 09:13:10 volumio go-librespot[18569]: time="2026-02-18T09:13:10+07:00" level=info msg="zeroconf server listening on port 43979" Feb 18 09:13:11 volumio go-librespot[18569]: time="2026-02-18T09:13:11+07:00" level=debug msg="obtained new client token: AACyBvAFue3xYhzeLNRb70t4Ydct9eFDT3QbRvUNEgU+qzD4Tz2Y0fHprlqSsWTg2Jq31YfwvjQEkztoKBGk5GTmM4NPehqM49LQLgdWltiGi9Tp7m4eyKki1AoULNOEEKGDXvZ30NSJZ6wJpGl0lsyNSAw5tgbxXMH4wLBKg8szs3HIXrDHG1aI6lr25m7VWiY9ntur0yfmIv1RuIyrxlgtMI9jH/aPSclNishyUwp3HyRD0uWe0OE=" Feb 18 09:13:11 volumio go-librespot[18569]: time="2026-02-18T09:13:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 09:13:11 volumio go-librespot[18569]: time="2026-02-18T09:13:11+07:00" level=debug msg="completed keyexchange" Feb 18 09:13:11 volumio go-librespot[18569]: time="2026-02-18T09:13:11+07:00" level=debug msg="completed challenge" Feb 18 09:13:11 volumio go-librespot[18569]: time="2026-02-18T09:13:11+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 09:13:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 09:13:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 09:13:14 volumio volumio[18584]: info: ------------------------------------------- Feb 18 09:13:14 volumio volumio[18584]: info: ----- Volumio3 ---- Feb 18 09:13:14 volumio volumio[18584]: info: ------------------------------------------- Feb 18 09:13:14 volumio volumio[18584]: info: ----- System startup ---- Feb 18 09:13:14 volumio volumio[18584]: info: ------------------------------------------- Feb 18 09:13:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 18 09:13:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:13:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:13:14 volumio go-librespot[18606]: go-librespot daemon starting... Feb 18 09:13:14 volumio go-librespot[18607]: time="2026-02-18T09:13:14+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 09:13:14 volumio go-librespot[18607]: time="2026-02-18T09:13:14+07:00" level=debug msg="app state loaded" Feb 18 09:13:14 volumio go-librespot[18607]: time="2026-02-18T09:13:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 09:13:15 volumio volumio-remote-updater[25144]: [2026-02-18 09:13:15] [connect] Successful connection Feb 18 09:13:15 volumio go-librespot[18607]: time="2026-02-18T09:13:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 09:13:15 volumio go-librespot[18607]: time="2026-02-18T09:13:15+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 09:13:15 volumio go-librespot[18607]: time="2026-02-18T09:13:15+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 09:13:15 volumio go-librespot[18607]: time="2026-02-18T09:13:15+07:00" level=info msg="zeroconf server listening on port 44745" Feb 18 09:13:15 volumio go-librespot[18607]: time="2026-02-18T09:13:15+07:00" level=debug msg="obtained new client token: AAB+ZC6InuZE9BmqwAXUrbISHiXPrDavhWtZs5pJeen0otN7uh/CeITpTREbAvsx31SCX7UVRkT/kNdO3jn5da7evrswBpnHq5PajOwgvm+5/4HzEo0nbeCFDffXzscM3ajAWfu1bp/MkX6bPyFWqK1EsM8OdhuFElACUSdT/QlTL0kDrwT9J5eTvOThemcZrNUy4QJdWoxJBV0KAeSe/hXcd/DtF8ilX09HbUnVxQtVJne8WMdYJxPb0A==" Feb 18 09:13:15 volumio go-librespot[18607]: time="2026-02-18T09:13:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 09:13:15 volumio volumio[18584]: info: MYVOLUMIO Environment detected Feb 18 09:13:16 volumio go-librespot[18607]: time="2026-02-18T09:13:16+07:00" level=debug msg="completed keyexchange" Feb 18 09:13:16 volumio go-librespot[18607]: time="2026-02-18T09:13:16+07:00" level=debug msg="completed challenge" Feb 18 09:13:16 volumio volumio[18584]: info: Plugin folders cleanup Feb 18 09:13:16 volumio volumio[18584]: info: Scanning into folder /volumio/app/plugins/ Feb 18 09:13:16 volumio go-librespot[18607]: time="2026-02-18T09:13:16+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 09:13:16 volumio volumio[18584]: info: Scanning category audio_interface Feb 18 09:13:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 09:13:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 09:13:16 volumio volumio[18584]: info: Scanning category miscellanea Feb 18 09:13:16 volumio volumio[18584]: info: Scanning category music_service Feb 18 09:13:16 volumio volumio[18584]: info: Scanning category plugins.json Feb 18 09:13:16 volumio volumio[18584]: info: Scanning category system_controller Feb 18 09:13:16 volumio volumio[18584]: info: Scanning category user_interface Feb 18 09:13:16 volumio volumio[18584]: info: Scanning into folder /data/plugins/ Feb 18 09:13:16 volumio volumio[18584]: info: Scanning category music_service Feb 18 09:13:16 volumio volumio[18584]: info: Plugin folders cleanup completed Feb 18 09:13:16 volumio volumio[18584]: info: ------------------------------------------- Feb 18 09:13:16 volumio volumio[18584]: info: ----- Core plugins startup ---- Feb 18 09:13:16 volumio volumio[18584]: info: ------------------------------------------- Feb 18 09:13:16 volumio volumio[18584]: info: Loading plugins from folder /volumio/app/plugins/ Feb 18 09:13:16 volumio volumio[18584]: info: Adding plugin upnp to MyMusic Plugins Feb 18 09:13:16 volumio volumio[18584]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 18 09:13:16 volumio volumio[18584]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 18 09:13:16 volumio volumio[18584]: info: Loading plugins from folder /data/plugins/ Feb 18 09:13:16 volumio volumio[18584]: info: Loading plugin "system"... Feb 18 09:13:16 volumio volumio[18584]: info: Loading plugin "appearance"... Feb 18 09:13:18 volumio volumio[18584]: info: Loading plugin "network"... Feb 18 09:13:18 volumio volumio[18584]: info: Refreshing Cached IP Addresses Feb 18 09:13:18 volumio sudo[18622]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 09:13:18 volumio sudo[18622]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:13:18 volumio sudo[18624]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 09:13:18 volumio sudo[18624]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:13:18 volumio volumio[18584]: info: Loading plugin "services"... Feb 18 09:13:18 volumio sudo[18624]: pam_unix(sudo:session): session closed for user root Feb 18 09:13:18 volumio volumio[18584]: info: Loading plugin "alsa_controller"... Feb 18 09:13:18 volumio sudo[18622]: pam_unix(sudo:session): session closed for user root Feb 18 09:13:18 volumio sudo[18631]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 18 09:13:18 volumio sudo[18631]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:13:18 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 09:13:18 volumio volumio[18584]: info: Loading plugin "wizard"... Feb 18 09:13:18 volumio volumio[18584]: info: Loading plugin "networkfs"... Feb 18 09:13:18 volumio volumio[18584]: info: Starting Udev Watcher for removable devices Feb 18 09:13:18 volumio volumio[18584]: info: Ignoring mount for partition: boot Feb 18 09:13:18 volumio volumio[18584]: info: Ignoring mount for partition: volumio Feb 18 09:13:18 volumio volumio[18584]: info: Ignoring mount for partition: volumio_data Feb 18 09:13:18 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 09:13:18 volumio volumio[18584]: info: Loading plugin "volumio_command_line_client"... Feb 18 09:13:18 volumio volumio[18584]: info: Loading plugin "upnp"... Feb 18 09:13:18 volumio volumio[18584]: info: [1771380798553] Starting Upmpd Daemon Feb 18 09:13:18 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 09:13:18 volumio volumio[18584]: info: Loading plugin "my_music"... Feb 18 09:13:18 volumio volumio[18584]: info: Loading plugin "mpd"... Feb 18 09:13:19 volumio volumio[18584]: info: Loading plugin "upnp_browser"... Feb 18 09:13:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 18 09:13:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:13:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:13:19 volumio go-librespot[18655]: go-librespot daemon starting... Feb 18 09:13:19 volumio go-librespot[18656]: time="2026-02-18T09:13:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 09:13:19 volumio go-librespot[18656]: time="2026-02-18T09:13:19+07:00" level=debug msg="app state loaded" Feb 18 09:13:19 volumio go-librespot[18656]: time="2026-02-18T09:13:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 09:13:19 volumio go-librespot[18656]: time="2026-02-18T09:13:19+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 09:13:19 volumio go-librespot[18656]: time="2026-02-18T09:13:19+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 09:13:19 volumio go-librespot[18656]: time="2026-02-18T09:13:19+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 09:13:19 volumio go-librespot[18656]: time="2026-02-18T09:13:19+07:00" level=info msg="zeroconf server listening on port 45097" Feb 18 09:13:20 volumio go-librespot[18656]: time="2026-02-18T09:13:20+07:00" level=debug msg="obtained new client token: AAAwRiGWATbAFHEdI6vjh+zEk0cKQAtYcVWW5/N2mdSj/X8OkuL2ORvS1FDSqZHtUg1+gQ4NJL4h9Zn4B7WGnkkwgkdmJLZ6wPl/Sg24MtAImLkVzyWgHfeehKO9WVVqkmnaJIgbm+pSOn4EWOoDC1SRDmiWWQo3QnjSt0mycIONSsP1JiNwoSUQ1OZ419htVzbT054eIix/u0aokUcrt/oaeRuakt3d3UMaEQWyFVliinxfp5cZjC0=" Feb 18 09:13:20 volumio go-librespot[18656]: time="2026-02-18T09:13:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 09:13:20 volumio go-librespot[18656]: time="2026-02-18T09:13:20+07:00" level=debug msg="completed keyexchange" Feb 18 09:13:20 volumio go-librespot[18656]: time="2026-02-18T09:13:20+07:00" level=debug msg="completed challenge" Feb 18 09:13:20 volumio go-librespot[18656]: time="2026-02-18T09:13:20+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 09:13:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 09:13:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 09:13:21 volumio sudo[18631]: pam_unix(sudo:session): session closed for user root Feb 18 09:13:22 volumio volumio[18584]: info: Starting UPNP Browser Feb 18 09:13:22 volumio volumio[18584]: info: Loading plugin "alarm-clock"... Feb 18 09:13:22 volumio volumio[18584]: info: Loading plugin "airplay_emulation"... Feb 18 09:13:22 volumio volumio[18584]: info: Starting Shairport Sync Feb 18 09:13:22 volumio volumio[18584]: info: Loading plugin "last_100"... Feb 18 09:13:22 volumio volumio[18584]: info: Loading plugin "webradio"... Feb 18 09:13:22 volumio volumio[18584]: info: Loading plugin "i2s_dacs"... Feb 18 09:13:22 volumio volumio[18584]: info: Loading plugin "volumiodiscovery"... Feb 18 09:13:22 volumio volumio[18584]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 09:13:22 volumio volumio[18584]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 09:13:22 volumio node[18584]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 09:13:22 volumio volumio[18584]: *** WARNING *** For more information see Feb 18 09:13:22 volumio volumio[18584]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 09:13:22 volumio volumio[18584]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 09:13:22 volumio volumio[18584]: *** WARNING *** For more information see Feb 18 09:13:22 volumio node[18584]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 09:13:22 volumio node[18584]: *** WARNING *** For more information see Feb 18 09:13:22 volumio node[18584]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 09:13:22 volumio node[18584]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 09:13:22 volumio node[18584]: *** WARNING *** For more information see Feb 18 09:13:22 volumio volumio[18584]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 18 09:13:22 volumio volumio[18584]: info: Discovery: Started advertising with name: Volumio Feb 18 09:13:22 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 09:13:22 volumio volumio[18584]: info: Loading plugin "spop"... Feb 18 09:13:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 18 09:13:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:13:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:13:23 volumio go-librespot[18667]: go-librespot daemon starting... Feb 18 09:13:23 volumio go-librespot[18668]: time="2026-02-18T09:13:23+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 09:13:23 volumio go-librespot[18668]: time="2026-02-18T09:13:23+07:00" level=debug msg="app state loaded" Feb 18 09:13:23 volumio go-librespot[18668]: time="2026-02-18T09:13:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 09:13:24 volumio go-librespot[18668]: time="2026-02-18T09:13:24+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 09:13:24 volumio go-librespot[18668]: time="2026-02-18T09:13:24+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 09:13:24 volumio go-librespot[18668]: time="2026-02-18T09:13:24+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 09:13:24 volumio go-librespot[18668]: time="2026-02-18T09:13:24+07:00" level=info msg="zeroconf server listening on port 36337" Feb 18 09:13:24 volumio go-librespot[18668]: time="2026-02-18T09:13:24+07:00" level=debug msg="obtained new client token: AABzSWloIIOFgxJb+/ts3cLDC5p3yFA0l3gyvEHxu02ejc6UtmmgVTBJ3wpqmpFpC6y3Gc4iwonQ/idCkG1t+1HeNkha7MWHQ3mEjPX2BzHBEBUjf1XeNeUOuast9fDjb8K2vtLXwQTeY5/mdpR78YFY6+GWRuMQZcmahzKIx9eYkiPMgY1GuYtBAhErQ8mjlU26tPfT/OK8363yRQ0y6Uv0ubX0M4LHXYlgWAzqJCjDSyeYi2036zA5eA==" Feb 18 09:13:24 volumio go-librespot[18668]: time="2026-02-18T09:13:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 09:13:24 volumio go-librespot[18668]: time="2026-02-18T09:13:24+07:00" level=debug msg="completed keyexchange" Feb 18 09:13:24 volumio go-librespot[18668]: time="2026-02-18T09:13:24+07:00" level=debug msg="completed challenge" Feb 18 09:13:24 volumio go-librespot[18668]: time="2026-02-18T09:13:24+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 09:13:24 volumio volumio[18584]: info: Loading plugin "ytcr"... Feb 18 09:13:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 09:13:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 09:13:27 volumio volumio[18584]: info: Loading plugin "ytmusic"... Feb 18 09:13:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Feb 18 09:13:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:13:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:13:27 volumio go-librespot[18675]: go-librespot daemon starting... Feb 18 09:13:27 volumio go-librespot[18676]: time="2026-02-18T09:13:27+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 09:13:27 volumio go-librespot[18676]: time="2026-02-18T09:13:27+07:00" level=debug msg="app state loaded" Feb 18 09:13:27 volumio go-librespot[18676]: time="2026-02-18T09:13:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 09:13:27 volumio volumio-remote-updater[25144]: [2026-02-18 09:13:27] [connect] Successful connection Feb 18 09:13:28 volumio go-librespot[18676]: time="2026-02-18T09:13:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 09:13:28 volumio go-librespot[18676]: time="2026-02-18T09:13:28+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 09:13:28 volumio go-librespot[18676]: time="2026-02-18T09:13:28+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 09:13:28 volumio volumio[18584]: info: Loading plugin "outputs"... Feb 18 09:13:28 volumio go-librespot[18676]: time="2026-02-18T09:13:28+07:00" level=info msg="zeroconf server listening on port 35411" Feb 18 09:13:28 volumio volumio[18584]: info: Loading plugin "albumart"... Feb 18 09:13:28 volumio volumio[18584]: info: Plugin example_plugin is not enabled Feb 18 09:13:28 volumio volumio[18584]: info: Loading plugin "inputs"... Feb 18 09:13:28 volumio volumio[18584]: info: Loading plugin "updater_comm"... Feb 18 09:13:28 volumio go-librespot[18676]: time="2026-02-18T09:13:28+07:00" level=debug msg="obtained new client token: AABhD/wa/3OTyIiksDx+pxWAd8hsMIEkTJl4nJLsq31CjnEar3N6wX3KRzkcNPCSXWF0BZyBzzR+5jimxOFVeeMW/gmjozRNzfIMHA1e4I5oNoGMaueYtaFtM3IjRAQg+CkUnt+zvk4Tu1IW4rrSKs9v9Q946S/fyYMhZpbtC8JKXro0ztplVesj2uSjnxc9JiVi2ZlRLdEyl/M1ghnrYoVFuX1ZgbUpaFHH2eF1qmeVBdRJ2Q7ijfajDQ==" Feb 18 09:13:28 volumio volumio[18584]: info: Plugin mpdemulation is not enabled Feb 18 09:13:28 volumio volumio[18584]: info: Loading plugin "rest_api"... Feb 18 09:13:28 volumio go-librespot[18676]: time="2026-02-18T09:13:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 09:13:28 volumio volumio[18584]: info: Loading plugin "websocket"... Feb 18 09:13:28 volumio volumio[18584]: info: Starting Socket.io Server version 1.7.4 Feb 18 09:13:28 volumio volumio[18584]: info: Loading plugin "RoonBridge"... Feb 18 09:13:28 volumio go-librespot[18676]: time="2026-02-18T09:13:28+07:00" level=debug msg="completed keyexchange" Feb 18 09:13:28 volumio go-librespot[18676]: time="2026-02-18T09:13:28+07:00" level=debug msg="completed challenge" Feb 18 09:13:28 volumio go-librespot[18676]: time="2026-02-18T09:13: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 18 09:13:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 09:13:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 09:13:29 volumio volumio[18584]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 09:13:29 volumio volumio[18584]: info: Loading i18n strings for locale en Feb 18 09:13:29 volumio volumio[18584]: Updating browse sources language Feb 18 09:13:29 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 09:13:29 volumio volumio[18698]: Forking 3 albumart workers Feb 18 09:13:29 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 09:13:29 volumio volumio[18584]: info: CoreCommandRouter::initPlayerControls Feb 18 09:13:29 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:13:29 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:13:29 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:13:29 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:13:29 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:13:29 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:13:29 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:13:29 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:13:29 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 09:13:29 volumio volumio[18584]: Express server listening on port 3000 Feb 18 09:13:29 volumio volumio[18584]: [Metrics] WebUI: 16s 173.65ms Feb 18 09:13:29 volumio volumio[18584]: info: CoreStateMachine::resetVolumioState Feb 18 09:13:29 volumio volumio[18584]: info: CoreStateMachine::getcurrentVolume Feb 18 09:13:29 volumio volumio[18584]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 09:13:29 volumio sudo[18742]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 09:13:30 volumio sudo[18744]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 09:13:30 volumio sudo[18744]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:13:30 volumio sudo[18742]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:13:30 volumio volumio[18584]: info: Volumio Network Manager: Network status updated: 1 Feb 18 09:13:30 volumio sudo[18742]: pam_unix(sudo:session): session closed for user root Feb 18 09:13:30 volumio sudo[18744]: pam_unix(sudo:session): session closed for user root Feb 18 09:13:30 volumio volumio[18584]: info: VolumeController:: Volume=100 Mute =false Feb 18 09:13:30 volumio volumio[18584]: info: CoreStateMachine::pushState Feb 18 09:13:30 volumio volumio[18584]: info: CorePlayQueue::getTrack 0 Feb 18 09:13:30 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 09:13:30 volumio volumio[18584]: info: CoreCommandRouter::volumioPushState Feb 18 09:13:30 volumio volumio[18584]: info: CoreStateMachine::updateTrackBlock Feb 18 09:13:30 volumio volumio[18584]: info: CorePlayQueue::getTrackBlock Feb 18 09:13:30 volumio volumio[18584]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 09:13:30 volumio volumio-remote-updater[25144]: [2026-02-18 09:13:30] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771380807 101 Feb 18 09:13:30 volumio volumio[18584]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 18 09:13:30 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 09:13:30 volumio volumio[18584]: info: Reloading queue from file Feb 18 09:13:30 volumio volumio[18584]: info: CoreStateMachine::setRepeat null single undefined Feb 18 09:13:30 volumio volumio[18584]: info: CoreStateMachine::pushState Feb 18 09:13:30 volumio volumio[18584]: info: CorePlayQueue::getTrack 0 Feb 18 09:13:30 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 09:13:30 volumio volumio[18584]: info: CoreCommandRouter::volumioPushState Feb 18 09:13:30 volumio volumio[18584]: info: CoreStateMachine::setRandom null Feb 18 09:13:30 volumio volumio[18584]: info: CoreStateMachine::pushState Feb 18 09:13:30 volumio volumio[18584]: info: CorePlayQueue::getTrack 0 Feb 18 09:13:30 volumio volumio[18584]: info: CoreCommandRouter::volumioPushState Feb 18 09:13:30 volumio volumio[18584]: info: Setting Device type: Raspberry PI Feb 18 09:13:30 volumio volumio[18584]: info: Completed loading Core Plugins Feb 18 09:13:30 volumio volumio[18584]: info: Preparing to generate the ALSA configuration file Feb 18 09:13:30 volumio volumio[18584]: info: VolumeController:: Volume=100 Mute =false Feb 18 09:13:30 volumio volumio[18584]: info: CoreStateMachine::pushState Feb 18 09:13:30 volumio volumio[18584]: info: CorePlayQueue::getTrack 0 Feb 18 09:13:30 volumio volumio[18584]: info: CoreCommandRouter::volumioPushState Feb 18 09:13:30 volumio volumio[18584]: info: Asound.conf file unchanged, so no further update is needed Feb 18 09:13:30 volumio volumio[18584]: info: Output device has changed, restarting MPD Feb 18 09:13:30 volumio volumio[18584]: info: Output device has changed, restarting Shairport Sync Feb 18 09:13:30 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:13:30 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 09:13:30 volumio sudo[18758]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 09:13:30 volumio sudo[18758]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:13:30 volumio sudo[18760]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 09:13:30 volumio volumio[18584]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 09:13:30 volumio volumio[18584]: info: ___________ START PLUGINS ___________ Feb 18 09:13:30 volumio sudo[18760]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:13:30 volumio volumio[18584]: info: ControllerMpd::onStart: Initializing MPD Feb 18 09:13:30 volumio volumio[18584]: info: Creating MPD Configuration file Feb 18 09:13:30 volumio sudo[18760]: pam_unix(sudo:session): session closed for user root Feb 18 09:13:30 volumio sudo[18762]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 09:13:30 volumio sudo[18762]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:13:31 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 09:13:31 volumio volumio[18584]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 09:13:31 volumio volumio[18584]: info: [1771380811025] CoreMusicLibrary::Adding element Media Servers Feb 18 09:13:31 volumio sudo[18758]: pam_unix(sudo:session): session closed for user root Feb 18 09:13:31 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 09:13:31 volumio volumio[18584]: info: UPNP Browser: Client initialized successfully Feb 18 09:13:31 volumio sudo[18770]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 09:13:31 volumio sudo[18770]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:13:31 volumio sudo[18770]: pam_unix(sudo:session): session closed for user root Feb 18 09:13:31 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 09:13:31 volumio sudo[18773]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 09:13:31 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:13:31 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 09:13:31 volumio sudo[18773]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:13:31 volumio volumio[18584]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 09:13:31 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:13:31 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 09:13:31 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 09:13:31 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 09:13:31 volumio systemd[1]: mpd.service: Consumed 7.074s CPU time. Feb 18 09:13:31 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 09:13:31 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 09:13:31 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 09:13:31 volumio volumio[18584]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 09:13:31 volumio volumio[18584]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 09:13:31 volumio volumio[18584]: info: [1771380811350] CoreMusicLibrary::Adding element Last_100 Feb 18 09:13:31 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 09:13:31 volumio volumio[18584]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 09:13:31 volumio volumio[18584]: info: [1771380811369] CoreMusicLibrary::Adding element Webradio Feb 18 09:13:31 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 09:13:31 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 09:13:31 volumio volumio[18584]: info: Initializing BBC Radios Feb 18 09:13:31 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 09:13:31 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 09:13:31 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 09:13:31 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 09:13:31 volumio volumio[18584]: info: Creating Spotify config file Feb 18 09:13:31 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:13:31 volumio sudo[18787]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 09:13:31 volumio sudo[18787]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 09:13:31 volumio sudo[18787]: pam_unix(sudo:session): session closed for user root Feb 18 09:13:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Feb 18 09:13:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:13:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:13:32 volumio go-librespot[18801]: go-librespot daemon starting... Feb 18 09:13:32 volumio go-librespot[18802]: time="2026-02-18T09:13:32+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 09:13:32 volumio volumio[18584]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 09:13:32 volumio go-librespot[18802]: time="2026-02-18T09:13:32+07:00" level=info msg="zeroconf server listening on port 37935" Feb 18 09:13:32 volumio volumio[18584]: info: [1771380812931] CoreMusicLibrary::Adding element YouTube Music Feb 18 09:13:32 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 09:13:32 volumio volumio[18584]: Cannot find translation for source YouTube Music Feb 18 09:13:33 volumio volumio[18584]: info: Volumio Calling Home Feb 18 09:13:33 volumio volumio[18710]: Starting albumart workers Feb 18 09:13:33 volumio sudo[18810]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 09:13:33 volumio sudo[18810]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:13:33 volumio sudo[18810]: pam_unix(sudo:session): session closed for user root Feb 18 09:13:33 volumio volumio[18708]: Starting albumart workers Feb 18 09:13:33 volumio volumio[18709]: Starting albumart workers Feb 18 09:13:33 volumio volumio[18584]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 09:13:33 volumio volumio[18584]: info: Discovery: Found device Volumio Feb 18 09:13:33 volumio volumio[18584]: info: CoreCommandRouter::volumioGetState Feb 18 09:13:33 volumio volumio[18584]: info: CorePlayQueue::getTrack 0 Feb 18 09:13:33 volumio volumio[18584]: info: MPD Permissions set Feb 18 09:13:33 volumio volumio[18584]: info: MPD Permissions set Feb 18 09:13:33 volumio volumio[18584]: info: Upmpdcli Daemon Started Feb 18 09:13:33 volumio volumio[18584]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 09:13:33 volumio volumio[18584]: info: Discovery: Found device Volumio Feb 18 09:13:33 volumio volumio[18584]: info: CoreCommandRouter::volumioGetState Feb 18 09:13:33 volumio volumio[18584]: info: CorePlayQueue::getTrack 0 Feb 18 09:13:33 volumio volumio[18584]: info: Spotify config file written Feb 18 09:13:33 volumio sudo[18816]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 09:13:33 volumio sudo[18816]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:13:34 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 18 09:13:34 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 18 09:13:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:13:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:13:34 volumio go-librespot[18818]: go-librespot daemon starting... Feb 18 09:13:34 volumio sudo[18816]: pam_unix(sudo:session): session closed for user root Feb 18 09:13:34 volumio go-librespot[18819]: time="2026-02-18T09:13:34+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 09:13:34 volumio go-librespot[18819]: time="2026-02-18T09:13:34+07:00" level=debug msg="app state loaded" Feb 18 09:13:34 volumio go-librespot[18819]: time="2026-02-18T09:13:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 09:13:34 volumio volumio[18584]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 18 09:13:34 volumio volumio[18584]: info: Volumio called home Feb 18 09:13:34 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:13:34 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:13:34 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:13:34 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:13:34 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:13:34 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:13:34 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:13:34 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:13:34 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 09:13:34 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:13:34 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:13:34 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:13:34 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:13:34 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:13:34 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:13:34 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:13:34 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:13:34 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:13:34 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 09:13:34 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 09:13:34 volumio volumio[18584]: info: No need to fix Spotify hosts Feb 18 09:13:35 volumio go-librespot[18819]: time="2026-02-18T09:13:35+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 09:13:35 volumio go-librespot[18819]: time="2026-02-18T09:13:35+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 09:13:35 volumio go-librespot[18819]: time="2026-02-18T09:13:35+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 09:13:35 volumio go-librespot[18819]: time="2026-02-18T09:13:35+07:00" level=info msg="zeroconf server listening on port 44401" Feb 18 09:13:35 volumio go-librespot[18819]: time="2026-02-18T09:13:35+07:00" level=debug msg="obtained new client token: AACJi/sO/KNDyHOlob3o25uRnk/xl3ND/rilyxajZ3fWRYZFz1cGZYkKZp2nhgAfKXdeENh2KbYW1sSNlacpYZZAZDC1zrYL4jzuZ3Zj4FwW/xIdII+93+gz8LlPg7/jhxwPNm9gKmKdsgYx/5Xb1MMWfz+S8+GPFE8nvvnOfFvBXwho0PwqpbnsVRNfGn5VL1Q2LUPhtx1FEKuEto7S/Kx08OLjmdcAB3hJ4GXybnbIJpZn/wzCrEo=" Feb 18 09:13:35 volumio go-librespot[18819]: time="2026-02-18T09:13:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 09:13:35 volumio go-librespot[18819]: time="2026-02-18T09:13:35+07:00" level=debug msg="completed keyexchange" Feb 18 09:13:35 volumio go-librespot[18819]: time="2026-02-18T09:13:35+07:00" level=debug msg="completed challenge" Feb 18 09:13:35 volumio go-librespot[18819]: time="2026-02-18T09:13: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 18 09:13:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 09:13:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 09:13:35 volumio volumio[18584]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 09:13:35 volumio volumio[18584]: SPOTIFY: BQA4B8aMy4cpimAu6ps-YQ6HTr788hEzsLJjJlTwzL_MRjKnyquQ5_nlJKZGf-BJhUsfCS5GQQZy4czTrLdjA31WtTiq7pLFKWmMg58gCm4iOmisZSbXtd_h5iWF7uW6Sbbejl3aXIV2dIrS0w59gAxxCHBt5yJE1KtFc8EtdHqbgr40kDwquhYSGc72iA6_2r1iwejxq77dYWTv6cIWaS6DiJCDhc5yWnq1Ttr-130ZDGrA1riZ561ccroBtf66yErQtu7p4bugMU-XCbl9HGj6X1U2BCYnzGyg9U3x3FnD1qOrbn8il-Gi Feb 18 09:13:35 volumio volumio[18584]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 09:13:35 volumio volumio[18584]: info: New Spotify access token = BQA4B8aMy4cpimAu6ps-YQ6HTr788hEzsLJjJlTwzL_MRjKnyquQ5_nlJKZGf-BJhUsfCS5GQQZy4czTrLdjA31WtTiq7pLFKWmMg58gCm4iOmisZSbXtd_h5iWF7uW6Sbbejl3aXIV2dIrS0w59gAxxCHBt5yJE1KtFc8EtdHqbgr40kDwquhYSGc72iA6_2r1iwejxq77dYWTv6cIWaS6DiJCDhc5yWnq1Ttr-130ZDGrA1riZ561ccroBtf66yErQtu7p4bugMU-XCbl9HGj6X1U2BCYnzGyg9U3x3FnD1qOrbn8il-Gi Feb 18 09:13:35 volumio volumio[18584]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 09:13:35 volumio volumio[18584]: info: Starting Shairport Sync Feb 18 09:13:35 volumio volumio[18584]: info: Starting Shairport Sync Feb 18 09:13:36 volumio volumio[18584]: info: Starting Shairport Sync Feb 18 09:13:36 volumio sudo[18856]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 09:13:36 volumio sudo[18856]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:13:36 volumio sudo[18858]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 09:13:36 volumio sudo[18858]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:13:36 volumio sudo[18860]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 09:13:36 volumio sudo[18860]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:13:36 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 09:13:36 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 09:13:36 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 09:13:36 volumio systemd[1]: shairport-sync.service: Consumed 2.306s CPU time. Feb 18 09:13:36 volumio volumio[18584]: info: CoreCommandRouter::volumioGetState Feb 18 09:13:36 volumio volumio[18584]: info: CorePlayQueue::getTrack 0 Feb 18 09:13:36 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 09:13:36 volumio sudo[18856]: pam_unix(sudo:session): session closed for user root Feb 18 09:13:36 volumio sudo[18858]: pam_unix(sudo:session): session closed for user root Feb 18 09:13:36 volumio sudo[18860]: pam_unix(sudo:session): session closed for user root Feb 18 09:13:36 volumio volumio[18584]: info: Shairport-Sync Started Feb 18 09:13:36 volumio volumio[18584]: Error adding Membership: Error: addMembership EINVAL Feb 18 09:13:36 volumio volumio[18584]: info: Shairport-Sync Started Feb 18 09:13:36 volumio volumio[18584]: info: Shairport-Sync Started Feb 18 09:13:36 volumio volumio[18584]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 18 09:13:36 volumio volumio[18584]: info: Spotify Successfully logged in Feb 18 09:13:36 volumio volumio[18584]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 09:13:36 volumio volumio[18584]: info: [1771380816685] CoreMusicLibrary::Adding element Spotify Feb 18 09:13:36 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 09:13:36 volumio volumio[18584]: Cannot find translation for source YouTube Music Feb 18 09:13:36 volumio volumio[18584]: Cannot find translation for source Spotify Feb 18 09:13:37 volumio volumio[18584]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 09:13:37 volumio volumio[18584]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 09:13:37 volumio volumio[18584]: info: VolumeController:: Volume=100 Mute =false Feb 18 09:13:37 volumio volumio[18584]: info: CoreCommandRouter::volumioGetState Feb 18 09:13:37 volumio volumio[18584]: info: CorePlayQueue::getTrack 0 Feb 18 09:13:37 volumio volumio[18584]: info: CoreStateMachine::pushState Feb 18 09:13:37 volumio volumio[18584]: info: CorePlayQueue::getTrack 0 Feb 18 09:13:37 volumio volumio[18584]: info: CoreCommandRouter::volumioPushState Feb 18 09:13:38 volumio volumio[18584]: info: go-librespot daemon successfully initialized Feb 18 09:13:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 18 09:13:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:13:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:13:38 volumio go-librespot[18897]: go-librespot daemon starting... Feb 18 09:13:38 volumio mpd[18800]: 2026-02-18T09:13:38 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 09:13:38 volumio go-librespot[18898]: time="2026-02-18T09:13:38+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 09:13:38 volumio go-librespot[18898]: time="2026-02-18T09:13:38+07:00" level=debug msg="app state loaded" Feb 18 09:13:38 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 09:13:38 volumio go-librespot[18898]: time="2026-02-18T09:13:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 09:13:38 volumio sudo[18773]: pam_unix(sudo:session): session closed for user root Feb 18 09:13:38 volumio sudo[18762]: pam_unix(sudo:session): session closed for user root Feb 18 09:13:39 volumio volumio[18584]: error: MPD error: The expression evaluated to a falsy value: Feb 18 09:13:39 volumio volumio[18584]: assert.ok(self.idling) Feb 18 09:13:39 volumio volumio[18584]: error: The expression evaluated to a falsy value: Feb 18 09:13:39 volumio volumio[18584]: assert.ok(self.idling) Feb 18 09:13:39 volumio volumio[18584]: info: MPD running with PID18800 Feb 18 09:13:39 volumio volumio[18584]: ,establishing connection Feb 18 09:13:39 volumio volumio[18584]: error: updateQueue error: null Feb 18 09:13:39 volumio volumio[18584]: info: Completed starting Core Plugins Feb 18 09:13:39 volumio volumio[18584]: info: ------------------------------------------- Feb 18 09:13:39 volumio volumio[18584]: info: ----- MyVolumio plugins startup ---- Feb 18 09:13:39 volumio volumio[18584]: info: ------------------------------------------- Feb 18 09:13:39 volumio volumio[18584]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 09:13:39 volumio volumio[18584]: error: updateQueue error: null Feb 18 09:13:39 volumio go-librespot[18898]: time="2026-02-18T09:13:39+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 09:13:39 volumio go-librespot[18898]: time="2026-02-18T09:13:39+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 09:13:39 volumio go-librespot[18898]: time="2026-02-18T09:13:39+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 09:13:39 volumio go-librespot[18898]: time="2026-02-18T09:13:39+07:00" level=info msg="zeroconf server listening on port 43605" Feb 18 09:13:39 volumio go-librespot[18898]: time="2026-02-18T09:13:39+07:00" level=debug msg="obtained new client token: AADBpFmiPOKE9Kaxz6Rc44NUOmPpOApht4S963StQfuCOje4NysOHghreZz9ROjW87P9ESnv/jvZJ9th8L/5odJLckiTrWpotMfxWXLsL4kJyqoiO+e5hM02hdpRUGadwJVVonUPn4/Fn4oXYI7QZZT/t3hW30F9o7X/2YlOzHvhscC+q7kg5hHzQX9JmV7oSoMOrWlCBy/Y5tKmSiPSh/jc3zoXNr99yJ/TTUMwBv7Dr8cWHaBuszgHPg==" Feb 18 09:13:39 volumio go-librespot[18898]: time="2026-02-18T09:13:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 09:13:39 volumio go-librespot[18898]: time="2026-02-18T09:13:39+07:00" level=debug msg="completed keyexchange" Feb 18 09:13:39 volumio go-librespot[18898]: time="2026-02-18T09:13:39+07:00" level=debug msg="completed challenge" Feb 18 09:13:39 volumio go-librespot[18898]: time="2026-02-18T09:13: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 18 09:13:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 09:13:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 09:13:41 volumio volumio[18584]: info: Initializing connection to go-librespot Websocket Feb 18 09:13:41 volumio volumio[18584]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 09:13:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 18 09:13:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:13:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:13:43 volumio go-librespot[18909]: go-librespot daemon starting... Feb 18 09:13:43 volumio go-librespot[18910]: time="2026-02-18T09:13:43+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 09:13:43 volumio go-librespot[18910]: time="2026-02-18T09:13:43+07:00" level=debug msg="app state loaded" Feb 18 09:13:43 volumio go-librespot[18910]: time="2026-02-18T09:13:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 09:13:43 volumio go-librespot[18910]: time="2026-02-18T09:13: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 09:13:43 volumio go-librespot[18910]: time="2026-02-18T09:13:43+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 09:13:43 volumio go-librespot[18910]: time="2026-02-18T09:13:43+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 09:13:43 volumio go-librespot[18910]: time="2026-02-18T09:13:43+07:00" level=info msg="zeroconf server listening on port 40347" Feb 18 09:13:43 volumio go-librespot[18910]: time="2026-02-18T09:13:43+07:00" level=debug msg="obtained new client token: AAAEzSNhNwaz/AgSEf9qekiia/1xozymib8cH3TuR4zMVqKdSKu3BtLlwaJpABfiwiuxMizw+22IfoD+EkKOzqrjkhsAf3lLP+EAGBy5l2ylAQoSBHfIZSrHvdq/z8NeLMe8kVVAq0qV4HIJNE8ZW3Us9kJh+gI6t/YpdqeZEyMwEtKy/6RjeHasHXz8YPYKJtrsy4VzG1E4VP339gqPqtJqrdgrWCJspdtHcOkfEibK7TjXVmQfeAVyCQ==" Feb 18 09:13:43 volumio go-librespot[18910]: time="2026-02-18T09:13:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 09:13:44 volumio volumio[18584]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 09:13:44 volumio go-librespot[18910]: time="2026-02-18T09:13:44+07:00" level=debug msg="completed keyexchange" Feb 18 09:13:44 volumio go-librespot[18910]: time="2026-02-18T09:13:44+07:00" level=debug msg="completed challenge" Feb 18 09:13:44 volumio go-librespot[18910]: time="2026-02-18T09:13:44+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 09:13:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 09:13:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 09:13:44 volumio volumio[18584]: info: Initializing connection to go-librespot Websocket Feb 18 09:13:44 volumio volumio[18584]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 09:13:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 18 09:13:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:13:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:13:47 volumio go-librespot[18917]: go-librespot daemon starting... Feb 18 09:13:47 volumio volumio[18584]: info: Initializing connection to go-librespot Websocket Feb 18 09:13:47 volumio volumio[18584]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 09:13:47 volumio go-librespot[18918]: time="2026-02-18T09:13:47+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 09:13:47 volumio go-librespot[18918]: time="2026-02-18T09:13:47+07:00" level=debug msg="app state loaded" Feb 18 09:13:47 volumio go-librespot[18918]: time="2026-02-18T09:13:47+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 09:13:47 volumio go-librespot[18918]: time="2026-02-18T09:13: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 09:13:47 volumio go-librespot[18918]: time="2026-02-18T09:13:47+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 09:13:47 volumio go-librespot[18918]: time="2026-02-18T09:13:47+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 09:13:47 volumio go-librespot[18918]: time="2026-02-18T09:13:47+07:00" level=info msg="zeroconf server listening on port 35451" Feb 18 09:13:48 volumio volumio[18584]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 09:13:48 volumio volumio[18584]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 09:13:48 volumio volumio[18584]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 09:13:48 volumio volumio[18584]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 09:13:48 volumio volumio[18584]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 09:13:48 volumio volumio[18584]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 09:13:48 volumio volumio[18584]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 09:13:48 volumio volumio[18584]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 09:13:48 volumio volumio[18584]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 09:13:48 volumio volumio[18584]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 09:13:48 volumio volumio[18584]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 09:13:48 volumio volumio[18584]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 09:13:48 volumio volumio[18584]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 09:13:48 volumio volumio[18584]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 09:13:48 volumio volumio[18584]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 09:13:48 volumio volumio[18584]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 09:13:48 volumio volumio[18584]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 09:13:48 volumio volumio[18584]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 09:13:48 volumio volumio[18584]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 09:13:48 volumio volumio[18584]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 09:13:48 volumio volumio[18584]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 09:13:48 volumio volumio[18584]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 09:13:48 volumio volumio[18584]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 09:13:48 volumio volumio[18584]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 09:13:48 volumio volumio[18584]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 09:13:48 volumio volumio[18584]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 09:13:48 volumio volumio[18584]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 09:13:48 volumio volumio[18584]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 09:13:48 volumio volumio[18584]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 09:13:48 volumio volumio[18584]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 09:13:48 volumio volumio[18584]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 09:13:48 volumio volumio[18584]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 09:13:48 volumio volumio[18584]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 09:13:48 volumio volumio[18584]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 09:13:48 volumio volumio[18584]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 09:13:48 volumio volumio[18584]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 09:13:48 volumio go-librespot[18918]: time="2026-02-18T09:13:48+07:00" level=debug msg="obtained new client token: AAD3HZLU/GNnkm+0GlhtcucW2taOXKSqUNw9t31a52E81zsPR/RweRNMgdR1QNxXFEf8dO7hfD4Pgylp1/S8BUSpuOWNVrkHEjeyx6CMtEPE4Y4xCdHlRhRDiCXH6Zv8OuLKQ0APF/RvTv6CMFRNGASXL0fAlWHJqXQNqkr0TPGXujGvOMLs4a7Y1zSIcvOpEZHkjsqvcaGj1Gq69fvRCcuIWXu7eJ15p3bodEoj8oZd8A9hx/ueLAM=" Feb 18 09:13:48 volumio go-librespot[18918]: time="2026-02-18T09:13:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 09:13:48 volumio go-librespot[18918]: time="2026-02-18T09:13:48+07:00" level=debug msg="completed keyexchange" Feb 18 09:13:48 volumio go-librespot[18918]: time="2026-02-18T09:13:48+07:00" level=debug msg="completed challenge" Feb 18 09:13:48 volumio go-librespot[18918]: time="2026-02-18T09:13:48+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 09:13:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 09:13:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 09:13:49 volumio volumio[18584]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 09:13:49 volumio volumio[18584]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 09:13:49 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 09:13:49 volumio volumio[18584]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 09:13:49 volumio volumio[18584]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 09:13:50 volumio volumio[18584]: info: MyVolumio login type: Token Feb 18 09:13:50 volumio volumio[18584]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 09:13:50 volumio volumio[18584]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 09:13:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 18 09:13:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:13:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:13:51 volumio go-librespot[18939]: go-librespot daemon starting... Feb 18 09:13:51 volumio go-librespot[18940]: time="2026-02-18T09:13:51+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 09:13:51 volumio go-librespot[18940]: time="2026-02-18T09:13:51+07:00" level=debug msg="app state loaded" Feb 18 09:13:51 volumio go-librespot[18940]: time="2026-02-18T09:13:51+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 09:13:51 volumio volumio[18584]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 09:13:51 volumio volumio[18584]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 09:13:51 volumio volumio[18584]: info: Streaming services startup Feb 18 09:13:51 volumio volumio[18584]: info: Starting Streaming Daemon Feb 18 09:13:51 volumio sudo[18948]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 09:13:51 volumio sudo[18948]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:13:51 volumio volumio[18584]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 09:13:51 volumio sudo[18948]: pam_unix(sudo:session): session closed for user root Feb 18 09:13:52 volumio volumio[18584]: info: Initializing connection to go-librespot Websocket Feb 18 09:13:52 volumio volumio[18584]: error: Cannot start Volumio Streaming Daemon Feb 18 09:13:52 volumio volumio[18584]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 09:13:52 volumio volumio[18584]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 09:13:52 volumio go-librespot[18940]: time="2026-02-18T09:13:52+07:00" level=debug msg="new websocket client" Feb 18 09:13:52 volumio volumio[18584]: info: Connection to go-librespot Websocket established Feb 18 09:13:52 volumio go-librespot[18940]: time="2026-02-18T09:13:52+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 09:13:52 volumio go-librespot[18940]: time="2026-02-18T09:13:52+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 09:13:52 volumio go-librespot[18940]: time="2026-02-18T09:13:52+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 09:13:52 volumio go-librespot[18940]: time="2026-02-18T09:13:52+07:00" level=info msg="zeroconf server listening on port 41395" Feb 18 09:13:52 volumio go-librespot[18940]: time="2026-02-18T09:13:52+07:00" level=debug msg="obtained new client token: AACS0iDgbEanEKKIzkkqFwGdqu9H8oHtaPrFBAyuB1utpbjsm5/Gbyw9jx+R9u32kMOnl03Kvn1cEidvPs9Y7h3EWcYbZaP3vlT1Kh+OhFBNtAa3DQPaVCa8L6/YXVr+NEGHlwVO3QYw5SIf2QuRdkTgHsUCWQbAr1XZFJTfg1aebZCp04aE9bmG1cEDs1BaBHNyhhDvB8XZfAsLbliKsYSwxa+i9GNEjgK4Di07+VJwXVk4MQyzVwjQJg==" Feb 18 09:13:52 volumio go-librespot[18940]: time="2026-02-18T09:13:52+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 09:13:52 volumio go-librespot[18940]: time="2026-02-18T09:13:52+07:00" level=debug msg="completed keyexchange" Feb 18 09:13:52 volumio go-librespot[18940]: time="2026-02-18T09:13:52+07:00" level=debug msg="completed challenge" Feb 18 09:13:52 volumio go-librespot[18940]: time="2026-02-18T09:13: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 18 09:13:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 09:13:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 09:13:52 volumio volumio[18584]: info: Connection to go-librespot Websocket closed Feb 18 09:13:52 volumio volumio[18584]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 18 09:13:53 volumio volumio[18584]: info: MyVolumio token set successfully Feb 18 09:13:53 volumio volumio[18584]: info: MYVOLUMIO: Adding device Feb 18 09:13:53 volumio volumio[18584]: info: MYVOLUMIO: Evaluating Server Feb 18 09:13:54 volumio volumio[18584]: info: MyVolumio status changed Feb 18 09:13:54 volumio volumio[18584]: info: Streaming services startup Feb 18 09:13:54 volumio volumio[18584]: info: Starting Streaming Daemon Feb 18 09:13:54 volumio volumio[18584]: info: Removing browser output: myVolumio user plan is not superstar Feb 18 09:13:54 volumio volumio[18584]: info: Removing audio output: Feb 18 09:13:54 volumio volumio[18584]: info: Stoppping Tunnel 1 Feb 18 09:13:54 volumio sudo[18976]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 09:13:54 volumio sudo[18976]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:13:54 volumio sudo[18979]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 18 09:13:54 volumio sudo[18979]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:13:54 volumio sudo[18976]: pam_unix(sudo:session): session closed for user root Feb 18 09:13:54 volumio volumio[18584]: error: Cannot start Volumio Streaming Daemon Feb 18 09:13:54 volumio volumio[18584]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 09:13:54 volumio volumio[18584]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 09:13:54 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 09:13:54 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 09:13:54 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 09:13:54 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 09:13:54 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 09:13:54 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 09:13:54 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 09:13:54 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 09:13:54 volumio sudo[18979]: pam_unix(sudo:session): session closed for user root Feb 18 09:13:54 volumio volumio[18584]: info: Remote SSH Stopped Feb 18 09:13:55 volumio volumio[18584]: info: Getting Spotify volume Feb 18 09:13:55 volumio volumio[18584]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 09:13:55 volumio volumio[18584]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 09:13:55 volumio volumio[18584]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 18 09:13:55 volumio volumio[18584]: errno: -111, Feb 18 09:13:55 volumio volumio[18584]: code: 'ECONNREFUSED', Feb 18 09:13:55 volumio volumio[18584]: syscall: 'connect', Feb 18 09:13:55 volumio volumio[18584]: address: '127.0.0.1', Feb 18 09:13:55 volumio volumio[18584]: port: 9879, Feb 18 09:13:55 volumio volumio[18584]: response: undefined Feb 18 09:13:55 volumio volumio[18584]: } Feb 18 09:13:55 volumio volumio[18584]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 09:13:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 18 09:13:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:13:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 09:13:55 volumio go-librespot[18993]: go-librespot daemon starting... Feb 18 09:13:55 volumio go-librespot[18994]: time="2026-02-18T09:13:55+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 09:13:55 volumio go-librespot[18994]: time="2026-02-18T09:13:55+07:00" level=debug msg="app state loaded" Feb 18 09:13:55 volumio go-librespot[18994]: time="2026-02-18T09:13:55+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 09:13:56 volumio go-librespot[18994]: time="2026-02-18T09:13:56+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 09:13:56 volumio go-librespot[18994]: time="2026-02-18T09:13:56+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 09:13:56 volumio go-librespot[18994]: time="2026-02-18T09:13:56+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 09:13:56 volumio go-librespot[18994]: time="2026-02-18T09:13:56+07:00" level=info msg="zeroconf server listening on port 46531" Feb 18 09:13:56 volumio sudo[19003]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 09:12' Feb 18 09:13:56 volumio sudo[19003]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 09:13:56 volumio go-librespot[18994]: time="2026-02-18T09:13:56+07:00" level=debug msg="obtained new client token: AACt2CxY+KP493yl2peahrZnd+gJH2OWymC//bHdBtkk/9bnYvME4U//bznjUMCfEAoR6xIAZyXKfBWykL1yfIeTMqO3tonBw8/j3P30tLUPWanN0P+tnK6VXw4ZZnTKsNLb1gBvwTASWf4gerIm/ed6Khz2tOOM1W1p4j107QCPGa6rW8pNvvn9RVC0GPu8o5/vUbHDUGWwk3HnrBMFuhg2WMSkQjRNwrIzlZTFLu4w5UHby4SuD4qSfQ==" Feb 18 09:13:56 volumio go-librespot[18994]: time="2026-02-18T09:13:56+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 09:13:56 volumio go-librespot[18994]: time="2026-02-18T09:13:56+07:00" level=debug msg="completed keyexchange" Feb 18 09:13:56 volumio go-librespot[18994]: time="2026-02-18T09:13:56+07:00" level=debug msg="completed challenge" Feb 18 09:13:57 volumio go-librespot[18994]: time="2026-02-18T09:13:57+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " 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"